diff --git a/ci-scripts/cls_containerize.py b/ci-scripts/cls_containerize.py index 235b5cdce9..e21cb3771b 100644 --- a/ci-scripts/cls_containerize.py +++ b/ci-scripts/cls_containerize.py @@ -31,24 +31,17 @@ #----------------------------------------------------------- # Import #----------------------------------------------------------- -import sys # arg import re # reg import logging import os -import shutil -import time -from zipfile import ZipFile #----------------------------------------------------------- # OAI Testing modules #----------------------------------------------------------- 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 #----------------------------------------------------------- # Helper functions used here and in other classes @@ -190,59 +183,6 @@ def GetDeployedServices(ssh, file): deployed_services.append((s, c)) return deployed_services -def CheckLogs(self, filename, HTML, RAN): - success = True - name = os.path.basename(filename) - if (any(sub in name for sub in ['oai_ue','oai-nr-ue','lte_ue'])): - logging.debug(f'\u001B[1m Analyzing UE logfile {filename} \u001B[0m') - logStatus = cls_oaicitest.OaiCiTest().AnalyzeLogFile_UE(filename, HTML, RAN) - opt = f"UE log analysis ({name})" - # usage of htmlUEFailureMsg/htmleNBFailureMsg is because Analyze log files - # abuse HTML to store their reports, and we here want to put custom options, - # which is not possible with CreateHtmlTestRow - # solution: use HTML templates, where we don't need different HTML write funcs - if (logStatus < 0): - HTML.CreateHtmlTestRowQueue(opt, 'KO', [HTML.htmlUEFailureMsg]) - success = False - else: - HTML.CreateHtmlTestRowQueue(opt, 'OK', [HTML.htmlUEFailureMsg]) - HTML.htmlUEFailureMsg = "" - elif 'nv-cubb' in name: - msg = 'Undeploy PNF/Nvidia CUBB' - HTML.CreateHtmlTestRow(msg, 'OK', CONST.ALL_PROCESSES_OK) - elif (any(sub in name for sub in ['enb','rru','rcc','cu','du','gnb','vnf'])): - logging.debug(f'\u001B[1m Analyzing XnB logfile {filename}\u001B[0m') - logStatus = RAN.AnalyzeLogFile_eNB(filename, HTML, self.ran_checkers) - opt = f"xNB log analysis ({name})" - if (logStatus < 0): - HTML.CreateHtmlTestRowQueue(opt, 'KO', [HTML.htmleNBFailureMsg]) - success = False - else: - HTML.CreateHtmlTestRowQueue(opt, 'OK', [HTML.htmleNBFailureMsg]) - HTML.htmleNBFailureMsg = "" - elif 'xapp' in name: - opt = f"Undeploy {name}" - with open(f'{filename}', "r") as f: - last_line = deque(f, maxlen=1).pop() - if ('Test xApp run SUCCESSFULLY' in last_line): - HTML.CreateHtmlTestRowQueue(opt, 'OK', ["xApp run successfully"]) - else: - HTML.CreateHtmlTestRowQueue(opt, 'KO', ["xApp didn't run successfully"]) - success = False - elif 'RIC' in name: - opt = f"Undeploy {name}" - with open(f'{filename}', 'r') as f: - last_line = deque(f, maxlen=1).pop() - if ('Removing E2 Node' in last_line): - HTML.CreateHtmlTestRowQueue(opt, 'OK', ["nearRT-RIC run successfully"]) - else: - HTML.CreateHtmlTestRowQueue(opt, 'KO', ["nearRT-RIC didn't run successfully"]) - success = False - else: - logging.info(f"Skipping analysis of log '{filename}': no submatch for xNB/UE") - logging.debug(f"log check: file {filename} passed analysis {success}") - return success - #----------------------------------------------------------- # Class Declaration #----------------------------------------------------------- diff --git a/ci-scripts/cls_oaicitest.py b/ci-scripts/cls_oaicitest.py index 850961c00b..26ac91e668 100644 --- a/ci-scripts/cls_oaicitest.py +++ b/ci-scripts/cls_oaicitest.py @@ -32,7 +32,6 @@ #----------------------------------------------------------- # Import Libs #----------------------------------------------------------- -import sys # arg import re # reg import time # sleep import os @@ -41,7 +40,6 @@ import concurrent.futures import json #import our libs -import helpreadme as HELP import constants as CONST import cls_module @@ -578,263 +576,6 @@ class OaiCiTest(): HTML.CreateHtmlTestRowQueue(self.iperf_args, 'KO', [f'{ue_header}\n{msg}']) return success - def AnalyzeLogFile_UE(self, UElogFile,HTML,RAN): - if (not os.path.isfile(f'{UElogFile}')): - return -1 - ue_log_file = open(f'{UElogFile}', 'r') - exitSignalReceived = False - foundAssertion = False - msgAssertion = '' - msgLine = 0 - foundSegFault = False - foundRealTimeIssue = False - uciStatMsgCount = 0 - pdcpDataReqFailedCount = 0 - badDciCount = 0 - f1aRetransmissionCount = 0 - fatalErrorCount = 0 - macBsrTimerExpiredCount = 0 - rrcConnectionRecfgComplete = 0 - no_cell_sync_found = False - mib_found = False - frequency_found = False - plmn_found = False - nrUEFlag = False - nrDecodeMib = 0 - nrFoundDCI = 0 - nrCRCOK = 0 - nbPduSessAccept = 0 - nbPduDiscard = 0 - HTML.htmlUEFailureMsg='' - global_status = CONST.ALL_PROCESSES_OK - for line in ue_log_file.readlines(): - result = re.search('nr_synchro_time|Starting NR UE soft modem', str(line)) - sidelink = re.search('sl-mode', str(line)) - if result is not None: - nrUEFlag = True - if sidelink is not None: - nrUEFlag = False - if nrUEFlag: - result = re.search('decode mib', str(line)) - if result is not None: - nrDecodeMib += 1 - result = re.search('found 1 DCIs', str(line)) - if result is not None: - nrFoundDCI += 1 - result = re.search('CRC OK', str(line)) - if result is not None: - nrCRCOK += 1 - result = re.search('Received PDU Session Establishment Accept', str(line)) - if result is not None: - nbPduSessAccept += 1 - result = re.search('warning: discard PDU, sn out of window', str(line)) - if result is not None: - nbPduDiscard += 1 - result = re.search('--nfapi STANDALONE_PNF --node-number 2', str(line)) - if result is not None: - frequency_found = True - result = re.search('Exiting OAI softmodem', str(line)) - if result is not None: - exitSignalReceived = True - result = re.search('System error|[Ss]egmentation [Ff]ault|======= Backtrace: =========|======= Memory map: ========', str(line)) - if result is not None and not exitSignalReceived: - foundSegFault = True - result = re.search('[Cc]ore [dD]ump', str(line)) - if result is not None and not exitSignalReceived: - foundSegFault = True - result = re.search('[Aa]ssertion', str(line)) - if result is not None and not exitSignalReceived: - foundAssertion = True - result = re.search('LLL', str(line)) - if result is not None and not exitSignalReceived: - foundRealTimeIssue = True - if foundAssertion and (msgLine < 3): - msgLine += 1 - msgAssertion += str(line) - result = re.search('uci->stat', str(line)) - if result is not None and not exitSignalReceived: - uciStatMsgCount += 1 - result = re.search('PDCP data request failed', str(line)) - if result is not None and not exitSignalReceived: - pdcpDataReqFailedCount += 1 - result = re.search('bad DCI 1', str(line)) - if result is not None and not exitSignalReceived: - badDciCount += 1 - result = re.search('Format1A Retransmission but TBS are different', str(line)) - if result is not None and not exitSignalReceived: - f1aRetransmissionCount += 1 - result = re.search('FATAL ERROR', str(line)) - if result is not None and not exitSignalReceived: - fatalErrorCount += 1 - result = re.search('MAC BSR Triggered ReTxBSR Timer expiry', str(line)) - if result is not None and not exitSignalReceived: - macBsrTimerExpiredCount += 1 - result = re.search('Generating RRCConnectionReconfigurationComplete', str(line)) - if result is not None: - rrcConnectionRecfgComplete += 1 - # No cell synchronization found, abandoning - result = re.search('No cell synchronization found, abandoning', str(line)) - if result is not None: - no_cell_sync_found = True - result = re.search(r"MIB Information => ([a-zA-Z]{1,10}), ([a-zA-Z]{1,10}), NidCell (?P\d{1,3}), N_RB_DL (?P\d{1,3}), PHICH DURATION (?P\d), PHICH RESOURCE (?P.{1,4}), TX_ANT (?P\d)", str(line)) - if result is not None and (not mib_found): - try: - mibMsg = "MIB Information: " + result.group(1) + ', ' + result.group(2) - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg + '\n' - logging.debug(f'\033[94m{mibMsg}\033[0m') - mibMsg = " nidcell = " + result.group('nidcell') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg - logging.debug(f'\033[94m{mibMsg}\033[0m') - mibMsg = " n_rb_dl = " + result.group('n_rb_dl') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg + '\n' - logging.debug(f'\033[94m{mibMsg}\033[0m') - mibMsg = " phich_duration = " + result.group('phich_duration') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg - logging.debug(f'\033[94m{mibMsg}\033[0m') - mibMsg = " phich_resource = " + result.group('phich_resource') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg + '\n' - logging.debug(f'\033[94m{mibMsg}\033[0m') - mibMsg = " tx_ant = " + result.group('tx_ant') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg + '\n' - logging.debug(f'\033[94m{mibMsg}\033[0m') - mib_found = True - except Exception as e: - logging.error(f'\033[91m MIB marker was not found \033[0m') - result = re.search("Initial sync: pbch decoded sucessfully", str(line)) - if result is not None and (not frequency_found): - try: - mibMsg = f"UE decoded PBCH successfully" - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg + '\n' - logging.debug(f'\033[94m{mibMsg}\033[0m') - frequency_found = True - except Exception as e: - logging.error(f'\033[91m UE did not find PBCH\033[0m') - result = re.search(r"PLMN MCC (?P\d{1,3}), MNC (?P\d{1,3}), TAC", str(line)) - if result is not None and (not plmn_found): - try: - mibMsg = f"PLMN MCC = {result.group('mcc')} MNC = {result.group('mnc')}" - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg + '\n' - logging.debug(f'\033[94m{mibMsg}\033[0m') - plmn_found = True - except Exception as e: - logging.error(f'\033[91m PLMN not found \033[0m') - result = re.search(r"Found (?P[\w,\s]{1,15}) \(name from internal table\)", str(line)) - if result is not None: - try: - mibMsg = f"The operator is: {result.group('operator')}" - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg + '\n' - logging.debug(f'\033[94m{mibMsg}\033[0m') - except Exception as e: - logging.error(f'\033[91m Operator name not found \033[0m') - result = re.search("SIB5 InterFreqCarrierFreq element (.{1,4})/(.{1,4})", str(line)) - if result is not None: - try: - mibMsg = f'SIB5 InterFreqCarrierFreq element {result.group(1)}/{result.group(2)}' - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + mibMsg + ' -> ' - logging.debug(f'\033[94m{mibMsg}\033[0m') - except Exception as e: - logging.error(f'\033[91m SIB5 InterFreqCarrierFreq element not found \033[0m') - result = re.search(r"DL Carrier Frequency/ARFCN : \-*(?P\d{1,15}/\d{1,4})", str(line)) - if result is not None: - try: - freq = result.group('carrier_frequency') - new_freq = re.sub('/[0-9]+','',freq) - float_freq = float(new_freq) / 1000000 - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + 'DL Freq: ' + ('%.1f' % float_freq) + ' MHz' - logging.debug(f'\033[94m DL Carrier Frequency is: {freq}\033[0m') - except Exception as e: - logging.error(f'\033[91m DL Carrier Frequency not found \033[0m') - result = re.search(r"AllowedMeasBandwidth : (?P\d{1,7})", str(line)) - if result is not None: - try: - prb = result.group('allowed_bandwidth') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + ' -- PRB: ' + prb + '\n' - logging.debug(f'\033[94m AllowedMeasBandwidth: {prb}\033[0m') - except Exception as e: - logging.error(f'\033[91m AllowedMeasBandwidth not found \033[0m') - ue_log_file.close() - if rrcConnectionRecfgComplete > 0: - statMsg = f'UE connected to eNB ({rrcConnectionRecfgComplete}) RRCConnectionReconfigurationComplete message(s) generated)' - logging.debug(f'\033[94m{statMsg}\033[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if nrUEFlag: - if nrDecodeMib > 0: - statMsg = f'UE showed {nrDecodeMib} "MIB decode" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if nrFoundDCI > 0: - statMsg = f'UE showed {nrFoundDCI} "DCI found" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if nrCRCOK > 0: - statMsg = f'UE showed {nrCRCOK} "PDSCH decoding" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if not frequency_found: - statMsg = 'NR-UE could NOT synch!' - logging.error(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if nbPduSessAccept > 0: - statMsg = f'UE showed {nbPduSessAccept} "Received PDU Session Establishment Accept" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if nbPduDiscard > 0: - statMsg = f'UE showed {nbPduDiscard} "warning: discard PDU, sn out of window" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if uciStatMsgCount > 0: - statMsg = f'UE showed {uciStatMsgCount} "uci->stat" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if pdcpDataReqFailedCount > 0: - statMsg = f'UE showed {pdcpDataReqFailedCount} "PDCP data request failed" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if badDciCount > 0: - statMsg = f'UE showed {badDciCount} "bad DCI 1(A)" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if f1aRetransmissionCount > 0: - statMsg = f'UE showed {f1aRetransmissionCount} "Format1A Retransmission but TBS are different" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if fatalErrorCount > 0: - statMsg = f'UE showed {fatalErrorCount} "FATAL ERROR:" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if macBsrTimerExpiredCount > 0: - statMsg = f'UE showed {fatalErrorCount} "MAC BSR Triggered ReTxBSR Timer expiry" message(s)' - logging.debug(f'\u001B[1;30;43m{statMsg}\u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + statMsg + '\n' - if foundSegFault: - logging.debug('\u001B[1;37;41m UE ended with a Segmentation Fault! \u001B[0m') - if not nrUEFlag: - global_status = CONST.OAI_UE_PROCESS_SEG_FAULT - else: - if not frequency_found: - global_status = CONST.OAI_UE_PROCESS_SEG_FAULT - if foundAssertion: - logging.debug('\u001B[1;30;43m UE showed an assertion! \u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + 'UE showed an assertion!\n' - if not nrUEFlag: - if not mib_found or not frequency_found: - global_status = CONST.OAI_UE_PROCESS_ASSERTION - else: - if not frequency_found: - global_status = CONST.OAI_UE_PROCESS_ASSERTION - if foundRealTimeIssue: - logging.debug('\u001B[1;37;41m UE faced real time issues! \u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + 'UE faced real time issues!\n' - if nrUEFlag: - if not frequency_found: - global_status = CONST.OAI_UE_PROCESS_COULD_NOT_SYNC - else: - if no_cell_sync_found and not mib_found: - logging.debug('\u001B[1;37;41m UE could not synchronize ! \u001B[0m') - HTML.htmlUEFailureMsg=HTML.htmlUEFailureMsg + 'UE could not synchronize!\n' - global_status = CONST.OAI_UE_PROCESS_COULD_NOT_SYNC - return global_status - def TerminateUE(self, ctx, node, HTML): ues = [cls_module.Module_UE(n.strip(), node) for n in self.ue_ids] with concurrent.futures.ThreadPoolExecutor(max_workers=64) as executor: diff --git a/ci-scripts/ran.py b/ci-scripts/ran.py index 864c2463a5..950b868ad3 100644 --- a/ci-scripts/ran.py +++ b/ci-scripts/ran.py @@ -31,21 +31,15 @@ #----------------------------------------------------------- # Import #----------------------------------------------------------- -import sys # arg import re # reg import logging import os import time -import yaml -import cls_cmd - #----------------------------------------------------------- # OAI Testing modules #----------------------------------------------------------- import cls_cmd -import helpreadme as HELP -import constants as CONST import cls_analysis from cls_ci_helper import archiveArtifact @@ -173,438 +167,3 @@ class RANManagement(): success, datalog_rt_stats = cls_analysis.Analysis.analyze_rt_stats(thresholds, l1_file, mac_file) HTML.CreateHtmlDataLogTable(datalog_rt_stats) return success - - def AnalyzeLogFile_eNB(self, eNBlogFile, HTML, checkers={}): - if (not os.path.isfile(eNBlogFile)): - return -1 - enb_log_file = open(eNBlogFile, 'r') - exitSignalReceived = False - foundAssertion = False - msgAssertion = '' - msgLine = 0 - foundSegFault = False - foundRealTimeIssue = False - foundRealTimeIssue_cnt = 0 - rrcSetupComplete = 0 - rrcReleaseRequest = 0 - rrcReconfigRequest = 0 - rrcReconfigComplete = 0 - rrcReestablishRequest = 0 - rrcReestablishComplete = 0 - rrcReestablishReject = 0 - rlcDiscardBuffer = 0 - rachCanceledProcedure = 0 - uciStatMsgCount = 0 - pdcpFailure = 0 - ulschFailure = 0 - ulschAllocateCCEerror = 0 - uplinkSegmentsAborted = 0 - ulschReceiveOK = 0 - gnbRxTxWakeUpFailure = 0 - gnbTxWriteThreadEnabled = False - cdrxActivationMessageCount = 0 - dropNotEnoughRBs = 0 - mbmsRequestMsg = 0 - htmleNBFailureMsg = '' - isRRU = False - isSlave = False - slaveReceivesFrameResyncCmd = False - global_status = CONST.ALL_PROCESSES_OK - # Runtime statistics - runTime = '' - userTime = '' - systemTime = '' - maxPhyMemUsage = '' - nbContextSwitches = '' - #NSA FR1 check - NSA_RAPROC_PUSCH_check = 0 - #count "problem receiving samples" msg - pb_receiving_samples_cnt = 0 - #count "removing UE" msg - removing_ue = 0 - #count"X2AP-PDU" - x2ap_pdu = 0 - #gnb specific log markers - gnb_markers ={'SgNBReleaseRequestAcknowledge': [],'FAILURE': [], 'scgFailureInformationNR-r15': [], 'SgNBReleaseRequest': [], 'Detected UL Failure on PUSCH':[]} - nodeB_prefix_found = False - RealTimeProcessingIssue = False - retx_status = {} - nrRrcRcfgComplete = 0 - harqFeedbackPast = 0 - showedByeMsg = False # last line is Bye. -> stopped properly - - line_cnt=0 #log file line counter - for line in enb_log_file.readlines(): - line_cnt+=1 - # Detection of eNB/gNB from a container log - result = re.search('Starting eNB soft modem', str(line)) - if result is not None: - nodeB_prefix_found = True - nodeB_prefix = 'e' - result = re.search('Starting gNB soft modem', str(line)) - if result is not None: - nodeB_prefix_found = True - nodeB_prefix = 'g' - result = re.search('Run time:' ,str(line)) - # Runtime statistics - result = re.search('Run time:' ,str(line)) - if result is not None: - runTime = str(line).strip() - if runTime != '': - result = re.search('Time executing user inst', str(line)) - if result is not None: - fields=line.split(':') - userTime = 'userTime : ' + fields[1].replace('\n','') - result = re.search('Time executing system inst', str(line)) - if result is not None: - fields=line.split(':') - systemTime = 'systemTime : ' + fields[1].replace('\n','') - result = re.search('Max. Phy. memory usage:', str(line)) - if result is not None: - fields=line.split(':') - maxPhyMemUsage = 'maxPhyMemUsage : ' + fields[1].replace('\n','') - result = re.search('Number of context switch.*process origin', str(line)) - if result is not None: - fields=line.split(':') - nbContextSwitches = 'nbContextSwitches : ' + fields[1].replace('\n','') - - if self.eNBOptions[0] != '': - res1 = re.search('max_rxgain (?P[0-9]+)', self.eNBOptions[0]) - res2 = re.search('max_rxgain (?P[0-9]+)', str(line)) - if res1 is not None and res2 is not None: - requested_option = int(res1.group('requested_option')) - applied_option = int(res2.group('applied_option')) - if requested_option == applied_option: - htmleNBFailureMsg += ' Command line option(s) correctly applied ' + self.eNBOptions[0] + '\n\n' - else: - htmleNBFailureMsg += ' Command line option(s) NOT applied ' + self.eNBOptions[0] + '\n\n' - result = re.search('Exiting OAI softmodem|Caught SIGTERM, shutting down', str(line)) - if result is not None: - exitSignalReceived = True - result = re.search('[Ss]egmentation [Ff]ault', str(line)) - if result is not None and not exitSignalReceived: - foundSegFault = True - result = re.search('[Cc]ore [dD]ump', str(line)) - if result is not None and not exitSignalReceived: - foundSegFault = True - result = re.search('[Aa]ssertion', str(line)) - if result is not None and not exitSignalReceived: - foundAssertion = True - result = re.search('LLL', str(line)) - if result is not None and not exitSignalReceived: - foundRealTimeIssue = True - foundRealTimeIssue_cnt += 1 - if foundAssertion and (msgLine < 3): - msgLine += 1 - msgAssertion += str(line) - result = re.search('Setting function for RU', str(line)) - if result is not None: - isRRU = True - if isRRU: - result = re.search('RU 0 is_slave=yes', str(line)) - if result is not None: - isSlave = True - if isSlave: - result = re.search('Received RRU_frame_resynch command', str(line)) - if result is not None: - slaveReceivesFrameResyncCmd = True - result = re.search('LTE_RRCConnectionSetupComplete from UE', str(line)) - if result is not None: - rrcSetupComplete += 1 - result = re.search('Generate LTE_RRCConnectionRelease|Generate RRCConnectionRelease', str(line)) - if result is not None: rrcReleaseRequest += 1 - result = re.search('Generate LTE_RRCConnectionReconfiguration', str(line)) - if result is not None: - rrcReconfigRequest += 1 - result = re.search('LTE_RRCConnectionReconfigurationComplete from UE rnti', str(line)) - if result is not None: - rrcReconfigComplete += 1 - result = re.search('LTE_RRCConnectionReestablishmentRequest', str(line)) - if result is not None: - rrcReestablishRequest += 1 - result = re.search('LTE_RRCConnectionReestablishmentComplete', str(line)) - if result is not None: - rrcReestablishComplete += 1 - result = re.search('LTE_RRCConnectionReestablishmentReject', str(line)) - if result is not None: - rrcReestablishReject += 1 - result = re.search('CDRX configuration activated after RRC Connection', str(line)) - if result is not None: - cdrxActivationMessageCount += 1 - result = re.search('uci->stat', str(line)) - if result is not None: - uciStatMsgCount += 1 - result = re.search('PDCP.*Out of Resources.*reason', str(line)) - if result is not None: - pdcpFailure += 1 - result = re.search('could not wakeup gNB rxtx process', str(line)) - if result is not None: - gnbRxTxWakeUpFailure += 1 - result = re.search('tx write thread ready', str(line)) - if result is not None: - gnbTxWriteThreadEnabled = True - result = re.search('ULSCH in error in round|ULSCH 0 in error', str(line)) - if result is not None: - ulschFailure += 1 - result = re.search('ERROR ALLOCATING CCEs', str(line)) - if result is not None: - ulschAllocateCCEerror += 1 - result = re.search('uplink segment error.*aborted [1-9] segments', str(line)) - if result is not None: - uplinkSegmentsAborted += 1 - result = re.search('ULSCH received ok', str(line)) - if result is not None: - ulschReceiveOK += 1 - result = re.search('BAD all_segments_received', str(line)) - if result is not None: - rlcDiscardBuffer += 1 - result = re.search('Canceled RA procedure for UE rnti', str(line)) - if result is not None: - rachCanceledProcedure += 1 - result = re.search('dropping, not enough RBs', str(line)) - if result is not None: - dropNotEnoughRBs += 1 - #FR1 NSA test : add new markers to make sure gNB is used - result = re.search(r'\[gNB [0-9]+\]\[RAPROC\] PUSCH with TC_RNTI 0x[0-9a-fA-F]+ received correctly, adding UE MAC Context RNTI 0x[0-9a-fA-F]+', str(line)) - if result is not None: - NSA_RAPROC_PUSCH_check = 1 - - result = re.search('Received NR_RRCReconfigurationComplete from UE', str(line)) - if result is not None: - nrRrcRcfgComplete += 1 - result = re.search('HARQ feedback is in the past', str(line)) - if result is not None: - harqFeedbackPast += 1 - - - #count "problem receiving samples" msg - result = re.search(r'\[PHY\]\s+problem receiving samples', str(line)) - if result is not None: - pb_receiving_samples_cnt += 1 - #count "Removing UE" msg - result = re.search(r'\[MAC\]\s+Removing UE', str(line)) - if result is not None: - removing_ue += 1 - #count "X2AP-PDU" - result = re.search('X2AP-PDU', str(line)) - if result is not None: - x2ap_pdu += 1 - #gnb markers logging - for k in gnb_markers: - result = re.search(k, line) - if result is not None: - gnb_markers[k].append(line_cnt) - - # check whether e/gNB log finishes with "Bye." message - showedByeMsg |= re.search(r'^Bye.\n', str(line), re.MULTILINE) is not None - - enb_log_file.close() - - #stdout log file and stat log files analysis completed - logging.debug(' File analysis (stdout, stats) completed') - - #post processing depending on the node type - if not nodeB_prefix_found: - if self.air_interface == 'lte-softmodem': - nodeB_prefix = 'e' - else: - nodeB_prefix = 'g' - - if nodeB_prefix == 'g': - if ulschReceiveOK > 0: - statMsg = nodeB_prefix + 'NB showed ' + str(ulschReceiveOK) + ' "ULSCH received ok" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if gnbRxTxWakeUpFailure > 0: - statMsg = nodeB_prefix + 'NB showed ' + str(gnbRxTxWakeUpFailure) + ' "could not wakeup gNB rxtx process" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if gnbTxWriteThreadEnabled: - statMsg = nodeB_prefix + 'NB ran with TX Write thread enabled' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if nrRrcRcfgComplete > 0: - statMsg = nodeB_prefix + 'NB showed ' + str(nrRrcRcfgComplete) + ' "Received NR_RRCReconfigurationComplete from UE" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if harqFeedbackPast > 0: - statMsg = nodeB_prefix + 'NB showed ' + str(harqFeedbackPast) + ' "HARQ feedback is in the past" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - #FR1 NSA test : add new markers to make sure gNB is used - if NSA_RAPROC_PUSCH_check: - statMsg = '[RAPROC] PUSCH with TC_RNTI message check for ' + nodeB_prefix + 'NB : PASS ' - htmlMsg = statMsg+'\n' - else: - statMsg = '[RAPROC] PUSCH with TC_RNTI message check for ' + nodeB_prefix + 'NB : FAIL or not relevant' - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - #problem receiving samples log - statMsg = '[PHY] problem receiving samples msg count = '+str(pb_receiving_samples_cnt) - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - #gnb markers - statMsg = 'logfile line count = ' + str(line_cnt) - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - if len(gnb_markers['SgNBReleaseRequestAcknowledge'])!=0: - statMsg = 'SgNBReleaseRequestAcknowledge = ' + str(len(gnb_markers['SgNBReleaseRequestAcknowledge'])) + ' occurences , starting line ' + str(gnb_markers['SgNBReleaseRequestAcknowledge'][0]) - else: - statMsg = 'SgNBReleaseRequestAcknowledge = ' + str(len(gnb_markers['SgNBReleaseRequestAcknowledge'])) + ' occurences' - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - statMsg = 'FAILURE = ' + str(len(gnb_markers['FAILURE'])) + ' occurences' - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - statMsg = 'Detected UL Failure on PUSCH = ' + str(len(gnb_markers['Detected UL Failure on PUSCH'])) + ' occurences' - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - - if not showedByeMsg: - logging.debug('\u001B[1;37;41m ' + nodeB_prefix + 'NB did not show "Bye." message at end, it likely did not stop properly! \u001B[0m') - htmleNBFailureMsg += 'No Bye. message found, did not stop properly\n' - global_status = CONST.ENB_SHUTDOWN_NO_BYE - else: - logging.debug('"Bye." message found at end.') - - else: - #Removing UE log - statMsg = '[MAC] Removing UE msg count = '+str(removing_ue) - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - #X2AP-PDU log - statMsg = 'X2AP-PDU msg count = '+str(x2ap_pdu) - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - #nsa markers - statMsg = 'logfile line count = ' + str(line_cnt) - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - if len(gnb_markers['SgNBReleaseRequest'])!=0: - statMsg = 'SgNBReleaseRequest = ' + str(len(gnb_markers['SgNBReleaseRequest'])) + ' occurences , starting line ' + str(gnb_markers['SgNBReleaseRequest'][0]) - else: - statMsg = 'SgNBReleaseRequest = ' + str(len(gnb_markers['SgNBReleaseRequest'])) + ' occurences' - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - statMsg = 'scgFailureInformationNR-r15 = ' + str(len(gnb_markers['scgFailureInformationNR-r15'])) + ' occurences' - htmlMsg = statMsg+'\n' - logging.debug(statMsg) - htmleNBFailureMsg += htmlMsg - - if RealTimeProcessingIssue: - logging.debug('\u001B[1;37;41m ' + nodeB_prefix + 'NB ended with real time processing issue! \u001B[0m') - htmleNBFailureMsg += 'Fail due to real time processing issue\n' - global_status = CONST.ENB_REAL_TIME_PROCESSING_ISSUE - if uciStatMsgCount > 0: - statMsg = nodeB_prefix + 'NB showed ' + str(uciStatMsgCount) + ' "uci->stat" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if pdcpFailure > 0: - statMsg = nodeB_prefix + 'NB showed ' + str(pdcpFailure) + ' "PDCP Out of Resources" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if ulschFailure > 0: - statMsg = nodeB_prefix + 'NB showed ' + str(ulschFailure) + ' "ULSCH in error in round" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if ulschAllocateCCEerror > 0: - statMsg = nodeB_prefix + 'NB showed ' + str(ulschAllocateCCEerror) + ' "eNB_dlsch_ulsch_scheduler(); ERROR ALLOCATING CCEs" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if uplinkSegmentsAborted > 0: - statMsg = nodeB_prefix + 'NB showed ' + str(uplinkSegmentsAborted) + ' "uplink segment error 0/2, aborted * segments" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if dropNotEnoughRBs > 0: - statMsg = 'eNB showed ' + str(dropNotEnoughRBs) + ' "dropping, not enough RBs" message(s)' - logging.debug('\u001B[1;30;43m ' + statMsg + ' \u001B[0m') - htmleNBFailureMsg += statMsg + '\n' - if rrcSetupComplete > 0: - rrcMsg = nodeB_prefix + 'NB completed ' + str(rrcSetupComplete) + ' RRC Connection Setup(s)' - logging.debug('\u001B[1;30;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - rrcMsg = ' -- ' + str(rrcSetupComplete) + ' were completed' - logging.debug('\u001B[1;30;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - if rrcReleaseRequest > 0: - rrcMsg = nodeB_prefix + 'NB requested ' + str(rrcReleaseRequest) + ' RRC Connection Release(s)' - logging.debug('\u001B[1;30;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - if rrcReconfigRequest > 0 or rrcReconfigComplete > 0: - rrcMsg = nodeB_prefix + 'NB requested ' + str(rrcReconfigRequest) + ' RRC Connection Reconfiguration(s)' - logging.debug('\u001B[1;30;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - rrcMsg = ' -- ' + str(rrcReconfigComplete) + ' were completed' - logging.debug('\u001B[1;30;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - if rrcReestablishRequest > 0 or rrcReestablishComplete > 0 or rrcReestablishReject > 0: - rrcMsg = nodeB_prefix + 'NB requested ' + str(rrcReestablishRequest) + ' RRC Connection Reestablishment(s)' - logging.debug('\u001B[1;30;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - rrcMsg = ' -- ' + str(rrcReestablishComplete) + ' were completed' - logging.debug('\u001B[1;30;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - rrcMsg = ' -- ' + str(rrcReestablishReject) + ' were rejected' - logging.debug('\u001B[1;30;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - if self.eNBOptions[0] != '': - res1 = re.search('drx_Config_present prSetup', self.eNBOptions[0]) - if res1 is not None: - if cdrxActivationMessageCount > 0: - rrcMsg = 'eNB activated the CDRX Configuration for ' + str(cdrxActivationMessageCount) + ' time(s)' - logging.debug('\u001B[1;30;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - else: - rrcMsg = 'eNB did NOT ACTIVATE the CDRX Configuration' - logging.debug('\u001B[1;37;43m ' + rrcMsg + ' \u001B[0m') - htmleNBFailureMsg += rrcMsg + '\n' - if rachCanceledProcedure > 0: - rachMsg = nodeB_prefix + 'NB cancelled ' + str(rachCanceledProcedure) + ' RA procedure(s)' - logging.debug('\u001B[1;30;43m ' + rachMsg + ' \u001B[0m') - htmleNBFailureMsg += rachMsg + '\n' - if isRRU: - if isSlave: - if slaveReceivesFrameResyncCmd: - rruMsg = 'Slave RRU received the RRU_frame_resynch command from RAU' - logging.debug('\u001B[1;30;43m ' + rruMsg + ' \u001B[0m') - htmleNBFailureMsg += rruMsg + '\n' - else: - rruMsg = 'Slave RRU DID NOT receive the RRU_frame_resynch command from RAU' - logging.debug('\u001B[1;37;41m ' + rruMsg + ' \u001B[0m') - htmleNBFailureMsg += rruMsg + '\n' - global_status = CONST.ENB_PROCESS_SLAVE_RRU_NOT_SYNCED - if foundSegFault: - logging.debug('\u001B[1;37;41m ' + nodeB_prefix + 'NB ended with a Segmentation Fault! \u001B[0m') - global_status = CONST.ENB_PROCESS_SEG_FAULT - if foundAssertion: - logging.debug('\u001B[1;37;41m ' + nodeB_prefix + 'NB ended with an assertion! \u001B[0m') - htmleNBFailureMsg += msgAssertion - global_status = CONST.ENB_PROCESS_ASSERTION - if foundRealTimeIssue: - logging.debug('\u001B[1;37;41m ' + nodeB_prefix + 'NB faced real time issues! \u001B[0m') - htmleNBFailureMsg += nodeB_prefix + 'NB faced real time issues! COUNT = '+ str(foundRealTimeIssue_cnt) +' lines\n' - if rlcDiscardBuffer > 0: - rlcMsg = nodeB_prefix + 'NB RLC discarded ' + str(rlcDiscardBuffer) + ' buffer(s)' - logging.debug('\u001B[1;37;41m ' + rlcMsg + ' \u001B[0m') - htmleNBFailureMsg += rlcMsg + '\n' - global_status = CONST.ENB_PROCESS_REALTIME_ISSUE - HTML.htmleNBFailureMsg=htmleNBFailureMsg - # Runtime statistics for console output and HTML - if runTime != '': - logging.debug(runTime) - logging.debug(userTime) - logging.debug(systemTime) - logging.debug(maxPhyMemUsage) - logging.debug(nbContextSwitches) - self.runtime_stats='
'+runTime + '\n'+ userTime + '\n' + systemTime + '\n' + maxPhyMemUsage + '\n' + nbContextSwitches+'
' - return global_status