From fe464ec6d00002304fc7bf8180355d5e533c4188 Mon Sep 17 00:00:00 2001 From: Robert Schmidt Date: Tue, 17 Feb 2026 01:04:00 +0100 Subject: [PATCH] Initial code for log analysis - we agreed to basically throw away the old log checker (as it is unmaintainable) - now: provide list of analysis to do * all checkers in cls_log_analysis, can be unit tested (see also next commit) * looked up dynamically to simplify adding of new tests + config * configured with DESCRIPTION [DESCRIPTION...] DESCRIPTION ... where DESCRIPTION follows service=func[=options]: - service is name of service to check - func is function to call, which receives filename - option are arbitary options to pass to func is whitespace delimited (so can take multiple service analysis definitions) exists to allow service definitions with whitespace changes that would not work in - I initially planned to check return code, but most softmodems actually exit with non-zero return code, so this is still TODO - Default analyzer (checking for assertions, ...) is always run if a service is listed - checks for file size - add unit tests --- ci-scripts/cls_analysis.py | 98 +++++++++++++++++++ ci-scripts/cls_containerize.py | 21 ++-- ci-scripts/cls_loganalysis.py | 40 ++++++++ ci-scripts/main.py | 24 +++-- ci-scripts/ran.py | 14 ++- ci-scripts/tests/README.md | 1 + ci-scripts/tests/analysis.py | 14 +++ ci-scripts/tests/deployment.py | 48 +++++++-- ci-scripts/tests/log-analysis.py | 26 +++++ ci-scripts/tests/log-analysis/empty.log | 0 .../gnb_phytest_rfemulator_run_100_2x2.xml | 3 + 11 files changed, 257 insertions(+), 32 deletions(-) create mode 100644 ci-scripts/cls_loganalysis.py create mode 100644 ci-scripts/tests/log-analysis.py create mode 100644 ci-scripts/tests/log-analysis/empty.log diff --git a/ci-scripts/cls_analysis.py b/ci-scripts/cls_analysis.py index 3d9eb9c499..866a261352 100644 --- a/ci-scripts/cls_analysis.py +++ b/ci-scripts/cls_analysis.py @@ -24,10 +24,13 @@ import re import os import logging import yaml +import signal import xml.etree.ElementTree as ET import json +import importlib, inspect + class Analysis(): def _get_test_description(properties): @@ -147,3 +150,98 @@ class Analysis(): logging.debug(f'\u001B[1;30;43m normalized metric {k}={valnorm} deviates by more than {dev}\u001B[0m') success = False return success, datalog_rt_stats + + +# returns tuple of (service, analyzer, option string) +def _lookupServiceAnalyzerOpt(s, analyzers): + res = s.split("=", 2) + name = res[0] + if len(res) == 1: + return res[0], analyzers["Default"], None + opt = res[2] if len(res) > 2 else None + func = res[1] + a = analyzers[func] if func in analyzers else None + return name, a, opt + +# groups requested service analysis (service=func[=option]) on per service +# basis and looks up analyzer func. If log analysis is requested, will always +# run Default log analysis +def _groupServices(to_analyze): + req_analysis = {} + # get content of cls_loganalysis module, then get all analyzers (classes) in this module + mod = importlib.import_module("cls_loganalysis") + analyzers = {name:cl for name, cl in inspect.getmembers(mod, inspect.isclass)} + for req in to_analyze: + s, func, opt = _lookupServiceAnalyzerOpt(req, analyzers) + logging.debug(f"requested check '{req}' => service {s}, function {func.__name__}, options '{opt}'") + # always put default analyzer first + l = req_analysis[s] if s in req_analysis else [(analyzers["Default"], None, "default")] + if func is not analyzers["Default"]: + l.append((func, opt, req)) + req_analysis[s] = l + return req_analysis + +def _describe_exit_code(code): + if code > 128: + sig = code - 128 + try: + return f"terminated by signal {sig} ({signal.Signals(sig).name})" + except ValueError: + return f"terminated by unknown signal {sig}" + else: + return f"custom exit code" + +def AnalyzeServices(HTML, service_desc, to_analyze): + success = True + # hack: we want to give as a description "log analysis", but the description + # is set outside, so retain what was set before + orig_html_desc = HTML.desc + # group analysis on a per-service basis, then iterate + for serv, list_analysis in _groupServices(to_analyze).items(): + HTML.desc = f"Log analysis for service {serv}" + if serv not in service_desc: + success = False + logging.error(f"requested service {serv} not in list of services") + HTML.CreateHtmlTestRowQueue("N/A", 'KO', ["service not detected"]) + continue + # pre-initialize with return code + rc = service_desc[serv]["returncode"] + logging.info(f"analyze service {serv}: return code {rc}") + service_success = True # TODO rc == 0: too many functions (eNB, lteUE, RIC, nrUE) fail non-zero + logs = [] + if rc != 0: + logs.append(f"=> return code {rc}, likely " + _describe_exit_code(rc) + " [ignored by CI]") + # skip if the file is too big + logfile = service_desc[serv]["logfile"] + filename = os.path.basename(logfile) + b = os.path.getsize(logfile) + logging.debug(f"using logfile {logfile} of size {b} bytes") + if b > 10 * 1024 * 1024: + success = False + logs.append(f"logfile too big (>10MB)") + logging.error(logs) + HTML.CreateHtmlTestRowQueue(filename, 'KO', ["\n".join(logs)]) + continue + # run each analyzer with its options on the logfile + for (func, opt, desc) in list_analysis: + if func is None: + service_success = False + logging.error(f"request analysis function for desc {desc} not found") + HTML.CreateHtmlTestRowQueue(serv, 'KO', [f"no analysis function for {desc}"]) + continue + result, l = func.run(logfile, opt) + logging.info(f"service {serv}: analysis with func {func}, result {result}, logs '{l}'") + service_success = service_success and result + if not result: + logs.append(f"=> {func.__name__} check (options '{opt}') FAILED") + logs.append(l) + logs = '\n'.join(logs) + if not service_success: + logging.error(l) + else: + logging.info(l) + all_funcs = ", ".join([f.__name__ for (f, _, _) in list_analysis]) + HTML.CreateHtmlTestRowQueue(f"Check {all_funcs} on {filename}", 'OK' if service_success else 'KO', [logs]) + success = success and service_success + HTML.desc = orig_html_desc + return success diff --git a/ci-scripts/cls_containerize.py b/ci-scripts/cls_containerize.py index c56bdb33d2..16fc89613d 100644 --- a/ci-scripts/cls_containerize.py +++ b/ci-scripts/cls_containerize.py @@ -46,6 +46,7 @@ import cls_cmd import helpreadme as HELP import constants as CONST import cls_oaicitest +import cls_analysis from cls_ci_helper import archiveArtifact from collections import deque @@ -808,7 +809,7 @@ class Containerize(): HTML.CreateHtmlTestRowQueue(self.services, 'KO', [f'Failed stopping {" ".join(fail)}, succeeded {" ".join(success)}']) return success - def UndeployObject(self, ctx, node, HTML, RAN): + def UndeployObject(self, ctx, node, HTML, to_analyze): lSourcePath = self.eNBSourceCodePath logging.info(f'\u001B[1m Undeploying all objects from server {node}\u001B[0m') yaml = self.yamlPath.strip('/') @@ -817,21 +818,27 @@ class Containerize(): with cls_cmd.getConnection(node) as ssh: ExistEnvFilePrint(ssh, wd) services = GetDeployedServices(ssh, wd_yaml) - copyin_res = None + all_logs = True ssh.run(f'docker compose -f {wd_yaml} stop') if services is not None: - copyin_res = [CopyinServiceLog(ssh, lSourcePath, s, wd_yaml, ctx) for s, _ in services] + service_desc = {} + for s, c in services: + ret = ssh.run(f'docker inspect {c} --format="{{{{.State.ExitCode}}}}"') + rc = int(ret.stdout.strip()) + f = CopyinServiceLog(ssh, lSourcePath, s, wd_yaml, ctx) + all_logs = all_logs and f is not None + service_desc[s] = {'returncode': rc, 'logfile': f} else: logging.warning('could not identify services to stop => no log file') ssh.run(f'docker compose -f {wd_yaml} down -v') + HTML.CreateHtmlTestRowQueue(node, 'OK', ['Undeployment successful']) ssh.run(f'rm {wd}/.env') - if not copyin_res: + if not all_logs: HTML.CreateHtmlTestRowQueue('N/A', 'KO', ['Could not copy logfile(s)']) - logging.error(f"could not copy all files: {copyin_res=} {services=}") + logging.error(f"could not copy all files: {all_logs=} {services=}") success = False else: - log_results = [CheckLogs(self, f, HTML, RAN) for f in copyin_res] - success = all(log_results) + success = cls_analysis.AnalyzeServices(HTML, service_desc, to_analyze) if success: logging.info('\u001B[1m Undeploying objects Pass\u001B[0m') else: diff --git a/ci-scripts/cls_loganalysis.py b/ci-scripts/cls_loganalysis.py new file mode 100644 index 0000000000..0003b8be69 --- /dev/null +++ b/ci-scripts/cls_loganalysis.py @@ -0,0 +1,40 @@ +#/* +# * Licensed to the OpenAirInterface (OAI) Software Alliance under one or more +# * contributor license agreements. See the NOTICE file distributed with +# * this work for additional information regarding copyright ownership. +# * The OpenAirInterface Software Alliance licenses this file to You under +# * the OAI Public License, Version 1.1 (the "License"); you may not use this file +# * except in compliance with the License. +# * You may obtain a copy of the License at +# * +# * http://www.openairinterface.org/?page_id=698 +# * +# * Unless required by applicable law or agreed to in writing, software +# * distributed under the License is distributed on an "AS IS" BASIS, +# * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# * See the License for the specific language governing permissions and +# * limitations under the License. +# *------------------------------------------------------------------------------- +# * For more information about the OpenAirInterface (OAI) Software Alliance: +# * contact@openairinterface.org +# */ +#--------------------------------------------------------------------- + +import re +import os +import logging + +class Default: + def run(file, opt=None): + # TODO add check on assertions, etc + if not os.path.exists(file): + return False, f"cannot find file {file}" + return True, "" + +class ContainsString: + def run(file, needle): + with open(file, "r") as f: + for line in f.readlines(): + if re.search(needle, line): + return True, "" + return False, f"could not find '{needle}' in logs" diff --git a/ci-scripts/main.py b/ci-scripts/main.py index 75f92bba3b..bbce96f304 100644 --- a/ci-scripts/main.py +++ b/ci-scripts/main.py @@ -115,7 +115,14 @@ def ExecuteActionWithParam(action, ctx, node): string_field=test.findtext('u_retx_th') if (string_field is not None): RAN.ran_checkers['u_retx_th'] = [float(x) for x in string_field.split(',')] - success = RAN.TerminateeNB(ctx, node, HTML) + services = [] + analysis = test.find("analysis") + if analysis is not None: + # services: multiple services to analyse, separated by whitespace + services = analysis.findtext("services", default="").split() + # service: individual services to analyze, in case they have whitespace + services = services + [s.text for s in analysis.findall("service")] + success = RAN.TerminateeNB(ctx, node, HTML, services) elif action == 'Initialize_UE' or action == 'Attach_UE' or action == 'Detach_UE' or action == 'Terminate_UE' or action == 'CheckStatusUE' or action == 'DataEnable_UE' or action == 'DataDisable_UE': CiTestObj.ue_ids = test.findtext('id').split(' ') @@ -188,12 +195,6 @@ def ExecuteActionWithParam(action, ctx, node): elif action == 'Deploy_Object' or action == 'Undeploy_Object' or action == "Create_Workspace" or action == "Stop_Object": CONTAINERS.yamlPath = test.findtext('yaml_path') - string_field=test.findtext('d_retx_th') - if (string_field is not None): - CONTAINERS.ran_checkers['d_retx_th'] = [float(x) for x in string_field.split(',')] - string_field=test.findtext('u_retx_th') - if (string_field is not None): - CONTAINERS.ran_checkers['u_retx_th'] = [float(x) for x in string_field.split(',')] CONTAINERS.services = test.findtext('services') CONTAINERS.num_attempts = int(test.findtext('num_attempts') or 1) CONTAINERS.deploymentTag = cls_containerize.CreateTag(CONTAINERS.ranCommitID, CONTAINERS.ranBranch, CONTAINERS.ranAllowMerge) @@ -202,7 +203,14 @@ def ExecuteActionWithParam(action, ctx, node): elif action == 'Stop_Object': success = CONTAINERS.StopObject(ctx, node, HTML) elif action == 'Undeploy_Object': - success = CONTAINERS.UndeployObject(ctx, node, HTML, RAN) + analysis = test.find("analysis") + services = [] + if analysis is not None: + # services: multiple services to analyse, separated by whitespace + services = analysis.findtext("services", default="").split() + # service: individual services to analyze, in case they have whitespace + services = services + [s.text for s in analysis.findall("service")] + success = CONTAINERS.UndeployObject(ctx, node, HTML, services) elif action == 'Create_Workspace': if force_local: # Do not create a working directory when running locally. Current repo directory will be used diff --git a/ci-scripts/ran.py b/ci-scripts/ran.py index 020ec5949f..27b309cafd 100644 --- a/ci-scripts/ran.py +++ b/ci-scripts/ran.py @@ -127,7 +127,7 @@ class RANManagement(): return enbDidSync - def TerminateeNB(self, ctx, node, HTML): + def TerminateeNB(self, ctx, node, HTML, to_analyze): logging.debug('Stopping eNB/gNB on server: ' + node) lSourcePath = self.eNBSourceCodePath cmd = cls_cmd.getConnection(node) @@ -142,6 +142,7 @@ class RANManagement(): if result is not None: cmd.run('sudo -S killall --signal SIGKILL -r .*-softmodem') time.sleep(5) + HTML.CreateHtmlTestRowQueue(node, 'OK', ['Undeployment successful']) # see InitializeeNB() logfile = f'{lSourcePath}/cmake_targets/enb.log' @@ -156,13 +157,10 @@ class RANManagement(): return False logging.debug('\u001B[1m Analyzing xNB logfile \u001B[0m ' + file) - logStatus = self.AnalyzeLogFile_eNB(file, HTML, self.ran_checkers) - if logStatus < 0: - HTML.CreateHtmlTestRow('N/A', 'KO', logStatus) - else: - HTML.CreateHtmlTestRow(self.runtime_stats, 'OK', CONST.ALL_PROCESSES_OK) - - return logStatus >= 0 + service_desc = {} + service_desc["nr-softmodem"] = {'returncode': 0, 'logfile': file} + success = cls_analysis.AnalyzeServices(HTML, service_desc, to_analyze) + return success def AnalyzeRTStats(self, HTML, node, ctx, thresholds): logging.info(f'Analyzing realtime stats from server: {node}') diff --git a/ci-scripts/tests/README.md b/ci-scripts/tests/README.md index 48a48b8a31..ac3aa2115f 100644 --- a/ci-scripts/tests/README.md +++ b/ci-scripts/tests/README.md @@ -16,6 +16,7 @@ To run individual unit tests, start them like so: python tests/corenetwork.py -v python tests/deployment.py -v python tests/iperf-analysis.py -v + python tests/log-analysis.py -v python tests/ping-iperf.py -v python tests/pull-clean-int-registry.py -v diff --git a/ci-scripts/tests/analysis.py b/ci-scripts/tests/analysis.py index 37e4d3499e..e77bf14603 100644 --- a/ci-scripts/tests/analysis.py +++ b/ci-scripts/tests/analysis.py @@ -53,5 +53,19 @@ class TestAnalysis(unittest.TestCase): # TODO this one is not found, the CI does not recover this?? #self.assertEqual(s['Data']['DL & UL scheduling timing'], ['17', '97', '159371', '1.14']) + def test_analze_services_no_service(self): + service_desc = {} # nothing to analyze + to_analyze = ["testserv"] # some service requested to be analyze that does not exist + status = cls_analysis.AnalyzeServices(self.html, service_desc, to_analyze) + self.assertFalse(status) + + # TODO this does not work: we don't evaluate return codes yet + #def test_analze_service_exit_nonnull(self): + # service_desc = {} + # service_desc["testserv"] = {'returncode': 129, 'logfile': 'tests/log-analysis/empty.log'} + # to_analyze = ["testserv"] # some service requested to be analyze that does not exist + # status = cls_analysis.AnalyzeServices(self.html, service_desc, to_analyze) + # self.assertFalse(status) + if __name__ == '__main__': unittest.main() diff --git a/ci-scripts/tests/deployment.py b/ci-scripts/tests/deployment.py index 10bd2c843f..4fb466acc2 100644 --- a/ci-scripts/tests/deployment.py +++ b/ci-scripts/tests/deployment.py @@ -16,7 +16,6 @@ import cls_oai_html import cls_oaicitest import cls_containerize from cls_ci_helper import TestCaseCtx -import ran import cls_cmd class TestDeploymentMethods(unittest.TestCase): @@ -39,7 +38,6 @@ class TestDeploymentMethods(unittest.TestCase): self.html.testCaseId = "000000" self.ci = cls_oaicitest.OaiCiTest() self.cont = cls_containerize.Containerize() - self.ran = ran.RANManagement() self.cont.yamlPath = '' self.cont.ranAllowMerge = True self.cont.ranBranch = '' @@ -56,7 +54,7 @@ class TestDeploymentMethods(unittest.TestCase): self.cont.yamlPath = 'tests/simple-dep/' self.cont.deploymentTag = "noble" deploy = self.cont.DeployObject(self.ctx, self.node, self.html) - undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, self.ran) + undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, []) self.assertTrue(deploy) self.assertTrue(undeploy) @@ -79,7 +77,7 @@ class TestDeploymentMethods(unittest.TestCase): stopB = self.cont.StopObject(self.ctx, self.node, self.html) # should not undeploy anything (everything already stopped) self.cont.services = None - undeployAll = self.cont.UndeployObject(self.ctx, self.node, self.html, self.ran) + undeployAll = self.cont.UndeployObject(self.ctx, self.node, self.html, []) self.assertTrue(deploy) self.assertFalse(stopC) self.assertTrue(stopA) @@ -92,7 +90,7 @@ class TestDeploymentMethods(unittest.TestCase): old = self.cont.yamlPath self.cont.yamlPath = 'tests/simple-fail/' deploy = self.cont.DeployObject(self.ctx, self.node, self.html) - self.cont.UndeployObject(self.ctx, self.node, self.html, self.ran) + self.cont.UndeployObject(self.ctx, self.node, self.html, []) self.assertFalse(deploy) self.cont.yamlPath = old @@ -101,7 +99,7 @@ class TestDeploymentMethods(unittest.TestCase): old = self.cont.yamlPath self.cont.yamlPath = 'tests/simple-fail-2svc/' deploy = self.cont.DeployObject(self.ctx, self.node, self.html) - self.cont.UndeployObject(self.ctx, self.node, self.html, self.ran) + self.cont.UndeployObject(self.ctx, self.node, self.html, []) self.assertFalse(deploy) self.cont.yamlPath = old @@ -110,7 +108,7 @@ class TestDeploymentMethods(unittest.TestCase): self.cont.services = "oai-gnb" self.cont.deploymentTag = 'develop-12345678' deploy = self.cont.DeployObject(self.ctx, self.node, self.html) - undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, self.ran) + undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, []) self.assertTrue(deploy) self.assertTrue(undeploy) @@ -119,7 +117,7 @@ class TestDeploymentMethods(unittest.TestCase): self.cont.services = "oai-gnb oai-nr-ue" self.cont.deploymentTag = 'develop-12345678' deploy = self.cont.DeployObject(self.ctx, self.node, self.html) - undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, self.ran) + undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, []) self.assertTrue(deploy) self.assertTrue(undeploy) @@ -130,7 +128,7 @@ class TestDeploymentMethods(unittest.TestCase): deploy1 = self.cont.DeployObject(self.ctx, self.node, self.html) self.cont.services = "oai-nr-ue" deploy2 = self.cont.DeployObject(self.ctx, self.node, self.html) - undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, self.ran) + undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, []) self.assertTrue(deploy1) self.assertTrue(deploy2) self.assertTrue(undeploy) @@ -145,5 +143,37 @@ class TestDeploymentMethods(unittest.TestCase): cmd.run(f"rm -rf {self.cont.eNBSourceCodePath}") self.assertTrue(ws) + def test_undeploy_loganalysis(self): + self.cont.yamlPath = 'yaml_files/5g_rfsimulator_tdd_dora' + self.cont.services = "oai-gnb" + self.cont.deploymentTag = 'develop-12345678' + deploy = self.cont.DeployObject(self.ctx, self.node, self.html) + analyze = ["oai-gnb"] + undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, analyze) + self.assertTrue(deploy) + self.assertTrue(undeploy) + + def test_undeploy_multi_loganalysis(self): + self.cont.yamlPath = 'yaml_files/5g_rfsimulator_tdd_dora' + self.cont.services = "oai-gnb" + self.cont.deploymentTag = 'develop-12345678' + deploy = self.cont.DeployObject(self.ctx, self.node, self.html) + analyze = ["oai-gnb", "oai-gnb=ContainsString=NOTFOUND"] + undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, analyze) + self.assertTrue(deploy) + self.assertFalse(undeploy) + + # TODO this does not work: we don't evaluate return codes yet + #def test_undeploy_rc_nonnull(self): + # # fails reliably + # old = self.cont.yamlPath + # self.cont.yamlPath = 'tests/simple-fail/' + # deploy = self.cont.DeployObject(self.ctx, self.node, self.html) + # # should be false because wrong exit code + # undeploy = self.cont.UndeployObject(self.ctx, self.node, self.html, ["test"]) + # self.assertFalse(deploy) + # self.assertFalse(undeploy) + # self.cont.yamlPath = old + if __name__ == '__main__': unittest.main() diff --git a/ci-scripts/tests/log-analysis.py b/ci-scripts/tests/log-analysis.py new file mode 100644 index 0000000000..dba7e9caf4 --- /dev/null +++ b/ci-scripts/tests/log-analysis.py @@ -0,0 +1,26 @@ +import sys +import logging +logging.basicConfig( + level=logging.DEBUG, + stream=sys.stdout, + format="[%(asctime)s] %(levelname)8s: %(message)s" +) +import os +import unittest + +sys.path.append('./') # to find OAI imports below +import cls_loganalysis + +class TestLogAnalysis(unittest.TestCase): + def test_no_file(self): + f = "/total/fantasy/path/file.log" + result, _ = cls_loganalysis.Default.run(f, None) + self.assertFalse(result) + + def test_no_error(self): + f = "tests/log-analysis/empty.log" + result, _ = cls_loganalysis.Default.run(f, None) + self.assertTrue(result) + +if __name__ == '__main__': + unittest.main() diff --git a/ci-scripts/tests/log-analysis/empty.log b/ci-scripts/tests/log-analysis/empty.log new file mode 100644 index 0000000000..e69de29bb2 diff --git a/ci-scripts/xml_files/gnb_phytest_rfemulator_run_100_2x2.xml b/ci-scripts/xml_files/gnb_phytest_rfemulator_run_100_2x2.xml index c91b9c8fc5..8429baa1ba 100644 --- a/ci-scripts/xml_files/gnb_phytest_rfemulator_run_100_2x2.xml +++ b/ci-scripts/xml_files/gnb_phytest_rfemulator_run_100_2x2.xml @@ -59,6 +59,9 @@ caracal true Terminate gNB + + nr-softmodem=ContainsString=Bye. +