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

22 Dec 2025


      See https://jenkins.osmocom.org/jenkins/job/ttcn3-pcu-test-asan/564/display/redirect?page=changes
Changes:
[Pau Espin Pedrol] library/NGAP_Templates: PDUSessionResourceSetupRequest: Fix criticality
------------------------------------------
[...truncated 16.24 MiB...]
[1;34m20251222170210825 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-0-1:G:TLLI-0x00000009){FLOW} stopping timer T3141 [Contention resolution success (UL-TBF, CCCH)] (tbf.cpp:377)[0;m
[0;36m20251222170210825 [1;34mDRLCMACSCHED[0;m[0;36m [1;34mDEBUG[0;m[0;36m PDCH(bts=0,trx=0,ts=7) FN=182 Scheduling control message at RTS for TBF(UL:TFI-0-0-1:G:TLLI-0x00000009){FLOW} (gprs_rlcmac_sched.cpp:202)[0;m
[1;32m20251222170210825 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=0,ts=7) FN=182 Sending data request: sapi=5 arfcn=871 cur_fn=177 block=6 data=41 24 02 00 40 00 00 00 00 00 00 00 60 00 00 01 38 01 4b 2b 2b 2b 2b  (pcu_l1_if.cpp:189)[0;m
[1;32m20251222170210825 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m Time indication received: 26 (pcu_l1_if.cpp:1055)[0;m
BTS(593)@6ebd5b2d9456: Warning: dec_RlcmacDlCtrlBlock(): Data remained at the end of the stream after successful decoding: '4B2B2B2B2B'O ("K++++")
MTC@6ebd5b2d9456: Sending RACH.ind on fn=1337 with RA=122, TA=0
MTC@6ebd5b2d9456: Start timer T: 2 s
[1;32m20251222170210826 [1;32mDL1IF[0;m[1;32m [1;32mINFO[0;m[1;32m RACH request received: sapi=1 qta=0, ra=0x7a, fn=1337 (rfn=1337), cur_fn=177, is_11bit=0 (pcu_l1_if.cpp:640)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m MS requests Uplink resource on CCCH/RACH: ra=0x7a (8 bit) Fn=1337 qta=0 (bts.cpp:952)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m MS requests single TS uplink transmission (one phase packet access) (bts.cpp:970)[0;m
[1;34m20251222170210826 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m Creating MS object (gprs_ms.c:152)[0;m
20251222170210826 [1;34mDLGLOBAL[0;m [1;34mDEBUG[0;m validating counter group 0x55f469457620(pcu:ms) with 1 counters (rate_ctr.c:86)
[1;34m20251222170210826 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m MS(TA-220:MSCLS-0-0): + bts_rcv_rach: now used by 1 (bts_rcv_rach) (gprs_ms.c:175)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m [UL] algo B <single> (suggested TRX: -1): Alloc start (alloc_algo.cpp:763)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m Found first unallocated TRX=1 TFI=1 (bts.cpp:663)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 0, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 1, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 2, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 3, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 4, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 5, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 6, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Possible DL/UL slots: (TS=0)".......C"(TS=7) (alloc_algo.cpp:504)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m Rx=4 Tx=4 Sum Rx+Tx=5, Tta=2 Ttb=1, Tra=2 Trb=1, Type=1 (mslot_class.c:193)[0;m
[0;33mSelected UL slots: (TS=0)"u......U"(TS=7), single (alloc_algo.cpp:688)[0;m
[0;33m20251222170210826 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m [UL] algo B <single> (suggested TRX: -1): using single slot at TS 7 (alloc_algo.cpp:834)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Available DL/UL slots: (TS=0)"D......C"(TS=7) (alloc_algo.cpp:841)[0;m
[1;34m20251222170210826 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m MS(TA-220:MSCLS-0-0) ********** UL-TBF starts here ********** (tbf_ul.cpp:114)[0;m
[1;34m20251222170210826 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m MS(TA-220:MSCLS-0-0) Allocating UL TBF (tbf_ul.cpp:115)[0;m
[1;34m20251222170210826 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m UL_ASS_TBF{NONE}: Allocated (fsm.c:456)[0;m
[1;34m20251222170210826 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m DL_ASS_TBF{NONE}: Allocated (fsm.c:456)[0;m
20251222170210826 [1;34mDLGLOBAL[0;m [1;34mDEBUG[0;m validating counter group 0x55f469457a80(pcu:tbf) with 1 counters (rate_ctr.c:86)
[1;34m20251222170210826 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_TBF{NEW}: Allocated (fsm.c:456)[0;m
[1;34m20251222170210826 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_ACK_TBF{NONE}: Allocated (fsm.c:456)[0;m
20251222170210826 [1;34mDLGLOBAL[0;m [1;34mDEBUG[0;m validating counter group 0x55f469457bc0(tbf:egprs) with 9 counters (rate_ctr.c:86)
20251222170210826 [1;34mDLGLOBAL[0;m [1;34mDEBUG[0;m validating counter group 0x55f469457c00(tbf:gprs) with 4 counters (rate_ctr.c:86)
[1;34m20251222170210826 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1--1:G){NEW} Assigning TS=7 TFI=1 USF=1 (tbf_ul.cpp:695)[0;m
[0;33m20251222170210826 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m PDCH(bts=0,trx=1,ts=7) Attaching TBF(UL:TFI-0-1-1:G){NEW}, 2 TBFs, USFs = 03, TFIs = 00000003. (pdch.cpp:1192)[0;m
[1;34m20251222170210826 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m TBF(UL:TFI-0-1-1:G){NEW} Setting Control TS PDCH(bts=0,trx=1,ts=7) (tbf.cpp:299)[0;m
[1;34m20251222170210826 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m TBF(UL:TFI-0-1-1:G){NEW} Allocated: trx = 1, ul_slots = 80, dl_slots = 00 (tbf_ul.cpp:712)[0;m
[1;34m20251222170210826 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-1-1:G){NEW} (gprs_ms.c:336)[0;m
[1;34m20251222170210826 [1;34mDMS[0;m[1;34m [1;34mDEBUG[0;m[1;34m MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf) (gprs_ms.c:343)[0;m
[1;34m20251222170210826 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_TBF(UL:TFI-0-1-1:G){NEW}: Received Event ASSIGN_ADD_CCCH (gprs_ms.c:1225)[0;m
[1;34m20251222170210826 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m TBF(UL:TFI-0-1-1:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] (tbf_ul_fsm.c:65)[0;m
[1;34m20251222170210826 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_TBF(UL:TFI-0-1-1:G){NEW}: state_chg to ASSIGN (tbf_ul_fsm.c:92)[0;m
[1;34m20251222170210826 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1-1:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 200000 microsec (tbf_ul_fsm.c:141)[0;m
[1;34m20251222170210826 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1-1:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=177 (tbf_ul.cpp:221)[0;m
[1;34m20251222170210826 [1;34mDMS[0;m[1;34m [1;34mDEBUG[0;m[1;34m MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf) (bts.cpp:1012)[0;m
[1;34m20251222170210826 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 (gprs_ms.c:609)[0;m
[0;33m20251222170210826 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m Tx Immediate Assignment on AGCH: TRX=1 (ARFCN 872) TS=7 TA=0 TSC=7 TFI=1 USF=1 (bts.cpp:1026)[0;m
[1;32m20251222170210826 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=0,ts=0) FN=0 Sending data request: sapi=9 arfcn=0 cur_fn=177 block=0 data=ff ff ff ff 2d 06 3f 10 0f e3 68 7a 09 6b 00 00 c8 42 30 0b 2b 2b 2b 2b 2b 2b 2b 00  (pcu_l1_if.cpp:189)[0;m
BTS(593)@6ebd5b2d9456: Warning: dec_PCUIF_agch(): Data remained at the end of the stream after successful decoding: '00'O
MTC@6ebd5b2d9456: Rx Immediate Assignment: { header := { l2_plen := { l2_plen := 11, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := IMMEDIATE_ASSIGNMENT (63) }, payload := { imm_ass := { ded_or_tbf := { spare := '0'B, tma := false, downlink := false, tbf := true }, page_mode := PAGE_MODE_NORMAL (0), chan_desc := omit, pkt_chan_desc := { channel_Type_spare := 1, tn := 7, tsc := 7, presence := '0'B, zero := { hopping := '0'B, spare := '0'B, arfcn := 872, indirect := omit }, one := omit }, req_ref := { ra := '01111010'B, t1p := 1, t3 := 11, t2 := 11 }, timing_advance := 0, mobile_allocation := { len := 0, ma := ''B }, rest_octets := { presence := '11'B, ll := omit, lh := omit, hl := omit, hh := { pa_disc := '0'B, pa := { uldl := { ass_disc := '0'B, ass := { ul := { presence := '1'B, dynamic := { tfi_assignment := 1, polling := '0'B, spare := '0'B, usf := 1, usf_granularity := '0'B, p0_present := '0'B, p0 := omit, pr_mode := omit, ch_coding_cmd := CH_CODING_CS2 (1), tlli_block_chan_coding := '1'B, alpha_present := '0'B, alpha := omit, gamma := 0, ta_index_present := '0'B, ta_index := omit, tbf_starting_time_present := '0'B, tbf_starting_time := omit }, single := omit } } } } } } } } }
MTC@6ebd5b2d9456: Rx Uplink TBF GPRS assignment: { presence := '1'B, dynamic := { tfi_assignment := 1, polling := '0'B, spare := '0'B, usf := 1, usf_granularity := '0'B, p0_present := '0'B, p0 := omit, pr_mode := omit, ch_coding_cmd := CH_CODING_CS2 (1), tlli_block_chan_coding := '1'B, alpha_present := '0'B, alpha := omit, gamma := 0, ta_index_present := '0'B, ta_index := omit, tbf_starting_time_present := '0'B, tbf_starting_time := omit }, single := omit }
[1;32m20251222170210839 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=0,ts=7) FN=182 Rx DATA.ind: sapi=5 arfcn=871 cur_fn=177 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210839 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=0,ts=7) FN=182 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[0;33m20251222170210839 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m PDCH(bts=0,trx=0,ts=7) Timeout for registered USF (FN=182): TBF(UL:TFI-0-0-1:G:TLLI-0x00000009){FLOW} (pdch_ul_controller.c:309)[0;m
[1;34m20251222170210839 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-0-1:G:TLLI-0x00000009){FLOW} N3101 0 => 1 (< MAX 10) (tbf.cpp:362)[0;m
[1;32m20251222170210839 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=1,ts=7) FN=182 Rx DATA.ind: sapi=5 arfcn=872 cur_fn=182 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210839 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=1,ts=7) FN=182 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210839 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=2,ts=7) FN=182 Rx DATA.ind: sapi=5 arfcn=873 cur_fn=182 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210839 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=2,ts=7) FN=182 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210839 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=3,ts=7) FN=182 Rx DATA.ind: sapi=5 arfcn=874 cur_fn=182 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210839 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=3,ts=7) FN=182 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210840 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=4,ts=7) FN=182 Rx DATA.ind: sapi=5 arfcn=875 cur_fn=182 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210840 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=4,ts=7) FN=182 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210840 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=5,ts=7) FN=182 Rx DATA.ind: sapi=5 arfcn=876 cur_fn=182 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210840 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=5,ts=7) FN=182 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210840 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=6,ts=7) FN=182 Rx DATA.ind: sapi=5 arfcn=877 cur_fn=182 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210840 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=6,ts=7) FN=182 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210840 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=7,ts=7) FN=182 Rx DATA.ind: sapi=5 arfcn=878 cur_fn=182 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210840 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=7,ts=7) FN=182 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210844 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=0,ts=7) FN=186 RX RTS.req: sapi=5 arfcn=871 cur_fn=182 block=7 (pcu_l1_if.cpp:583)[0;m
[0;36m20251222170210844 [1;34mDRLCMACSCHED[0;m[0;36m [1;34mDEBUG[0;m[0;36m PDCH(bts=0,trx=0,ts=7) Received RTS for PDCH: FN=186 block_nr=7 scheduling USF=1 for TBF(UL:TFI-0-0-1:G:TLLI-0x00000009){FLOW}, expect answer on UL FN=190 (gprs_rlcmac_sched.cpp:454)[0;m
[0;33m20251222170210844 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m PDCH(bts=0,trx=0,ts=7) Reserving FN 190 for type USF (pdch_ul_controller.c:184)[0;m
[1;32m20251222170210844 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=0,ts=7) FN=186 Sending data request: sapi=5 arfcn=871 cur_fn=182 block=7 data=41 94 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b  (pcu_l1_if.cpp:189)[0;m
[1;32m20251222170210844 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m Time indication received: 30 (pcu_l1_if.cpp:1055)[0;m
BTS(593)@6ebd5b2d9456: Warning: dec_RlcmacDlCtrlBlock(): Data remained at the end of the stream after successful decoding: '2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B2B'O ("+++++++++++++++++++++")
MTC@6ebd5b2d9456: Rx DL block USF 1 vs exp USF 1
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=0,ts=7) FN=186 Rx DATA.ind: sapi=5 arfcn=871 cur_fn=182 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=0,ts=7) FN=186 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[0;33m20251222170210858 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m PDCH(bts=0,trx=0,ts=7) Timeout for registered USF (FN=186): TBF(UL:TFI-0-0-1:G:TLLI-0x00000009){FLOW} (pdch_ul_controller.c:309)[0;m
[1;34m20251222170210858 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-0-1:G:TLLI-0x00000009){FLOW} N3101 1 => 2 (< MAX 10) (tbf.cpp:362)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=1,ts=7) FN=186 Rx DATA.ind: sapi=5 arfcn=872 cur_fn=186 block=7 data=3c 03 01 00 00 00 0a 9d c0 6c de 90 a4 a6 77 bb 40 a0 78 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00  (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=1,ts=7) FN=186 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 0 (pcu_l1_if.cpp:485)[0;m
[1;36m20251222170210858 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m PDCH(bts=0,trx=1,ts=7) Got RLC block, coding scheme: CS-2, length: 34 (33)) (pdch.cpp:983)[0;m
[1;36m20251222170210858 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m PDCH(bts=0,trx=1,ts=7)   UL data: 3c 03 01 00 00 00 0a 9d c0 6c de 90 a4 a6 77 bb 40 a0 78 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00  (pdch.cpp:1021)[0;m
[1;36m20251222170210858 [1;32mDRLCMACUL[0;m[1;36m [1;32mINFO[0;m[1;36m PDCH(bts=0,trx=1,ts=7) Got CS-2 RLC block: R=0, SI=0, TFI=1, CPS=0, RSB=0, rc=264 (pdch.cpp:1032)[0;m
[1;36m20251222170210858 [1;33mDRLCMACUL[0;m[1;36m [1;33mNOTICE[0;m[1;36m PDCH(bts=0,trx=1,ts=7) FN=186 Rx UL DATA from unexpected TBF(UL:TFI-0-1-1:G){ASSIGN} (pdch.cpp:1072)[0;m
[1;34m20251222170210858 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1-1:G){ASSIGN} UL DATA TFI=1 received (V(Q)=0 .. V(R)=0) (tbf_ul.cpp:257)[0;m
[1;31m20251222170210858 [1;32mDRLCMACMEAS[0;m[1;31m [1;32mINFO[0;m[1;31m MS(TA-0:MSCLS-0-0:UL) Link quality 0dB (old 0dB) left window [5, 8], modifying uplink CS level: CS-2 -> CS-1 (gprs_ms.c:816)[0;m
[1;34m20251222170210858 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1-1:G){ASSIGN} Got CS-2 RLC data block: CV=15, BSN=0, SPB=0, PI=0, E=1, TI=1, bitoffs=24 (tbf_ul.cpp:292)[0;m
[1;34m20251222170210858 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1-1:G){ASSIGN} BSN 0 storing in window (0..63) (tbf_ul.cpp:314)[0;m
[1;34m20251222170210858 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1-1:G){ASSIGN} data_length=30, data=00 00 00 0a 9d c0 6c de 90 a4 a6 77 bb 40 a0 78 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b  (tbf_ul.cpp:337)[0;m
[1;34m20251222170210858 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m TBF(UL:TFI-0-1-1:G){ASSIGN} Decoded premier TLLI=0x0000000a of UL DATA TFI=1. (tbf_ul.cpp:361)[0;m
[1;34m20251222170210858 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m Modifying MS object, UL TLLI: 0xffffffff -> 0x0000000a, not yet confirmed (gprs_ms.c:512)[0;m
[1;34m20251222170210858 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_TBF(UL:TFI-0-1-1:G){ASSIGN}: Received Event FIRST_UL_DATA_RECVD (tbf_ul.cpp:365)[0;m
[1;34m20251222170210858 [1;31mDTBFUL[0;m[1;34m [1;31mERROR[0;m[1;34m UL_TBF(UL:TFI-0-1-1:G){ASSIGN}: Event FIRST_UL_DATA_RECVD not permitted (tbf_ul.cpp:365)[0;m
[1;36m20251222170210858 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m - Mark BSN 64 as INVALID (rlc_window_ul.cpp:42)[0;m
[1;36m20251222170210858 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m - Raising V(R) to 1 (rlc_window_ul.cpp:50)[0;m
[1;36m20251222170210858 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m - Taking block 0 out, raising V(Q) to 1 (rlc_window_ul.cpp:65)[0;m
[1;34m20251222170210858 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1-1:G:TLLI-0x0000000a){ASSIGN} Assembling frames: (len=30) (tbf_ul.cpp:172)[0;m
[1;34m20251222170210858 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1-1:G:TLLI-0x0000000a){ASSIGN} Frame 1 starts at offset 4, length=26, is_complete=0 (tbf_ul.cpp:185)[0;m
[1;34m20251222170210858 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-1-1:G:TLLI-0x0000000a){ASSIGN} Scheduling Ack/Nack, because TLLI is included. (tbf_ul.cpp:434)[0;m
[1;34m20251222170210858 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_ACK_TBF(UL:TFI-0-1-1:G){NONE}: Received Event SCHED_ACK (tbf_ul.cpp:456)[0;m
[1;34m20251222170210858 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_ACK_TBF(UL:TFI-0-1-1:G){NONE}: state_chg to SCHED_UL_ACK (tbf_ul_ack_fsm.c:102)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=2,ts=7) FN=186 Rx DATA.ind: sapi=5 arfcn=873 cur_fn=186 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=2,ts=7) FN=186 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=3,ts=7) FN=186 Rx DATA.ind: sapi=5 arfcn=874 cur_fn=186 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=3,ts=7) FN=186 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=4,ts=7) FN=186 Rx DATA.ind: sapi=5 arfcn=875 cur_fn=186 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=4,ts=7) FN=186 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=5,ts=7) FN=186 Rx DATA.ind: sapi=5 arfcn=876 cur_fn=186 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210858 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=5,ts=7) FN=186 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210859 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=6,ts=7) FN=186 Rx DATA.ind: sapi=5 arfcn=877 cur_fn=186 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210859 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=6,ts=7) FN=186 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210859 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=7,ts=7) FN=186 Rx DATA.ind: sapi=5 arfcn=878 cur_fn=186 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210859 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=7,ts=7) FN=186 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[1;32m20251222170210862 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=1,ts=7) FN=190 RX RTS.req: sapi=5 arfcn=872 cur_fn=186 block=8 (pcu_l1_if.cpp:583)[0;m
[0;36m20251222170210862 [1;34mDRLCMACSCHED[0;m[0;36m [1;34mDEBUG[0;m[0;36m PDCH(bts=0,trx=1,ts=7) Received RTS for PDCH: FN=190 block_nr=8 scheduling USF=0 for TBF(UL:TFI-0-1-0:G:TLLI-0x00000002){FLOW}, expect answer on UL FN=195 (gprs_rlcmac_sched.cpp:454)[0;m
[0;33m20251222170210862 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m PDCH(bts=0,trx=1,ts=7) Reserving FN 195 for type USF (pdch_ul_controller.c:184)[0;m
[1;34m20251222170210862 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_ACK_TBF(UL:TFI-0-1-1:G){SCHED_UL_ACK}: Received Event CREATE_RLCMAC_MSG (tbf_ul_ack_fsm.c:251)[0;m
[1;36m20251222170210862 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m Encoding Ack/Nack for TBF(UL:TFI-0-1-1:G:TLLI-0x0000000a){ASSIGN} (final=0) (encoding.cpp:1116)[0;m
[1;36m20251222170210862 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m - V(N): "IIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIR" R=Received I=Invalid (encoding.cpp:864)[0;m
[1;36m20251222170210862 [1;34mDRLCMACUL[0;m[1;36m [1;34mDEBUG[0;m[1;36m Uplink Ack/Nack bit count 147, max 184, message = 40 24 02 00 40 00 00 00 00 00 00 00 60 00 00 01 58 01 4b 2b 2b 2b 2b  (encoding.cpp:1139)[0;m
[1;34m20251222170210862 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_ACK_TBF(UL:TFI-0-1-1:G){SCHED_UL_ACK}: state_chg to NONE (tbf_ul_ack_fsm.c:131)[0;m
[1;34m20251222170210862 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_TBF(UL:TFI-0-1-1:G){ASSIGN}: Received Event CONTENTION_RESOLUTION_MS_SUCCESS (tbf_ul_ack_fsm.c:152)[0;m
[1;34m20251222170210862 [1;31mDTBFUL[0;m[1;34m [1;31mERROR[0;m[1;34m UL_TBF(UL:TFI-0-1-1:G){ASSIGN}: Event CONTENTION_RESOLUTION_MS_SUCCESS not permitted (tbf_ul_ack_fsm.c:152)[0;m
[0;36m20251222170210862 [1;34mDRLCMACSCHED[0;m[0;36m [1;34mDEBUG[0;m[0;36m PDCH(bts=0,trx=1,ts=7) FN=190 Scheduling control message at RTS for TBF(UL:TFI-0-1-1:G:TLLI-0x0000000a){ASSIGN} (gprs_rlcmac_sched.cpp:202)[0;m
[1;32m20251222170210862 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=1,ts=7) FN=190 Sending data request: sapi=5 arfcn=872 cur_fn=186 block=8 data=40 24 02 00 40 00 00 00 00 00 00 00 60 00 00 01 58 01 4b 2b 2b 2b 2b  (pcu_l1_if.cpp:189)[0;m
[1;32m20251222170210862 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m Time indication received: 34 (pcu_l1_if.cpp:1055)[0;m
BTS(593)@6ebd5b2d9456: Warning: dec_RlcmacDlCtrlBlock(): Data remained at the end of the stream after successful decoding: '4B2B2B2B2B'O ("K++++")
MTC@6ebd5b2d9456: Sending RACH.ind on fn=1337 with RA=123, TA=0
MTC@6ebd5b2d9456: Start timer T: 2 s
[1;32m20251222170210863 [1;32mDL1IF[0;m[1;32m [1;32mINFO[0;m[1;32m RACH request received: sapi=1 qta=0, ra=0x7b, fn=1337 (rfn=1337), cur_fn=186, is_11bit=0 (pcu_l1_if.cpp:640)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m MS requests Uplink resource on CCCH/RACH: ra=0x7b (8 bit) Fn=1337 qta=0 (bts.cpp:952)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m MS requests single TS uplink transmission (one phase packet access) (bts.cpp:970)[0;m
[1;34m20251222170210863 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m Creating MS object (gprs_ms.c:152)[0;m
20251222170210863 [1;34mDLGLOBAL[0;m [1;34mDEBUG[0;m validating counter group 0x55f469457620(pcu:ms) with 1 counters (rate_ctr.c:86)
[1;34m20251222170210863 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m MS(TA-220:MSCLS-0-0): + bts_rcv_rach: now used by 1 (bts_rcv_rach) (gprs_ms.c:175)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m [UL] algo B <single> (suggested TRX: -1): Alloc start (alloc_algo.cpp:763)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m Found first unallocated TRX=2 TFI=1 (bts.cpp:663)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 0, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 1, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 2, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 3, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 4, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 5, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Skipping TS 6, because not enabled (alloc_algo.cpp:75)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Possible DL/UL slots: (TS=0)".......C"(TS=7) (alloc_algo.cpp:504)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m Rx=4 Tx=4 Sum Rx+Tx=5, Tta=2 Ttb=1, Tra=2 Trb=1, Type=1 (mslot_class.c:193)[0;m
[0;33mSelected UL slots: (TS=0)"u......U"(TS=7), single (alloc_algo.cpp:688)[0;m
[0;33m20251222170210863 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m [UL] algo B <single> (suggested TRX: -1): using single slot at TS 7 (alloc_algo.cpp:834)[0;m
[0;33m20251222170210863 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m - Available DL/UL slots: (TS=0)"D......C"(TS=7) (alloc_algo.cpp:841)[0;m
[1;34m20251222170210863 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m MS(TA-220:MSCLS-0-0) ********** UL-TBF starts here ********** (tbf_ul.cpp:114)[0;m
[1;34m20251222170210863 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m MS(TA-220:MSCLS-0-0) Allocating UL TBF (tbf_ul.cpp:115)[0;m
[1;34m20251222170210863 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m UL_ASS_TBF{NONE}: Allocated (fsm.c:456)[0;m
[1;34m20251222170210863 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m DL_ASS_TBF{NONE}: Allocated (fsm.c:456)[0;m
20251222170210864 [1;34mDLGLOBAL[0;m [1;34mDEBUG[0;m validating counter group 0x55f469457a80(pcu:tbf) with 1 counters (rate_ctr.c:86)
[1;34m20251222170210864 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_TBF{NEW}: Allocated (fsm.c:456)[0;m
[1;34m20251222170210864 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_ACK_TBF{NONE}: Allocated (fsm.c:456)[0;m
20251222170210864 [1;34mDLGLOBAL[0;m [1;34mDEBUG[0;m validating counter group 0x55f469457bc0(tbf:egprs) with 9 counters (rate_ctr.c:86)
20251222170210864 [1;34mDLGLOBAL[0;m [1;34mDEBUG[0;m validating counter group 0x55f469457c00(tbf:gprs) with 4 counters (rate_ctr.c:86)
[1;34m20251222170210864 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-2--1:G){NEW} Assigning TS=7 TFI=1 USF=1 (tbf_ul.cpp:695)[0;m
[0;33m20251222170210864 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m PDCH(bts=0,trx=2,ts=7) Attaching TBF(UL:TFI-0-2-1:G){NEW}, 2 TBFs, USFs = 03, TFIs = 00000003. (pdch.cpp:1192)[0;m
[1;34m20251222170210864 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m TBF(UL:TFI-0-2-1:G){NEW} Setting Control TS PDCH(bts=0,trx=2,ts=7) (tbf.cpp:299)[0;m
[1;34m20251222170210864 [1;32mDTBF[0;m[1;34m [1;32mINFO[0;m[1;34m TBF(UL:TFI-0-2-1:G){NEW} Allocated: trx = 2, ul_slots = 80, dl_slots = 00 (tbf_ul.cpp:712)[0;m
[1;34m20251222170210864 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m MS(TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:TFI-0-2-1:G){NEW} (gprs_ms.c:336)[0;m
[1;34m20251222170210864 [1;34mDMS[0;m[1;34m [1;34mDEBUG[0;m[1;34m MS(TA-220:MSCLS-0-0:UL): + tbf: now used by 2 (bts_rcv_rach,tbf) (gprs_ms.c:343)[0;m
[1;34m20251222170210864 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_TBF(UL:TFI-0-2-1:G){NEW}: Received Event ASSIGN_ADD_CCCH (gprs_ms.c:1225)[0;m
[1;34m20251222170210864 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m TBF(UL:TFI-0-2-1:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] (tbf_ul_fsm.c:65)[0;m
[1;34m20251222170210864 [1;32mDTBFUL[0;m[1;34m [1;32mINFO[0;m[1;34m UL_TBF(UL:TFI-0-2-1:G){NEW}: state_chg to ASSIGN (tbf_ul_fsm.c:92)[0;m
[1;34m20251222170210864 [1;34mDTBFUL[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-2-1:G){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 200000 microsec (tbf_ul_fsm.c:141)[0;m
[1;34m20251222170210864 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-2-1:G){ASSIGN} Starting timer T3141 [Contention resolution (UL-TBF, CCCH)] with 10 sec. 0 microsec, cur_fn=186 (tbf_ul.cpp:221)[0;m
[1;34m20251222170210864 [1;34mDMS[0;m[1;34m [1;34mDEBUG[0;m[1;34m MS(TA-220:MSCLS-0-0:UL): - bts_rcv_rach: now used by 1 (tbf) (bts.cpp:1012)[0;m
[1;34m20251222170210864 [1;32mDMS[0;m[1;34m [1;32mINFO[0;m[1;34m Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 (gprs_ms.c:609)[0;m
[0;33m20251222170210864 [1;34mDRLCMAC[0;m[0;33m [1;34mDEBUG[0;m[0;33m Tx Immediate Assignment on AGCH: TRX=2 (ARFCN 873) TS=7 TA=0 TSC=7 TFI=1 USF=1 (bts.cpp:1026)[0;m
[1;32m20251222170210864 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=0,ts=0) FN=0 Sending data request: sapi=9 arfcn=0 cur_fn=186 block=0 data=ff ff ff ff 2d 06 3f 10 0f e3 69 7b 09 6b 00 00 c8 42 30 0b 2b 2b 2b 2b 2b 2b 2b 00  (pcu_l1_if.cpp:189)[0;m
BTS(593)@6ebd5b2d9456: Warning: dec_PCUIF_agch(): Data remained at the end of the stream after successful decoding: '00'O
MTC@6ebd5b2d9456: Rx Immediate Assignment: { header := { l2_plen := { l2_plen := 11, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := IMMEDIATE_ASSIGNMENT (63) }, payload := { imm_ass := { ded_or_tbf := { spare := '0'B, tma := false, downlink := false, tbf := true }, page_mode := PAGE_MODE_NORMAL (0), chan_desc := omit, pkt_chan_desc := { channel_Type_spare := 1, tn := 7, tsc := 7, presence := '0'B, zero := { hopping := '0'B, spare := '0'B, arfcn := 873, indirect := omit }, one := omit }, req_ref := { ra := '01111011'B, t1p := 1, t3 := 11, t2 := 11 }, timing_advance := 0, mobile_allocation := { len := 0, ma := ''B }, rest_octets := { presence := '11'B, ll := omit, lh := omit, hl := omit, hh := { pa_disc := '0'B, pa := { uldl := { ass_disc := '0'B, ass := { ul := { presence := '1'B, dynamic := { tfi_assignment := 1, polling := '0'B, spare := '0'B, usf := 1, usf_granularity := '0'B, p0_present := '0'B, p0 := omit, pr_mode := omit, ch_coding_cmd := CH_CODING_CS2 (1), tlli_block_chan_coding := '1'B, alpha_present := '0'B, alpha := omit, gamma := 0, ta_index_present := '0'B, ta_index := omit, tbf_starting_time_present := '0'B, tbf_starting_time := omit }, single := omit } } } } } } } } }
MTC@6ebd5b2d9456: Rx Uplink TBF GPRS assignment: { presence := '1'B, dynamic := { tfi_assignment := 1, polling := '0'B, spare := '0'B, usf := 1, usf_granularity := '0'B, p0_present := '0'B, p0 := omit, pr_mode := omit, ch_coding_cmd := CH_CODING_CS2 (1), tlli_block_chan_coding := '1'B, alpha_present := '0'B, alpha := omit, gamma := 0, ta_index_present := '0'B, ta_index := omit, tbf_starting_time_present := '0'B, tbf_starting_time := omit }, single := omit }
[1;32m20251222170210876 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=0,ts=7) FN=190 Rx DATA.ind: sapi=5 arfcn=871 cur_fn=186 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210876 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=0,ts=7) FN=190 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
[0;33m20251222170210876 [1;32mDRLCMAC[0;m[0;33m [1;32mINFO[0;m[0;33m PDCH(bts=0,trx=0,ts=7) Timeout for registered USF (FN=190): TBF(UL:TFI-0-0-1:G:TLLI-0x00000009){FLOW} (pdch_ul_controller.c:309)[0;m
[1;34m20251222170210876 [1;34mDTBF[0;m[1;34m [1;34mDEBUG[0;m[1;34m TBF(UL:TFI-0-0-1:G:TLLI-0x00000009){FLOW} N3101 2 => 3 (< MAX 10) (tbf.cpp:362)[0;m
[1;32m20251222170210876 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m (bts=0,trx=1,ts=7) FN=190 Rx DATA.ind: sapi=5 arfcn=872 cur_fn=190 block=0 data= (pcu_l1_if.cpp:470)[0;m
[1;32m20251222170210876 [1;34mDL1IF[0;m[1;32m [1;34mDEBUG[0;m[1;32m PDCH(bts=0,trx=1,ts=7) FN=190 Rx DATA.ind PDTCH: BER10k = 0, BTO = 0, Q = 10 (pcu_l1_if.cpp:485)[0;m
FATAL: command execution failed
java.io.EOFException
    at java.base/java.io.ObjectInputStream$PeekInputStream.readFully(Unknown Source)
    at java.base/java.io.ObjectInputStream$BlockDataInputStream.readShort(Unknown Source)
    at java.base/java.io.ObjectInputStream.readStreamHeader(Unknown Source)
    at java.base/java.io.ObjectInputStream.<init>(Unknown Source)
    at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:50)
    at hudson.remoting.Command.readFrom(Command.java:141)
    at hudson.remoting.Command.readFrom(Command.java:127)
    at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35)
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:62)
Caused: java.io.IOException: Unexpected termination of the channel
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:80)
Caused: java.io.IOException: Backing channel 'build4-deb12build-ansible' is disconnected.
    at hudson.remoting.RemoteInvocationHandler.channelOrFail(RemoteInvocationHandler.java:227)
    at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:306)
    at jdk.proxy2/jdk.proxy2.$Proxy156.isAlive(Unknown Source)
    at hudson.Launcher$RemoteLauncher$ProcImpl.isAlive(Launcher.java:1212)
    at hudson.Launcher$RemoteLauncher$ProcImpl.join(Launcher.java:1204)
    at hudson.tasks.CommandInterpreter.join(CommandInterpreter.java:195)
    at hudson.tasks.CommandInterpreter.perform(CommandInterpreter.java:145)
    at hudson.tasks.CommandInterpreter.perform(CommandInterpreter.java:92)
    at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
    at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:818)
    at hudson.model.Build$BuildExecution.build(Build.java:199)
    at hudson.model.Build$BuildExecution.doRun(Build.java:164)
    at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:527)
    at hudson.model.Run.execute(Run.java:1833)
    at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:44)
    at hudson.model.ResourceController.execute(ResourceController.java:101)
    at hudson.model.Executor.run(Executor.java:446)
FATAL: Unable to delete script file /tmp/jenkins6527127350609205678.sh
java.io.EOFException
    at java.base/java.io.ObjectInputStream$PeekInputStream.readFully(Unknown Source)
    at java.base/java.io.ObjectInputStream$BlockDataInputStream.readShort(Unknown Source)
    at java.base/java.io.ObjectInputStream.readStreamHeader(Unknown Source)
    at java.base/java.io.ObjectInputStream.<init>(Unknown Source)
    at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:50)
    at hudson.remoting.Command.readFrom(Command.java:141)
    at hudson.remoting.Command.readFrom(Command.java:127)
    at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35)
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:62)
Caused: java.io.IOException: Unexpected termination of the channel
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:80)
Caused: hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@3f9ba8e:build4-deb12build-ansible": Remote call on build4-deb12build-ansible failed. The channel is closing down or has closed down
    at hudson.remoting.Channel.call(Channel.java:1105)
    at hudson.FilePath.act(FilePath.java:1207)
    at hudson.FilePath.act(FilePath.java:1196)
    at hudson.FilePath.delete(FilePath.java:1743)
    at hudson.tasks.CommandInterpreter.perform(CommandInterpreter.java:163)
    at hudson.tasks.CommandInterpreter.perform(CommandInterpreter.java:92)
    at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
    at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:818)
    at hudson.model.Build$BuildExecution.build(Build.java:199)
    at hudson.model.Build$BuildExecution.doRun(Build.java:164)
    at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:527)
    at hudson.model.Run.execute(Run.java:1833)
    at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:44)
    at hudson.model.ResourceController.execute(ResourceController.java:101)
    at hudson.model.Executor.run(Executor.java:446)
Build step 'Execute shell' marked build as failure
ERROR: Step ‘Publish JUnit test result report’ failed: no workspace for ttcn3-pcu-test-asan #564