Implement retransmission checker, include unit test

This commit is contained in:
Robert Schmidt
2026-02-26 14:17:28 +01:00
parent fe464ec6d0
commit 707cb560d5
8 changed files with 228 additions and 77 deletions
-2
View File
@@ -267,8 +267,6 @@ class Containerize():
self.dockerfileprefix = ''
self.host = ''
#checkers from xml
self.ran_checkers={}
self.num_attempts = 1
self.flexricTag = ''
+94
View File
@@ -38,3 +38,97 @@ class ContainsString:
if re.search(needle, line):
return True, ""
return False, f"could not find '{needle}' in logs"
class RetxCheck():
def _parseList(s):
if not s:
return []
return [int(n) for n in s.split(",")]
def _get_ul_dl(s):
dl, ul = (None, None)
for o in s.split(";", 1):
if o.startswith("dl="):
dl = o[3:]
elif o.startswith("ul="):
ul = o[3:]
else:
raise ValueError(f"unrecognized option {s}: needs format '[ul=,dl=]X,Y,...[;ul=Z,V,...]'")
return dl, ul
def _parseRetxCheckers(options):
if not "=" in options:
dlul = RetxCheck._parseList(options)
return dlul, dlul
dl, ul = RetxCheck._get_ul_dl(options)
return RetxCheck._parseList(dl), RetxCheck._parseList(ul)
def _analyzeUeRetx(rounds, checkers, regex):
perc = list(0 for i in checkers) # results in %
stats = list(False for i in checkers) # status if succeeded
tmp = re.match(regex, rounds)
if tmp is None:
logging.error('_analyzeUeRetx: did not match regex for DL retx analysis')
return stats
retx_data = [float(x) for x in tmp.groups()]
for i in range(0, len(perc)):
#case where numerator > denumerator with denum ==0 is disregarded, cannot hapen in principle, will lead to 0%
perc[i] = 0 if (retx_data[i] == 0) else 100 * retx_data[i + 1] / retx_data[i]
#treating % > 100 , % > requirement
stats[i] = perc[i] <= 100 and perc[i] <= checkers[i]
return stats
def _filter_retx_rounds(l):
# map to round number if False, else None
l = [i+1 if x is False else None for i, x in enumerate(l)]
# filter out None
return [x for x in l if x is not None]
def run(file, options):
# aggregate statistics per UE
dlsch_ulsch_stats = {}
status = True
with open(file, "r") as f:
for line in f.readlines():
keys = {'dlsch_rounds','ulsch_rounds'}
for k in keys:
result = re.search(k, line)
if result is None:
continue
result = re.search('UE (?:RNTI )?([0-9a-f]{4})', line)
if result is None:
logging.error(f'did not find RNTI while matching key {k}')
status = False
continue
rnti = result.group(1)
if not rnti in dlsch_ulsch_stats:
dlsch_ulsch_stats[rnti] = {}
dlsch_ulsch_stats[rnti][k]=re.sub(r'^.*\]\s+', r'' , line.rstrip())
dl, ul = RetxCheck._parseRetxCheckers(options)
msgs = []
for ue in dlsch_ulsch_stats:
dlulstat = dlsch_ulsch_stats[ue]
for key in dlulstat:
msgs.append(dlulstat[key])
retx_dl = RetxCheck._analyzeUeRetx(dlulstat['dlsch_rounds'], dl, r'^.*dlsch_rounds\s+(\d+)\/(\d+)\/(\d+)\/(\d+),\s+dlsch_errors\s+(\d+)')
retx_ul = RetxCheck._analyzeUeRetx(dlulstat['ulsch_rounds'], ul, r'^.*ulsch_rounds\s+(\d+)\/(\d+)\/(\d+)\/(\d+),\s+ulsch_errors\s+(\d+)')
if False in retx_dl or False in retx_ul:
dlstr = RetxCheck._filter_retx_rounds(retx_dl)
ulstr = RetxCheck._filter_retx_rounds(retx_ul)
msg = f"UE {ue}: retx rounds"
if dlstr:
msg = f"{msg} DL {dlstr}"
if ulstr:
msg = f"{msg} UL {ulstr}"
msg = f"{msg} exceeded threshold"
msgs.append('!!! Failure: ' + msg)
logging.error(f'\u001B[1;37;41m {msg}\u001B[0m')
status = False
else:
msg = f"UE {ue} retransmissions within bounds"
logging.debug(msg)
return status, "\n".join(msgs)
-7
View File
@@ -108,13 +108,6 @@ def ExecuteActionWithParam(action, ctx, node):
success = RAN.InitializeeNB(ctx, node, HTML)
elif action == 'Terminate_eNB':
#retx checkers
string_field = test.findtext('d_retx_th')
if (string_field is not None):
RAN.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):
RAN.ran_checkers['u_retx_th'] = [float(x) for x in string_field.split(',')]
services = []
analysis = test.find("analysis")
if analysis is not None:
-66
View File
@@ -67,8 +67,6 @@ class RANManagement():
self.eNBOptions = ['', '', '']
self.eNBstatuses = [-1, -1, -1]
self.runtime_stats= ''
#checkers from xml
self.ran_checkers={}
self.cmd_prefix = '' # prefix before {lte,nr}-softmodem
self.node = ''
self.command = ''
@@ -176,25 +174,6 @@ class RANManagement():
HTML.CreateHtmlDataLogTable(datalog_rt_stats)
return success
def _analyzeUeRetx(self, rounds, checkers, regex):
if len(rounds) == 0 or len(checkers) == 0:
logging.warning(f'warning: rounds={rounds} checkers={checkers}')
return []
perc = list(0 for i in checkers) # results in %
stats = list(False for i in checkers) # status if succeeded
tmp = re.match(regex, rounds)
if tmp is None:
logging.error('_analyzeUeRetx: did not match regex for DL retx analysis')
return stats
retx_data = [float(x) for x in tmp.groups()]
for i in range(0, len(perc)):
#case where numerator > denumerator with denum ==0 is disregarded, cannot hapen in principle, will lead to 0%
perc[i] = 0 if (retx_data[i] == 0) else 100 * retx_data[i + 1] / retx_data[i]
#treating % > 100 , % > requirement
stats[i] = perc[i] <= 100 and perc[i] <= checkers[i]
return stats
def AnalyzeLogFile_eNB(self, eNBlogFile, HTML, checkers={}):
if (not os.path.isfile(eNBlogFile)):
return -1
@@ -239,8 +218,6 @@ class RANManagement():
nbContextSwitches = ''
#NSA FR1 check
NSA_RAPROC_PUSCH_check = 0
#dlsch and ulsch statistics (dictionary)
dlsch_ulsch_stats = {}
#count "problem receiving samples" msg
pb_receiving_samples_cnt = 0
#count "removing UE" msg
@@ -392,22 +369,6 @@ class RANManagement():
if result is not None:
NSA_RAPROC_PUSCH_check = 1
# Collect information on UE DLSCH and ULSCH statistics
keys = {'dlsch_rounds','ulsch_rounds'}
for k in keys:
result = re.search(k, line)
if result is None:
continue
result = re.search('UE (?:RNTI )?([0-9a-f]{4})', line)
if result is None:
logging.error(f'did not find RNTI while matching key {k}')
continue
rnti = result.group(1)
#remove 1- all useless char before relevant info (ulsch or dlsch) 2- trailing char
if not rnti in dlsch_ulsch_stats: dlsch_ulsch_stats[rnti] = {}
dlsch_ulsch_stats[rnti][k]=re.sub(r'^.*\]\s+', r'' , line.rstrip())
result = re.search('Received NR_RRCReconfigurationComplete from UE', str(line))
if result is not None:
nrRrcRcfgComplete += 1
@@ -505,23 +466,6 @@ class RANManagement():
logging.debug(statMsg)
htmleNBFailureMsg += htmlMsg
#ulsch and dlsch statistics and checkers
for ue in dlsch_ulsch_stats:
dlulstat = dlsch_ulsch_stats[ue]
#print statistics into html
statMsg=''
for key in dlulstat:
statMsg += dlulstat[key] + '\n'
logging.debug(dlulstat[key])
htmleNBFailureMsg += statMsg
retx_status[ue] = {}
dlcheckers = [] if 'd_retx_th' not in checkers else checkers['d_retx_th']
retx_status[ue]['dl'] = self._analyzeUeRetx(dlulstat['dlsch_rounds'], dlcheckers, r'^.*dlsch_rounds\s+(\d+)\/(\d+)\/(\d+)\/(\d+),\s+dlsch_errors\s+(\d+)')
ulcheckers = [] if 'u_retx_th' not in checkers else checkers['u_retx_th']
retx_status[ue]['ul'] = self._analyzeUeRetx(dlulstat['ulsch_rounds'], ulcheckers, r'^.*ulsch_rounds\s+(\d+)\/(\d+)\/(\d+)\/(\d+),\s+ulsch_errors\s+(\d+)')
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'
@@ -557,16 +501,6 @@ class RANManagement():
logging.debug(statMsg)
htmleNBFailureMsg += htmlMsg
for ue in retx_status:
msg = f"retransmissions for UE {ue}: DL {retx_status[ue]['dl']} UL {retx_status[ue]['ul']}"
if False in retx_status[ue]['dl'] or False in retx_status[ue]['ul']:
msg = 'Failure: ' + msg
logging.error(f'\u001B[1;37;41m {msg}\u001B[0m')
htmleNBFailureMsg += f'{msg}\n'
global_status = CONST.ENB_RETX_ISSUE
else:
logging.debug(msg)
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'
+72
View File
@@ -12,6 +12,9 @@ sys.path.append('./') # to find OAI imports below
import cls_loganalysis
class TestLogAnalysis(unittest.TestCase):
def setUp(self):
self.maxDiff = None
def test_no_file(self):
f = "/total/fantasy/path/file.log"
result, _ = cls_loganalysis.Default.run(f, None)
@@ -22,5 +25,74 @@ class TestLogAnalysis(unittest.TestCase):
result, _ = cls_loganalysis.Default.run(f, None)
self.assertTrue(result)
def test_retx_check_good(self):
f = "tests/log-analysis/retx-check-good.log"
opt = "dl=1,0,0,0;ul=1,0,0,0"
result, log = cls_loganalysis.RetxCheck.run(f, opt)
expected = """UE f40a: dlsch_rounds 86/0/0/0, dlsch_errors 0, pucch0_DTX 0, BLER 0.00052 MCS (0) 0 CCE fail 3
UE f40a: ulsch_rounds 518/0/0/0, ulsch_errors 0, ulsch_DTX 0, BLER 0.00000 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 5 SNR 51.0 dB CCE fail 0"""
self.assertTrue(result)
self.assertEqual(log, expected)
def test_retx_check_good_single_val(self):
f = "tests/log-analysis/retx-check-good.log"
opt = "1,0,0,0"
result, log = cls_loganalysis.RetxCheck.run(f, opt)
expected = """UE f40a: dlsch_rounds 86/0/0/0, dlsch_errors 0, pucch0_DTX 0, BLER 0.00052 MCS (0) 0 CCE fail 3
UE f40a: ulsch_rounds 518/0/0/0, ulsch_errors 0, ulsch_DTX 0, BLER 0.00000 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 5 SNR 51.0 dB CCE fail 0"""
self.assertTrue(result)
self.assertEqual(log, expected)
def test_retx_check_good_ul_only(self):
f = "tests/log-analysis/retx-check-good.log"
opt = "ul=1,0,0,0"
result, log = cls_loganalysis.RetxCheck.run(f, opt)
expected = """UE f40a: dlsch_rounds 86/0/0/0, dlsch_errors 0, pucch0_DTX 0, BLER 0.00052 MCS (0) 0 CCE fail 3
UE f40a: ulsch_rounds 518/0/0/0, ulsch_errors 0, ulsch_DTX 0, BLER 0.00000 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 5 SNR 51.0 dB CCE fail 0"""
self.assertTrue(result)
self.assertEqual(log, expected)
def test_retx_check_bad(self):
f = "tests/log-analysis/retx-check-bad.log"
opt = "dl=10,100,100,100;ul=10,100,100,100"
result, log = cls_loganalysis.RetxCheck.run(f, opt)
expected = """UE a491: dlsch_rounds 13/1/0/0, dlsch_errors 0, pucch0_DTX 0, BLER 0.11000 MCS (0) 0 CCE fail 0
UE a491: ulsch_rounds 23/1/0/0, ulsch_errors 0, ulsch_DTX 1, BLER 0.08447 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 5 SNR 34.0 dB CCE fail 0
UE bf9b: dlsch_rounds 370/368/368/368, dlsch_errors 368, pucch0_DTX 1377, BLER 1.00000 MCS (0) 0 CCE fail 64
UE bf9b: ulsch_rounds 150/148/147/147, ulsch_errors 147, ulsch_DTX 589, BLER 1.00000 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 104 SNR 38.0 dB CCE fail 0
!!! Failure: UE bf9b: retx rounds DL [1] UL [1] exceeded threshold
UE 257a: dlsch_rounds 68071/142/14/0, dlsch_errors 0, pucch0_DTX 10, BLER 0.00427 MCS (1) 25 CCE fail 0
UE 257a: ulsch_rounds 41777/2863/10/0, ulsch_errors 0, ulsch_DTX 17, BLER 0.11456 MCS (1) 10 (Qm 4 deltaMCS 0 dB) NPRB 5 SNR 29.0 dB CCE fail 0"""
self.assertFalse(result)
self.assertEqual(log, expected)
def test_retx_check_dl_only_bad(self):
f = "tests/log-analysis/retx-check-bad.log"
opt = "dl=10,80,100,100"
result, log = cls_loganalysis.RetxCheck.run(f, opt)
expected = """UE a491: dlsch_rounds 13/1/0/0, dlsch_errors 0, pucch0_DTX 0, BLER 0.11000 MCS (0) 0 CCE fail 0
UE a491: ulsch_rounds 23/1/0/0, ulsch_errors 0, ulsch_DTX 1, BLER 0.08447 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 5 SNR 34.0 dB CCE fail 0
UE bf9b: dlsch_rounds 370/368/368/368, dlsch_errors 368, pucch0_DTX 1377, BLER 1.00000 MCS (0) 0 CCE fail 64
UE bf9b: ulsch_rounds 150/148/147/147, ulsch_errors 147, ulsch_DTX 589, BLER 1.00000 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 104 SNR 38.0 dB CCE fail 0
!!! Failure: UE bf9b: retx rounds DL [1, 2] exceeded threshold
UE 257a: dlsch_rounds 68071/142/14/0, dlsch_errors 0, pucch0_DTX 10, BLER 0.00427 MCS (1) 25 CCE fail 0
UE 257a: ulsch_rounds 41777/2863/10/0, ulsch_errors 0, ulsch_DTX 17, BLER 0.11456 MCS (1) 10 (Qm 4 deltaMCS 0 dB) NPRB 5 SNR 29.0 dB CCE fail 0"""
self.assertFalse(result)
self.assertEqual(log, expected)
def test_retx_check_ul_bad(self):
f = "tests/log-analysis/retx-check-bad.log"
opt = "dl=100,100,100,100;ul=10,100,100,100"
result, log = cls_loganalysis.RetxCheck.run(f, opt)
expected = """UE a491: dlsch_rounds 13/1/0/0, dlsch_errors 0, pucch0_DTX 0, BLER 0.11000 MCS (0) 0 CCE fail 0
UE a491: ulsch_rounds 23/1/0/0, ulsch_errors 0, ulsch_DTX 1, BLER 0.08447 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 5 SNR 34.0 dB CCE fail 0
UE bf9b: dlsch_rounds 370/368/368/368, dlsch_errors 368, pucch0_DTX 1377, BLER 1.00000 MCS (0) 0 CCE fail 64
UE bf9b: ulsch_rounds 150/148/147/147, ulsch_errors 147, ulsch_DTX 589, BLER 1.00000 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 104 SNR 38.0 dB CCE fail 0
!!! Failure: UE bf9b: retx rounds UL [1] exceeded threshold
UE 257a: dlsch_rounds 68071/142/14/0, dlsch_errors 0, pucch0_DTX 10, BLER 0.00427 MCS (1) 25 CCE fail 0
UE 257a: ulsch_rounds 41777/2863/10/0, ulsch_errors 0, ulsch_DTX 17, BLER 0.11456 MCS (1) 10 (Qm 4 deltaMCS 0 dB) NPRB 5 SNR 29.0 dB CCE fail 0"""
self.assertFalse(result)
self.assertEqual(log, expected)
if __name__ == '__main__':
unittest.main()
@@ -0,0 +1,54 @@
9185541.336575 [NR_RRC] I UE 1 Logical Channel DL-DCCH, Generate SecurityModeCommand (bytes 3)
9185541.356794 [NR_RRC] A [UL] (cellID bc614e, UE ID 1 RNTI a491) Received Security Mode Complete
9185541.357264 [NR_RRC] I UE 1: Logical Channel DL-DCCH, Generate NR UECapabilityEnquiry (bytes 8, xid 2)
9185541.373199 [NR_RRC] A [UL] (cellID bc614e, UE ID 1 RNTI a491) Received UE capabilities
9185541.373330 [NR_RRC] I Send message to ngap: NGAP_UE_CAPABILITIES_IND
9185541.373356 [NR_RRC] A [DL] (cellID bc614e, UE ID 1 RNTI a491) Send DL Information Transfer [53 bytes]
9185541.373368 [NR_RRC] I Send message to sctp: NGAP_InitialContextSetupResponse
9185541.390034 [NR_MAC] I Frame.Slot 384.0
UE RNTI a491 CU-UE-ID 1 in-sync PH 59 dB PCMAX 21 dBm, average RSRP -101 (4 meas)
UE a491: CQI 2, RI 2, PMI (0,0)
UE a491: dlsch_rounds 13/1/0/0, dlsch_errors 0, pucch0_DTX 0, BLER 0.11000 MCS (0) 0 CCE fail 0
UE a491: ulsch_rounds 23/1/0/0, ulsch_errors 0, ulsch_DTX 1, BLER 0.08447 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 5 SNR 34.0 dB CCE fail 0
UE a491: MAC: TX 367 RX 3664 bytes
UE a491: LCID 1: TX 213 RX 1649 bytes
9185559.310044 [NR_MAC] I Frame.Slot 128.0
UE RNTI bf9b CU-UE-ID 1 in-sync PH 48 dB PCMAX 21 dBm
UE bf9b: dlsch_rounds 370/368/368/368, dlsch_errors 368, pucch0_DTX 1377, BLER 1.00000 MCS (0) 0 CCE fail 64
UE bf9b: ulsch_rounds 150/148/147/147, ulsch_errors 147, ulsch_DTX 589, BLER 1.00000 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 104 SNR 38.0 dB CCE fail 0
UE bf9b: MAC: TX 10145 RX 82 bytes
UE bf9b: LCID 1: TX 5283 RX 53 bytes
9185582.350069 [NR_MAC] I Frame.Slot 384.0
UE RNTI 257a CU-UE-ID 2 in-sync PH 48 dB PCMAX 21 dBm, average RSRP -83 (16 meas)
UE 257a: CQI 15, RI 2, PMI (0,1)
UE 257a: UL-RI 2, TPMI 0
UE 257a: dlsch_rounds 153/1/0/0, dlsch_errors 0, pucch0_DTX 0, BLER 0.00000 MCS (1) 0 CCE fail 0
UE 257a: ulsch_rounds 562/2/1/0, ulsch_errors 0, ulsch_DTX 3, BLER 0.00000 MCS (1) 0 (Qm 2 deltaMCS 0 dB) NPRB 5 SNR 29.5 dB CCE fail 0
UE 257a: MAC: TX 13416 RX 26519 bytes
UE 257a: LCID 1: TX 523 RX 2046 bytes
UE 257a: LCID 2: TX 0 RX 0 bytes
UE 257a: LCID 4: TX 9800 RX 9945 bytes
9185687.310202 [NR_MAC] I Frame.Slot 640.0
UE RNTI 257a CU-UE-ID 2 in-sync PH 61 dB PCMAX 21 dBm, average RSRP -83 (16 meas)
UE 257a: CQI 15, RI 2, PMI (0,1)
UE 257a: UL-RI 2, TPMI 0
UE 257a: dlsch_rounds 64992/129/13/0, dlsch_errors 0, pucch0_DTX 10, BLER 0.00242 MCS (1) 27 CCE fail 0
UE 257a: ulsch_rounds 39328/2610/8/0, ulsch_errors 0, ulsch_DTX 14, BLER 0.11139 MCS (1) 9 (Qm 4 deltaMCS 0 dB) NPRB 273 SNR 25.5 dB CCE fail 0
UE 257a: MAC: TX 3344707955 RX 818603547 bytes
UE 257a: LCID 1: TX 832 RX 4312 bytes
UE 257a: LCID 2: TX 0 RX 0 bytes
UE 257a: LCID 4: TX 3322610250 RX 815642955 bytes
9185692.430254 [NR_MAC] I Frame.Slot 128.0
UE RNTI 257a CU-UE-ID 2 in-sync PH 48 dB PCMAX 21 dBm, average RSRP -84 (16 meas)
UE 257a: CQI 15, RI 2, PMI (0,1)
UE 257a: UL-RI 2, TPMI 0
UE 257a: dlsch_rounds 68071/142/14/0, dlsch_errors 0, pucch0_DTX 10, BLER 0.00427 MCS (1) 25 CCE fail 0
UE 257a: ulsch_rounds 41777/2863/10/0, ulsch_errors 0, ulsch_DTX 17, BLER 0.11456 MCS (1) 10 (Qm 4 deltaMCS 0 dB) NPRB 5 SNR 29.0 dB CCE fail 0
UE 257a: MAC: TX 3424886787 RX 879242724 bytes
UE 257a: LCID 1: TX 847 RX 4422 bytes
UE 257a: LCID 2: TX 0 RX 0 bytes
UE 257a: LCID 4: TX 3401067134 RX 875911216 bytes
@@ -0,0 +1,8 @@
7799905.793901 [NR_MAC] I Frame.Slot 256.0
UE RNTI f40a CU-UE-ID 2 in-sync PH 48 dB PCMAX 20 dBm, average RSRP -44 (16 meas)
UE f40a: dlsch_rounds 86/0/0/0, dlsch_errors 0, pucch0_DTX 0, BLER 0.00052 MCS (0) 0 CCE fail 3
UE f40a: ulsch_rounds 518/0/0/0, ulsch_errors 0, ulsch_DTX 0, BLER 0.00000 MCS (0) 0 (Qm 2 deltaMCS 0 dB) NPRB 5 SNR 51.0 dB CCE fail 0
UE f40a: MAC: TX 3836 RX 13684 bytes
UE f40a: LCID 1: TX 530 RX 281 bytes
UE f40a: LCID 2: TX 3 RX 35 bytes
UE f40a: LCID 4: TX 1886 RX 2100 bytes
@@ -113,8 +113,6 @@
<desc>Undeploy all OAI 5G stack</desc>
<node>localhost</node>
<yaml_path>ci-scripts/yaml_files/5g_fdd_rfsimulator</yaml_path>
<d_retx_th>1,0,0,0</d_retx_th>
<u_retx_th>1,0,0,0</u_retx_th>
</testCase>
<testCase>