Build failed in Jenkins: ttcn3-pcu-test-asan #137 - jenkins-notifications

24 Oct 2024

See
<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/137/display/redirect>

Changes:


------------------------------------------
[...truncated 45.14 MiB...]
[1;32m20241024140021714 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=7,ts=7) FN=91 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021715 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=0,ts=7) FN=95 RX RTS.req: sapi=5 arfcn=871 cur_fn=91 block=10
(pcu_l1_if.cpp:576)[0;m
[0;36m20241024140021715 [1;34mDRLCMACSCHED[0;m[0;36m [1;34mDEBUG[0;m[0;36m
PDCH(bts=0,trx=0,ts=7) Received RTS for PDCH: FN=95 block_nr=10 scheduling USF=0 for
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW}, expect answer on UL FN=99
(gprs_rlcmac_sched.cpp:454)[0;m
[0;33m20241024140021715 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) Reserving FN 99 for type USF (pdch_ul_controller.c:184)[0;m
[1;37m20241024140021715 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){TX_NEIGHBOUR_DATA}: Received Event CREATE_RLCMAC_MSG
(gprs_ms.c:1078)[0;m
[1;37m20241024140021715 [1;34mDNACC[0;m[1;37m [1;34mDEBUG[0;m[1;37m
+++++++++++++++++++++++++ TX : Packet Neighbour Cell Data +++++++++++++++++++++++++
(nacc_fsm.c:139)[0;m
[1;31m20241024140021715 [1;32mDCSN1[0;m[1;31m [1;32mINFO[0;m[1;31m csnStreamEncoder
(type: Pkt Neightbour Cell Data (12)): [0;m[1;31mMESSAGE_TYPE = 12 |
[0;m[1;31mPAGE_MODE = 0 | [0;m[1;31m0x00 = 0 | [0;m[1;31m : Global_TFI |
[0;m[1;31mu.UPLINK_TFI = 0 | [0;m[1;31mu.UPLINK_TFI = 0 | [0;m[1;31m : End
Global_TFI | [0;m[1;31mCONTAINER_ID = 0 | [0;m[1;31mspare = 0 |
[0;m[1;31mCONTAINER_INDEX = 3 | [0;m[1;31m : Container |
[0;m[1;31mu.PNCD_Container_Without_ID = 0 | [0;m[1;31m : u.PNCD_Container_Without_ID |
[0;m[1;31mCONTAINER = 11 | [0;m[1;31mCONTAINER = 171 | [0;m[1;31mCONTAINER = 43 |
[0;m[1;31mCONTAINER = 43 | [0;m[1;31mCONTAINER = 43 | [0;m[1;31mCONTAINER = 43 |
[0;m[1;31mCONTAINER = 43 | [0;m[1;31mCONTAINER = 43 | [0;m[1;31mCONTAINER = 43 |
[0;m[1;31mCONTAINER = 43 | [0;m[1;31mCONTAINER = 43 | [0;m[1;31mCONTAINER = 43 |
[0;m[1;31mCONTAINER = 0 | [0;m[1;31mCONTAINER = 0 | [0;m[1;31mCONTAINER = 0 |
[0;m[1;31mCONTAINER = 0 | [0;m[1;31mCONTAINER = 0 | [0;m[1;31mCONTAINER = 0 |
[0;m[1;31mCONTAINER = 0 | [0;m[1;31m : End u.PNCD_Container_Without_ID | [0;m[1;31m
: End Container | [0;m[1;31mPadding = [0;m[1;31m (gsm_rlcmac.c:6009)[0;m
[1;37m20241024140021716 [1;34mDNACC[0;m[1;37m [1;34mDEBUG[0;m[1;37m
------------------------- TX : Packet Neighbour Cell Data -------------------------
(nacc_fsm.c:145)[0;m
[1;37m20241024140021716 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){TX_NEIGHBOUR_DATA}: state_chg to TX_CELL_CHG_CONTINUE
(nacc_fsm.c:620)[0;m
[0;36m20241024140021716 [1;34mDRLCMACSCHED[0;m[0;36m [1;34mDEBUG[0;m[0;36m
PDCH(bts=0,trx=0,ts=7) FN=95 Scheduling control message at RTS for
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW} (gprs_rlcmac_sched.cpp:202)[0;m
[1;32m20241024140021716 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=0,ts=7) FN=95 Sending data request: sapi=5 arfcn=871 cur_fn=91 block=10 data=40
30 00 06 0b ab 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00 00 00 00 00 00 00 
(pcu_l1_if.cpp:182)[0;m
[1;32m20241024140021716 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m Time indication
received: 43 (pcu_l1_if.cpp:1048)[0;m
[1;32m20241024140021727 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=0,ts=7) FN=95 Rx DATA.ind: sapi=5 arfcn=871 cur_fn=91 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021727 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=0,ts=7) FN=95 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[0;33m20241024140021727 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) Timeout for registered USF (FN=95):
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW} (pdch_ul_controller.c:309)[0;m
[1;34m20241024140021727 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW} N3101 2 => 3 (< MAX 10)
(tbf.cpp:362)[0;m
[1;32m20241024140021729 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=1,ts=7) FN=95 Rx DATA.ind: sapi=5 arfcn=872 cur_fn=95 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021729 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=1,ts=7) FN=95 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021730 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=2,ts=7) FN=95 Rx DATA.ind: sapi=5 arfcn=873 cur_fn=95 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021730 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=2,ts=7) FN=95 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021731 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=3,ts=7) FN=95 Rx DATA.ind: sapi=5 arfcn=874 cur_fn=95 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021731 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=3,ts=7) FN=95 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021732 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=4,ts=7) FN=95 Rx DATA.ind: sapi=5 arfcn=875 cur_fn=95 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021732 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=4,ts=7) FN=95 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021733 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=5,ts=7) FN=95 Rx DATA.ind: sapi=5 arfcn=876 cur_fn=95 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021733 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=5,ts=7) FN=95 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021733 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=6,ts=7) FN=95 Rx DATA.ind: sapi=5 arfcn=877 cur_fn=95 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021733 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=6,ts=7) FN=95 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021734 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=7,ts=7) FN=95 Rx DATA.ind: sapi=5 arfcn=878 cur_fn=95 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021734 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=7,ts=7) FN=95 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021735 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=0,ts=7) FN=99 RX RTS.req: sapi=5 arfcn=871 cur_fn=95 block=11
(pcu_l1_if.cpp:576)[0;m
[0;36m20241024140021735 [1;34mDRLCMACSCHED[0;m[0;36m [1;34mDEBUG[0;m[0;36m
PDCH(bts=0,trx=0,ts=7) Received RTS for PDCH: FN=99 block_nr=11 scheduling USF=0 for
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW}, expect answer on UL FN=104
(gprs_rlcmac_sched.cpp:454)[0;m
[0;33m20241024140021735 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) Reserving FN 104 for type USF (pdch_ul_controller.c:184)[0;m
[1;37m20241024140021735 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){TX_CELL_CHG_CONTINUE}: Received Event CREATE_RLCMAC_MSG
(gprs_ms.c:1078)[0;m
[0;33m20241024140021735 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 99 + 13 = 112 (pdch_ul_controller.c:131)[0;m
[1;37m20241024140021735 [1;34mDNACC[0;m[1;37m [1;34mDEBUG[0;m[1;37m
+++++++++++++++++++++++++ TX : Packet Cell Change Continue +++++++++++++++++++++++++
(nacc_fsm.c:196)[0;m
[1;31m20241024140021735 [1;32mDCSN1[0;m[1;31m [1;32mINFO[0;m[1;31m csnStreamEncoder
(type: Pkt Cell Change Continue (11)): [0;m[1;31mMESSAGE_TYPE = 11 |
[0;m[1;31mPAGE_MODE = 0 | [0;m[1;31m0x00 = 0 | [0;m[1;31m : Global_TFI |
[0;m[1;31mu.UPLINK_TFI = 0 | [0;m[1;31mu.UPLINK_TFI = 0 | [0;m[1;31m : End
Global_TFI | [0;m[1;31mExist_ID = 1 | [0;m[1;31mARFCN = 862 | [0;m[1;31mBSIC = 43 |
[0;m[1;31mCONTAINER_ID = 0 | [0;m[1;31mPadding =
[0;m[1;31m11|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m
(gsm_rlcmac.c:6009)[0;m
[1;37m20241024140021736 [1;34mDNACC[0;m[1;37m [1;34mDEBUG[0;m[1;37m
------------------------- TX : Packet Cell Change Continue -------------------------
(nacc_fsm.c:202)[0;m
[0;33m20241024140021736 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) Reserving FN 112 for type POLL (pdch_ul_controller.c:184)[0;m
[1;34m20241024140021736 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW} Scheduled 'Packet Cell Change Continue'
polling on PACCH (FN=112, TS=7) (nacc_fsm.c:206)[0;m
[1;37m20241024140021736 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){TX_CELL_CHG_CONTINUE}: state_chg to WAIT_CELL_CHG_CONTINUE_ACK
(nacc_fsm.c:649)[0;m
[0;36m20241024140021736 [1;34mDRLCMACSCHED[0;m[0;36m [1;34mDEBUG[0;m[0;36m
PDCH(bts=0,trx=0,ts=7) FN=99 Scheduling control message at RTS for
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW} (gprs_rlcmac_sched.cpp:202)[0;m
[1;32m20241024140021736 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=0,ts=7) FN=99 Sending data request: sapi=5 arfcn=871 cur_fn=95 block=11 data=48
2c 01 d7 ab 0b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
(pcu_l1_if.cpp:182)[0;m
[1;32m20241024140021736 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m Time indication
received: 47 (pcu_l1_if.cpp:1048)[0;m
BTS(1073)@9541a9c1d226: Warning: dec_RlcmacDlCtrlBlock(): Data remained at the end of the
stream after successful decoding: '0B2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B'O
("\v+++++++++++++++++")
[1;32m20241024140021747 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=0,ts=7) FN=99 Rx DATA.ind: sapi=5 arfcn=871 cur_fn=95 block=11 data=40 30 06 bd
58 00 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b  (pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021747 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=0,ts=7) FN=99 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 0
(pcu_l1_if.cpp:478)[0;m
[1;36m20241024140021747 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m
PDCH(bts=0,trx=0,ts=7) Got RLC block, coding scheme: CS-1, length: 23 (23))
(pdch.cpp:983)[0;m
[0;33m20241024140021747 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) FN=99 +++++++++++++++++++++++++ RX : Uplink Control Block
+++++++++++++++++++++++++ (pdch.cpp:914)[0;m
[1;31m20241024140021747 [1;32mDCSN1[0;m[1;31m [1;32mINFO[0;m[1;31m csnStreamDecoder
(type: Pkt Cell Change Notification (12)): [0;m[1;31mPayloadType = 1 | [0;m[1;31mspare
= 0 | [0;m[1;31mR = 0 | [0;m[1;31mMESSAGE_TYPE = 12 | [0;m[1;31m : Global_TFI |
[0;m[1;31mu.UPLINK_TFI = 0 | [0;m[1;31mu.UPLINK_TFI = 0 | [0;m[1;31m: End Global_TFI
| [0;m[1;31m : Target_Cell | [0;m[1;31mu.Target_Cell_GSM_Notif = 0 | [0;m[1;31m :
u.Target_Cell_GSM_Notif | [0;m[1;31mARFCN = 862 | [0;m[1;31mBSIC = 43 | [0;m[1;31m :
End u.Target_Cell_GSM_Notif | [0;m[1;31m: End Target_Cell | [0;m[1;31mu.BA_IND = 0 |
[0;m[1;31mu.BA_IND = 0 | [0;m[1;31mPMO_USED = 0 | [0;m[1;31mPCCN_SENDING = 0 |
[0;m[1;31m : CCN_Measurement_Report | [0;m[1;31mRXLEV_SERVING_CELL = 0 | [0;m[1;31m0
= 0 | [0;m[1;31mNUMBER_OF_NC_MEASUREMENTS = 0 | [0;m[1;31m: End CCN_Measurement_Report
| [0;m[1;31mExist_AdditionsR6 = 0 | [0;m[1;31mPadding =
[0;m[1;31m0|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m
(gsm_rlcmac.c:5476)[0;m
[0;33m20241024140021748 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) FN=99 ------------------------- RX : Uplink Control Block
------------------------- (pdch.cpp:927)[0;m
[1;37m20241024140021748 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){WAIT_CELL_CHG_CONTINUE_ACK}: Received Event RX_CELL_CHG_NOTIFICATION
(gprs_ms.c:1052)[0;m
[1;37m20241024140021748 [1;33mDNACC[0;m[1;37m [1;33mNOTICE[0;m[1;37m
NACC(TLLI-0x00000001){WAIT_CELL_CHG_CONTINUE_ACK}: TargetCell: RAT=GSM, ARFCN=862, BSIC=43
(nacc_fsm.c:291)[0;m
[1;32m20241024140021750 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=1,ts=7) FN=99 Rx DATA.ind: sapi=5 arfcn=872 cur_fn=99 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021750 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=1,ts=7) FN=99 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021752 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=2,ts=7) FN=99 Rx DATA.ind: sapi=5 arfcn=873 cur_fn=99 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021752 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=2,ts=7) FN=99 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021753 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=3,ts=7) FN=99 Rx DATA.ind: sapi=5 arfcn=874 cur_fn=99 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021753 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=3,ts=7) FN=99 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021754 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=4,ts=7) FN=99 Rx DATA.ind: sapi=5 arfcn=875 cur_fn=99 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021754 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=4,ts=7) FN=99 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021754 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=5,ts=7) FN=99 Rx DATA.ind: sapi=5 arfcn=876 cur_fn=99 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021754 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=5,ts=7) FN=99 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021754 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=6,ts=7) FN=99 Rx DATA.ind: sapi=5 arfcn=877 cur_fn=99 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021755 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=6,ts=7) FN=99 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021755 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=7,ts=7) FN=99 Rx DATA.ind: sapi=5 arfcn=878 cur_fn=99 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021755 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=7,ts=7) FN=99 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021756 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m Time indication
received: 0 (pcu_l1_if.cpp:1048)[0;m
[1;32m20241024140021771 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=0,ts=7) FN=104 Rx DATA.ind: sapi=5 arfcn=871 cur_fn=99 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021771 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=0,ts=7) FN=104 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[0;33m20241024140021772 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) Timeout for registered USF (FN=104):
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW} (pdch_ul_controller.c:309)[0;m
[1;34m20241024140021772 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW} N3101 3 => 4 (< MAX 10)
(tbf.cpp:362)[0;m
[1;32m20241024140021773 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=1,ts=7) FN=104 Rx DATA.ind: sapi=5 arfcn=872 cur_fn=104 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021773 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=1,ts=7) FN=104 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021774 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=2,ts=7) FN=104 Rx DATA.ind: sapi=5 arfcn=873 cur_fn=104 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021774 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=2,ts=7) FN=104 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021775 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=3,ts=7) FN=104 Rx DATA.ind: sapi=5 arfcn=874 cur_fn=104 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021775 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=3,ts=7) FN=104 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021775 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=4,ts=7) FN=104 Rx DATA.ind: sapi=5 arfcn=875 cur_fn=104 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021775 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=4,ts=7) FN=104 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021776 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=5,ts=7) FN=104 Rx DATA.ind: sapi=5 arfcn=876 cur_fn=104 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021776 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=5,ts=7) FN=104 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021777 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=6,ts=7) FN=104 Rx DATA.ind: sapi=5 arfcn=877 cur_fn=104 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021777 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=6,ts=7) FN=104 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021778 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=7,ts=7) FN=104 Rx DATA.ind: sapi=5 arfcn=878 cur_fn=104 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021778 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=7,ts=7) FN=104 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021779 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m Time indication
received: 4 (pcu_l1_if.cpp:1048)[0;m
[1;32m20241024140021790 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=0,ts=7) FN=108 Rx DATA.ind: sapi=5 arfcn=871 cur_fn=104 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021790 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=0,ts=7) FN=108 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021791 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=1,ts=7) FN=108 Rx DATA.ind: sapi=5 arfcn=872 cur_fn=108 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021791 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=1,ts=7) FN=108 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021792 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=2,ts=7) FN=108 Rx DATA.ind: sapi=5 arfcn=873 cur_fn=108 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021792 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=2,ts=7) FN=108 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021792 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=3,ts=7) FN=108 Rx DATA.ind: sapi=5 arfcn=874 cur_fn=108 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021792 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=3,ts=7) FN=108 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021793 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=4,ts=7) FN=108 Rx DATA.ind: sapi=5 arfcn=875 cur_fn=108 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021793 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=4,ts=7) FN=108 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021794 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=5,ts=7) FN=108 Rx DATA.ind: sapi=5 arfcn=876 cur_fn=108 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021794 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=5,ts=7) FN=108 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021795 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=6,ts=7) FN=108 Rx DATA.ind: sapi=5 arfcn=877 cur_fn=108 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021795 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=6,ts=7) FN=108 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021795 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=7,ts=7) FN=108 Rx DATA.ind: sapi=5 arfcn=878 cur_fn=108 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021795 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=7,ts=7) FN=108 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021796 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m Time indication
received: 8 (pcu_l1_if.cpp:1048)[0;m
[1;32m20241024140021809 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=0,ts=7) FN=112 Rx DATA.ind: sapi=5 arfcn=871 cur_fn=108 block=2 data=40 04 00
00 00 07 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b  (pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021809 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=0,ts=7) FN=112 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 0
(pcu_l1_if.cpp:478)[0;m
[1;36m20241024140021809 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m
PDCH(bts=0,trx=0,ts=7) Got RLC block, coding scheme: CS-1, length: 23 (23))
(pdch.cpp:983)[0;m
[0;33m20241024140021809 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) FN=112 +++++++++++++++++++++++++ RX : Uplink Control Block
+++++++++++++++++++++++++ (pdch.cpp:914)[0;m
[1;31m20241024140021809 [1;32mDCSN1[0;m[1;31m [1;32mINFO[0;m[1;31m csnStreamDecoder
(type: Pkt Control Ack (1)): [0;m[1;31mPayloadType = 1 | [0;m[1;31mspare = 0 |
[0;m[1;31mR = 0 | [0;m[1;31mMESSAGE_TYPE = 1 | [0;m[1;31mTLLI = 0x00000001 |
[0;mBTS(1073)@9541a9c1d226: Shutting down virtual BTS #0...
[1;31mCTRL_ACK = 3 | [0;m[1;31mExist_AdditionsR5 = 0 | [0;m[1;31mPadding =
[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m43|[0;m[1;31m
(gsm_rlcmac.c:5476)[0;m
[0;33m20241024140021809 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) FN=112 ------------------------- RX : Uplink Control Block
------------------------- (pdch.cpp:927)[0;m
[1;34m20241024140021810 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW} FN=112 Rx Packet Control Ack
(reason=CELL_CHG_CONTINUE) (pdch.cpp:363)[0;m
[1;37m20241024140021810 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){WAIT_CELL_CHG_CONTINUE_ACK}: Received Event RX_CELL_CHG_CONTINUE_ACK
(pdch.cpp:449)[0;m
[1;37m20241024140021810 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){WAIT_CELL_CHG_CONTINUE_ACK}: state_chg to DONE
(nacc_fsm.c:671)[0;m
[1;37m20241024140021810 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
(nacc_fsm.c:681)[0;m
[1;37m20241024140021810 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){DONE}: Freeing instance (nacc_fsm.c:681)[0;m
[1;37m20241024140021810 [1;32mDNACC[0;m[1;37m [1;32mINFO[0;m[1;37m
NACC(TLLI-0x00000001){DONE}: Deallocated (fsm.c:568)[0;m
[1;32m20241024140021811 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=1,ts=7) FN=112 Rx DATA.ind: sapi=5 arfcn=872 cur_fn=112 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021811 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=1,ts=7) FN=112 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021812 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=2,ts=7) FN=112 Rx DATA.ind: sapi=5 arfcn=873 cur_fn=112 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021812 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=2,ts=7) FN=112 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021814 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=3,ts=7) FN=112 Rx DATA.ind: sapi=5 arfcn=874 cur_fn=112 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021814 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=3,ts=7) FN=112 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
20241024140021814 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Closing telnet connection
r=127.0.0.1:44156<->l=127.0.0.1:4240 (telnet_interface.c:138)
[1;32m20241024140021815 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=4,ts=7) FN=112 Rx DATA.ind: sapi=5 arfcn=875 cur_fn=112 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021815 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=4,ts=7) FN=112 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021816 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=5,ts=7) FN=112 Rx DATA.ind: sapi=5 arfcn=876 cur_fn=112 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021816 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=5,ts=7) FN=112 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021817 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=6,ts=7) FN=112 Rx DATA.ind: sapi=5 arfcn=877 cur_fn=112 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021817 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=6,ts=7) FN=112 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
[1;32m20241024140021819 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
(bts=0,trx=7,ts=7) FN=112 Rx DATA.ind: sapi=5 arfcn=878 cur_fn=112 block=0 data=
(pcu_l1_if.cpp:463)[0;m
[1;32m20241024140021819 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m
PDCH(bts=0,trx=7,ts=7) FN=112 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10
(pcu_l1_if.cpp:478)[0;m
20241024140021823 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Closing telnet connection
r=127.0.0.1:44152<->l=127.0.0.1:4240 (telnet_interface.c:138)
[1;32m20241024140021825 [1;31mDL1IF[0;m[1;32m [1;31mERROR[0;m[1;32m pcu_sock_read:
recv() failed with rc=0 errno=9 (pcuif_sock.c:123)[0;m
[1;32m20241024140021825 [1;33mDL1IF[0;m[1;32m [1;33mNOTICE[0;m[1;32m PCU socket has
LOST connection (pcuif_sock.c:78)[0;m
[0;33m20241024140021825 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) PDCH state: enabled => disabled (pdch.cpp:184)[0;m
[1;34m20241024140021825 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m
TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW} free (tbf.cpp:271)[0;m
[0;33m20241024140021825 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=0,ts=7) Detaching TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW}, 1 TBFs, USFs =
01, TFIs = 00000001. (pdch.cpp:1202)[0;m
[1;34m20241024140021825 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m
MS(TLLI-0x00000001:TA-0:MSCLS-3-0:UL) Detaching TBF: TBF(UL:G:TLLI-0x00000001){FLOW}
(gprs_ms.c:381)[0;m
[1;34m20241024140021825 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m
MS(TLLI-0x00000001:TA-0:MSCLS-3-0): - tbf: now used by 0 (-) (gprs_ms.c:394)[0;m
[1;34m20241024140021826 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m
MS(TLLI-0x00000001:TA-0:MSCLS-3-0) Schedule MS release in 60 secs (gprs_ms.c:246)[0;m
[1;34m20241024140021826 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m **********
UL-TBF ends here ********** (tbf.cpp:279)[0;m
[1;34m20241024140021826 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m
UL_ACK_TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){NONE}: Deallocated (fsm.c:568)[0;m
[1;34m20241024140021826 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m
UL_TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){FLOW}: Deallocated (fsm.c:568)[0;m
[1;34m20241024140021826 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m
UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){NONE}: Deallocated (fsm.c:568)[0;m
[1;34m20241024140021826 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m
DL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0x00000001){NONE}: Deallocated (fsm.c:568)[0;m
[0;33m20241024140021826 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=1,ts=7) PDCH state: enabled => disabled (pdch.cpp:184)[0;m
[0;33m20241024140021826 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=2,ts=7) PDCH state: enabled => disabled (pdch.cpp:184)[0;m
[0;33m20241024140021826 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=3,ts=7) PDCH state: enabled => disabled (pdch.cpp:184)[0;m
[0;33m20241024140021826 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=4,ts=7) PDCH state: enabled => disabled (pdch.cpp:184)[0;m
[0;33m20241024140021826 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=5,ts=7) PDCH state: enabled => disabled (pdch.cpp:184)[0;m
[0;33m20241024140021827 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=6,ts=7) PDCH state: enabled => disabled (pdch.cpp:184)[0;m
[0;33m20241024140021827 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m
PDCH(bts=0,trx=7,ts=7) PDCH state: enabled => disabled (pdch.cpp:184)[0;m
[38;5;57m20241024140021827 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m
NSE(01234) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523
(gprs_ns2.c:575)[0;m
[1;35m20241024140021827 [1;33mDPCU[0;m[1;35m [1;33mNOTICE[0;m[1;35m NS-NSE 1234
became unavailable (gprs_bssgp_pcu.c:690)[0;m
[38;5;57m20241024140021827 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m
NSE(01234)-NSVC(01234) NS-STATUS.ind(bvci=00000): cause=NSVC failure, transfer=0, first=0,
mtu=65523 (gprs_ns2.c:571)[0;m
[1;35m20241024140021827 [1;34mDPCU[0;m[1;35m [1;34mDEBUG[0;m[1;35m NS: indication
Unknown affecting cause NSVC failure / 0 from NS (gprs_bssgp_pcu.c:702)[0;m
[38;5;57m20241024140021827 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m
GPRS-NS2-VC(NSE01234-NSVC-UDP-0_0_0_0:22000-127_0_0_1:23000){UNBLOCKED}: Terminating
(cause = OSMO_FSM_TERM_REQUEST) (gprs_ns2.c:656)[0;m
[38;5;57m20241024140021827 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m
GPRS-NS2-VC(NSE01234-NSVC-UDP-0_0_0_0:22000-127_0_0_1:23000){UNBLOCKED}: Freeing instance
(gprs_ns2.c:656)[0;m
[38;5;57m20241024140021827 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m
GPRS-NS2-VC(NSE01234-NSVC-UDP-0_0_0_0:22000-127_0_0_1:23000){UNBLOCKED}: Deallocated
(fsm.c:568)[0;m
MTC@9541a9c1d226: Test case TC_nacc_outbound_pkt_cell_chg_notif_dup5 finished. Verdict:
pass
MTC@9541a9c1d226: Starting external command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh>
PCU_Tests.TC_nacc_outbound_pkt_cell_chg_notif_dup5 pass'.
Thu Oct 24 14:00:21 UTC 2024
[1;32m====== PCU_Tests.TC_nacc_outbound_pkt_cell_chg_notif_dup5 pass ======[0m

Saving talloc report from 127.0.0.1:4240 to
PCU_Tests.TC_nacc_outbound_pkt_cell_chg_notif_dup5.talloc
respawn: 95: stopped pid 13908 with status 0
respawn: 96: starting: osmo-pcu
20241024140021907 [1;33mDLGLOBAL[0;m [1;33mNOTICE[0;m Setting up GSMTAP Um forwarding
to '127.0.0.1:4729' (pcu_main.cpp:298)
20241024140021907 [1;33mDLGLOBAL[0;m [1;33mNOTICE[0;m Available via telnet 127.0.0.1
4240 (telnet_interface.c:88)
[1;32m20241024140021907 [1;32mDL1IF[0;m[1;32m [1;32mINFO[0;m[1;32m Opening OsmoPCU
L1 interface v12 to OsmoBTS/OsmoBSC (pcuif_sock.c:202)[0;m
[1;32m20241024140021907 [1;31mDL1IF[0;m[1;32m [1;31mERROR[0;m[1;32m Failed to
connect to the BTS (/tmp/pcu_bts). Retrying... (pcuif_sock.c:210)[0;m
20241024140021908 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Accept()ed new telnet connection
r=127.0.0.1:60948<->l=127.0.0.1:4240 (telnet_interface.c:192)
20241024140022009 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Closing telnet connection
r=127.0.0.1:60948<->l=127.0.0.1:4240 (telnet_interface.c:138)
Waiting for packet dumper to finish... 0 (prev_count=-1, count=302736)
Waiting for packet dumper to finish... 1 (prev_count=302736, count=312328)
MTC@9541a9c1d226: External command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh>
PCU_Tests.TC_nacc_outbound_pkt_cell_chg_notif_dup5 pass' was executed successfully
(exit status: 0).
MTC@9541a9c1d226: Starting external command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh>
PCU_Tests.TC_nacc_outbound_pkt_cell_chg_notif_twice'.
------ PCU_Tests.TC_nacc_outbound_pkt_cell_chg_notif_twice ------
Thu Oct 24 14:00:24 UTC 2024
/usr/bin/dumpcap -q -s 1520 -n -i any -w
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/137/artifact/logs/testsuite/PCU_Tests.TC_nacc_outbound_pkt_cell_chg_notif_twice.pcap">
><https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/137/artifact/logs/testsuite/PCU_Tests.TC_nacc_outbound_pkt_cell_chg_notif_twice.pcap.stdout>
2>/tmp/cmderr &
Waiting for packet dumper to start... 0
MTC@9541a9c1d226: External command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh>
PCU_Tests.TC_nacc_outbound_pkt_cell_chg_notif_twice' was executed successfully (exit
status: 0).
MTC@9541a9c1d226: Test case TC_nacc_outbound_pkt_cell_chg_notif_twice started.
1080@9541a9c1d226: Creating NSIP provider for "127.0.0.1":23000
1080@9541a9c1d226: Starting NSVC component for { provider := { ip := { address_family :=
AF_INET (2), local_udp_port := 23000, local_ip := "127.0.0.1", remote_udp_port
:= 22000, remote_ip := "127.0.0.1", data_weight := 1, signalling_weight := 1 }
}, nsvci := 1234 }
-NSVCI1234(1084)@9541a9c1d226: NSVC 1234 State Transition: NSVC_S_DEAD_BLOCKED (1) ->
NSVC_S_DEAD_BLOCKED (1)
TC_nacc_outbound_pkt_cell_chg_notif_twice-BVCI1234(1083)@9541a9c1d226: Adding Client=mtc,
IMSI='262420000000001'H, TLLI='FFFFFFFF'O, index=0
1080@9541a9c1d226: Creating NSIP provider for "127.0.0.1":23001
-NSVCI1234(1084)@9541a9c1d226: Provider Link came up: waiting for NS-RESET
MTC@9541a9c1d226: Start timer g_T_guard: 60 s
1080@9541a9c1d226: Starting NSVC component for { provider := { ip := { address_family :=
AF_INET (2), local_udp_port := 23001, local_ip := "127.0.0.1", remote_udp_port
:= 22000, remote_ip := "127.0.0.1", data_weight := 1, signalling_weight := 1 }
}, nsvci := 1234 }
-NSVCI1234(1087)@9541a9c1d226: NSVC 1234 State Transition: NSVC_S_DEAD_BLOCKED (1) ->
NSVC_S_DEAD_BLOCKED (1)
1080@9541a9c1d226: Creating NSIP provider for "127.0.0.1":23002
-NSVCI1234(1087)@9541a9c1d226: Provider Link came up: waiting for NS-RESET
20241024140025930 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Accept()ed new telnet connection
r=127.0.0.1:60962<->l=127.0.0.1:4240 (telnet_interface.c:192)
MTC@9541a9c1d226: Start timer T: 2 s
MTC@9541a9c1d226: Start timer T: 2 s
MTC@9541a9c1d226: Start timer T: 2 s
MTC@9541a9c1d226: Start timer T: 2 s
MTC@9541a9c1d226: Start timer T: 2 s
MTC@9541a9c1d226: Start timer T: 2 s
MTC@9541a9c1d226: Start timer T: 2 s
MTC@9541a9c1d226: Start timer T: 2 s
MTC@9541a9c1d226: Start timer T: 2 s
1080@9541a9c1d226: Starting NSVC component for { provider := { ip := { address_family :=
AF_INET (2), local_udp_port := 23002, local_ip := "127.0.0.1", remote_udp_port
:= 22000, remote_ip := "127.0.0.1", data_weight := 1, signalling_weight := 1 }
}, nsvci := 1234 }
-NSVCI1234(1090)@9541a9c1d226: NSVC 1234 State Transition: NSVC_S_DEAD_BLOCKED (1) ->
NSVC_S_DEAD_BLOCKED (1)
-NSVCI1234(1090)@9541a9c1d226: Provider Link came up: waiting for NS-RESET
PCUIF(1086)@9541a9c1d226: "Init PCU interface on '/tmp/pcu_bts', waiting for
connection..."
PCUIF(1086)@9541a9c1d226: Start timer T: 5 s
20241024140025937 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Accept()ed new telnet connection
r=127.0.0.1:60964<->l=127.0.0.1:4240 (telnet_interface.c:192)
PCUIF(1086)@9541a9c1d226: Start timer T_Conn: 10 s
TC_nacc_outbound_pkt_cell_chg_notif_twice-STATS(1091)@9541a9c1d226: Start timer T: 2 s
TC_nacc_outbound_pkt_cell_chg_notif_twice-STATS(1091)@9541a9c1d226: Start timer T: 2 s
Error: OCI runtime error: crun: the container
`9541a9c1d22616963ded87dae5e9d742098d2372ae18d2ab19bff3bad2a3b196` is not running
[1;91m[testenv] podman container crashed![0m
[0;94m[testenv][generic] Testsuite is done[0m
[1;34m[testenv][generic] Stopping testsuite (1828055)[0m
[1;34m[testenv][generic] Merging log files[0m
[0;94m[testenv][generic] + ['podman', 'exec', '-e',
'CCACHE_DIR=/home/osmocom-build/ccache/testenv', '-e',
'TESTENV_CACHE_DIR=<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache',>
'-e', 'TESTENV_SRC_DIR=/home/osmocom-build/jenkins/workspace',
'-e', 'TERM=dumb', '-e',
'TESTENV_GIT_DIR=<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/git',>
'-e',
'PATH=<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/data/scripts>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/data/scripts/qemu>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/pcu>:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin',
'-e', 'HOME=/home/osmocom-build', '-t', '-w',
'<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/137/artifact/logs/testsuite',>
'testenv-pcu-generic-osmocom-nightly-asan-20241024-1348-d17cee9a-0', 'sh',
'-c',
'<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/log_merge.sh>
PCU_Tests --rm >/dev/null'][0m
Error: no container with name or ID
"testenv-pcu-generic-osmocom-nightly-asan-20241024-1348-d17cee9a-0" found: no
such container
[1;91m[testenv][generic] Command failed unexpectedly[0m
[0;94m[testenv][generic] Command: ['podman', 'exec', '-e',
'CCACHE_DIR=/home/osmocom-build/ccache/testenv', '-e',
'TESTENV_CACHE_DIR=<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache',>
'-e', 'TESTENV_SRC_DIR=/home/osmocom-build/jenkins/workspace',
'-e', 'TERM=dumb', '-e',
'TESTENV_GIT_DIR=<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/git',>
'-e',
'PATH=<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/data/scripts>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/data/scripts/qemu>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/pcu>:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin',
'-e', 'HOME=/home/osmocom-build', '-t', '-w',
'<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/137/artifact/logs/testsuite',>
'testenv-pcu-generic-osmocom-nightly-asan-20241024-1348-d17cee9a-0', 'sh',
'-c',
'<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/log_merge.sh>
PCU_Tests --rm >/dev/null'][0m
[0;94m[testenv][generic] Returncode: 125[0m
Traceback (most recent call last):
  File
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/./testenv.py",>
line 115, in <module>
    main()
  File
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/./testenv.py",>
line 104, in main
    run()
  File
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/./testenv.py",>
line 63, in run
    testenv.testsuite.run(cfg)
  File
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/testenv/testsuite.py",>
line 204, in run
    merge_log_files(cfg)
  File
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/testenv/testsuite.py",>
line 130, in merge_log_files
    testenv.cmd.run(cmd, cwd=cwd)
  File
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/testenv/cmd.py",>
line 101, in run
    return testenv.podman.exec_cmd(cmd, check=check, env=env, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/testenv/podman.py",>
line 149, in exec_cmd
    testenv.cmd.run(
  File
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/testenv/cmd.py",>
line 118, in run
    exit_error_cmd(p, "Command failed unexpectedly")
  File
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/ws/_testenv/testenv/cmd.py",>
line 66, in exit_error_cmd
    raise RuntimeError("shell command related error, find details right above this
python trace")
RuntimeError: shell command related error, find details right above this python trace
[1;34m[testenv][generic] Logs saved to:
https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/137/artifact/lo… [0m
Build step 'Execute shell' marked build as failure
Recording test results
[Checks API] No suitable checks publisher found.