<div dir="ltr"><div>Hi, here is the log with debug info:</div>
<div> </div>
<div>Welcome to the Osmo-PCU control interface</div>
<div>Copyright (C) 2012 by ...<br>License GNU GPL version 2 or later<br>This is free software: you are free to change and redistribute it.<br>There is NO WARRANTY, to the extent permitted by law.<br>Osmo-PCU> <br>Osmo-PCU> <br>
Osmo-PCU> <br>Osmo-PCU> <br>Osmo-PCU> <br>Osmo-PCU> log<br>Osmo-PCU> loglogging en<br>Osmo-PCU> logging enenable 1<br>% Unknown command.<br>Osmo-PCU> logging enable 1  <br>Osmo-PCU> log<br>Osmo-PCU> loglogging fil<br>
Osmo-PCU> logging filfilter all 1<br>Osmo-PCU> log<br>Osmo-PCU> loglogging lev<br>Osmo-PCU> logging levlevel rl<br>Osmo-PCU> logging level rlrlcmac f de<br>Osmo-PCU> logging level rlcmac dedebug  <br>Osmo-PCU> <br>
Osmo-PCU> <br>Osmo-PCU> <br>Osmo-PCU> <br>Osmo-PCU> <br>Osmo-PCU> [1;32m<0001> pcu_l1_if.cpp:334 BTS available<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:335  mcc=452<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:336  mnc=2<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:337  lac=1000<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:338  rac=0<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:339  cell_id=0<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:340  nsei=8<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:345  nse_timer=0 0 0 0 0 0 0<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:353  cell_timer=0 0 0 0 0 0 0 0 0 0 0<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:354  repeat_time=5<br>[0;m<br>
[1;32m<0001> pcu_l1_if.cpp:355  repeat_count=10<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:356  bvci=7<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:357  t3142=20<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:358  t3169=5<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:359  t3191=5<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:360  t3193=1000 (ms)<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:361  t3195=5<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:362  n3101=10<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:363  n3103=4<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:364  n3105=8<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:365  cv_countdown=15<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:366  dl_tbf_ext=0<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:367  ul_tbf_ext=0<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:376  initial_cs=1<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:377  initial_mcs=0<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:378  nsvci=4<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:379  local_port=5944<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:380  remote_port=23000<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:381  remote_ip=2130706433<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:82 Sending activate request: trx=0 ts=7<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:429 PDCH: trx=0 ts=7<br>[0;m<br>[1;35m<0009> gprs_bssgp_pcu.cpp:491 NS-VC 4 is unblocked.<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:532 Sending reset on BVCI 0<br>[0;m<br>
[1;34m<0008> gprs_bssgp_pcu.cpp:540 Sending reset on BVCI 7<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:548 Sending unblock on BVCI 7<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=120, fn=1280580<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to FLOW<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 0 RACH qbit-ta=0 ra=0x78, Fn=1280580 (5,21,2)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 0 Immediate Assignment Uplink (AGCH)<br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xace80214 of UL DATA TBF=0.<br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=43<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xace80214 len=43<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xace80214 IMSI: 000 len: 9<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xace80214 <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because UL TBF=0 exists for TLLI=0xace80214<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xace80214 Packet Downlink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1280660 block_nr=1 scheduling free USF for polling at FN=1280664 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1280664 TLL=0xace80214 (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xace80214 <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=9<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1280686 block_nr=7 scheduling free USF for polling at FN=1280690 of UL TFI=0<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1280690 block_nr=8 scheduling free USF for polling at FN=1280695 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1280690 TLL=0xace80214 (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xace80214 <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xace80214.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=120, fn=1280840<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 0 RACH qbit-ta=0 ra=0x78, Fn=1280840 (5,26,2)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 0 Immediate Assignment Uplink (AGCH)<br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xace80214 of UL DATA TBF=0.<br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:882 Got RACH from TLLI=0xace80214 while DL TBF=0 still exists. Killing pending DL TBF<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xace80214.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=17<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xace80214 len=17<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xace80214 IMSI: 000 len: 9<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xace80214 <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=000)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xace80214 Immediate Assignment Downlink (PCH)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=ace80214<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1280907 block_nr=10 scheduling free USF for polling at FN=1280911 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=1280907 TLL=0xace80214 (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=9<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1280955 block_nr=9 scheduling free USF for polling at FN=1280959 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:107 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:82 - Assignment was on CCCH<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1281093 block_nr=5 scheduling free USF for polling at FN=1281098 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1281145 block_nr=5 scheduling free USF for polling at FN=1281150 of UL TFI=0<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=122, fn=1281151<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=1.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 1<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 1 RACH qbit-ta=0 ra=0x7a, Fn=1281151 (6,31,1)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 1 Immediate Assignment Uplink (AGCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xace80214.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xace80214 of UL DATA TBF=1.<br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:891 Got RACH from TLLI=0xace80214 while UL TBF=0 still exists. Killing pending UL TBF<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xace80214.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=17<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xace80214 len=17<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xace80214 IMSI: 452022112638582 len: 24<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xace80214 <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=452022112638582)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xace80214 Immediate Assignment Downlink (PCH)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=ace80214<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1281215 block_nr=9 scheduling free USF for polling at FN=1281219 of UL TFI=1<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1281219 TLL=0xace80214 (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xace80214 Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xace80214 <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xace80214.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=24<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1281267 block_nr=9 scheduling free USF for polling at FN=1281271 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=120, fn=1281444<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 0 RACH qbit-ta=0 ra=0x78, Fn=1281444 (6,18,8)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 0 Immediate Assignment Uplink (AGCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xace80214.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xcb46771f of UL DATA TBF=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=8<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=8<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1281518 block_nr=7 scheduling free USF for polling at FN=1281522 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1281522 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=123, fn=1288588<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 0 RACH qbit-ta=0 ra=0x7b, Fn=1288588 (11,22,2)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 0 Immediate Assignment Uplink (AGCH)<br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xcb46771f of UL DATA TBF=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=150<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=150<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 55<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because UL TBF=0 exists for TLLI=0xcb46771f<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1288694 block_nr=7 scheduling free USF for polling at FN=1288698 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1288698 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1288724 block_nr=2 scheduling free USF for polling at FN=1288729 of UL TFI=0<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=55<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1288737 block_nr=5 scheduling free USF for polling at FN=1288742 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1288729 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=117, fn=1288901<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x75, Fn=1288901 (12,29,3)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1288989 block_nr=3 scheduling free USF for polling at FN=1288993 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1288993 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=72<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=72<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 111<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because UL TBF=0 exists for TLLI=0xcb46771f<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289054 block_nr=6 scheduling free USF for polling at FN=1289058 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289058 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289084 block_nr=1 scheduling free USF for polling at FN=1289088 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289088 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=111<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289110 block_nr=7 scheduling free USF for polling at FN=1289114 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=118, fn=1289261<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x76, Fn=1289261 (12,32,25)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:437 Got RACH from TLLI=0xcb46771f while DL TBF=0 still exists. Killing pending DL TBF<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289348 block_nr=2 scheduling free USF for polling at FN=1289353 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289353 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=70<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289409 block_nr=4 scheduling free USF for polling at FN=1289413 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=1289409 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=452022112638582)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xcb46771f Immediate Assignment Downlink (PCH)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=cb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289517 block_nr=5 scheduling free USF for polling at FN=1289522 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:107 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289548 block_nr=0 scheduling free USF for polling at FN=1289552 of UL TFI=0<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f<br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289604 block_nr=1 scheduling free USF for polling at FN=1289608 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289608 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289647 block_nr=11 scheduling free USF for polling at FN=1289652 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=1.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289678 block_nr=6 scheduling free USF for polling at FN=1289682 of DL TFI=0<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289682 block_nr=7 scheduling free USF for polling at FN=1289686 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289682 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289730 block_nr=6 scheduling free USF for polling at FN=1289734 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289734 block_nr=7 scheduling free USF for polling at FN=1289738 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289738 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:119 - N3103 exceeded<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FINISHED to RELEASING<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289777 block_nr=5 scheduling free USF for polling at FN=1289782 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>
[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=506<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=506<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=110<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=110<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289916 block_nr=1 scheduling free USF for polling at FN=1289920 of UL TFI=1<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289920 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xcb46771f <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 62<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f<br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 454<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1289959 block_nr=11 scheduling free USF for polling at FN=1289964 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:158 - Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1290024 block_nr=2 scheduling free USF for polling at FN=1290029 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1290141 block_nr=5 scheduling free USF for polling at FN=1290146 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1290193 block_nr=5 scheduling free USF for polling at FN=1290198 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1290237 block_nr=3 scheduling free USF for polling at FN=1290241 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1290328 block_nr=0 scheduling free USF for polling at FN=1290332 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:515 Releasing due to PACCH assignment timeout.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:905 Software error: Pending downlink assignment. This may not happen, because the assignment message never gets transmitted. Please be shure not to free in this state. PLEASE FIX!<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=116, fn=1290786<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x74, Fn=1290786 (13,27,16)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 UL TBF=0 timer 3169 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:536 TBF T3169 timeout during transsmission<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1290874 block_nr=6 scheduling free USF for polling at FN=1290878 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1290878 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 454<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because UL TBF=0 exists for TLLI=0xcb46771f<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1290991 block_nr=9 scheduling free USF for polling at FN=1290995 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1290995 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=506<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=506<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=110<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=110<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291060 block_nr=1 scheduling free USF for polling at FN=1291064 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291064 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291112 block_nr=1 scheduling free USF for polling at FN=1291116 of DL TFI=0<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=454<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 62<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291203 block_nr=10 scheduling free USF for polling at FN=1291207 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=1291203 TFI=0 (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:90 - Downlink ACK was received<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291290 block_nr=6 scheduling free USF for polling at FN=1291294 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1660 Received acknowledge of all blocks, but without final ack inidcation (don't worry)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291376 block_nr=2 scheduling free USF for polling at FN=1291381 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1692 Trigger dowlink assignment on PACCH, because another LLC PDU has arrived in between<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to ASSIGN<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291407 block_nr=9 scheduling free USF for polling at FN=1291411 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291411 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291450 block_nr=7 scheduling free USF for polling at FN=1291454 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=117, fn=1291621<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x75, Fn=1291621 (14,46,19)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291706 block_nr=6 scheduling free USF for polling at FN=1291710 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291710 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=70<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291784 block_nr=0 scheduling free USF for polling at FN=1291788 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 107<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=452022112638582)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xcb46771f Immediate Assignment Downlink (PCH)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=cb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291788 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=107<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291862 block_nr=6 scheduling free USF for polling at FN=1291866 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291948 block_nr=2 scheduling free USF for polling at FN=1291953 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1291979 block_nr=9 scheduling free USF for polling at FN=1291983 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291983 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=70<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292044 block_nr=0 scheduling free USF for polling at FN=1292048 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292048 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f<br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292100 block_nr=1 scheduling free USF for polling at FN=1292104 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:158 - Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292143 block_nr=11 scheduling free USF for polling at FN=1292148 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292195 block_nr=11 scheduling free USF for polling at FN=1292200 of DL TFI=0<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292265 block_nr=3 scheduling free USF for polling at FN=1292269 of DL TFI=0<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292390 block_nr=8 scheduling free USF for polling at FN=1292395 of DL TFI=0<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:515 Releasing due to PACCH assignment timeout.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:905 Software error: Pending downlink assignment. This may not happen, because the assignment message never gets transmitted. Please be shure not to free in this state. PLEASE FIX!<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=452022112638582)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xcb46771f Immediate Assignment Downlink (PCH)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=cb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=117, fn=1292613<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x75, Fn=1292613 (14,18,23)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292676 block_nr=2 scheduling free USF for polling at FN=1292681 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292707 block_nr=9 scheduling free USF for polling at FN=1292711 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292711 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>[0;m<br>
[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292750 block_nr=7 scheduling free USF for polling at FN=1292754 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=70<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292754 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292793 block_nr=5 scheduling free USF for polling at FN=1292798 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1692 Trigger dowlink assignment on PACCH, because another LLC PDU has arrived in between<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to ASSIGN<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292824 block_nr=0 scheduling free USF for polling at FN=1292828 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292828 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292867 block_nr=10 scheduling free USF for polling at FN=1292871 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=1292867 TFI=0 (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=506<br>
[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=506<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>
[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=153<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=153<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting DL TBF=0 timer 3191 while old timer 3191 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292958 block_nr=7 scheduling free USF for polling at FN=1292962 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292962 block_nr=8 scheduling free USF for polling at FN=1292967 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292967 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 62<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f<br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>
[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 416<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506<br>[0;m<br>
[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 416<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>
[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 268<br>[0;m<br>
[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1292997 block_nr=4 scheduling free USF for polling at FN=1293001 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=1292997 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:158 - Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293157 block_nr=5 scheduling free USF for polling at FN=1293162 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293162 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:337 Recovered downlink assignment for DL TBF=0<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293274 block_nr=8 scheduling free USF for polling at FN=1293279 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293305 block_nr=3 scheduling free USF for polling at FN=1293309 of DL TFI=0<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293309 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293365 block_nr=5 scheduling free USF for polling at FN=1293370 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293370 block_nr=6 scheduling free USF for polling at FN=1293374 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293374 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=416)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293456 block_nr=2 scheduling free USF for polling at FN=1293461 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=416<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293543 block_nr=10 scheduling free USF for polling at FN=1293547 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=1293543 TFI=0 (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:90 - Downlink ACK was received<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293630 block_nr=6 scheduling free USF for polling at FN=1293634 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=0.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293660 block_nr=1 scheduling free USF for polling at FN=1293664 of DL TFI=0<br>
[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>
[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506<br>[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 416<br>
[0;m<br>[0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293664 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293721 block_nr=3 scheduling free USF for polling at FN=1293725 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293725 block_nr=4 scheduling free USF for polling at FN=1293729 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=416)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293725 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:368 Error: received PACET CONTROL ACK at no request<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:107 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293812 block_nr=0 scheduling free USF for polling at FN=1293816 of DL TFI=0<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293820 block_nr=2 scheduling free USF for polling at FN=1293825 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=416<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293903 block_nr=9 scheduling free USF for polling at FN=1293907 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1293989 block_nr=5 scheduling free USF for polling at FN=1293994 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one:<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=1.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=10<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294020 block_nr=0 scheduling free USF for polling at FN=1294024 of DL TFI=0<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294024 block_nr=1 scheduling free USF for polling at FN=1294028 of UL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294024 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=268)<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294067 block_nr=11 scheduling free USF for polling at FN=1294072 of UL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294085 block_nr=3 scheduling free USF for polling at FN=1294089 of UL TFI=1<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294093 block_nr=5 scheduling free USF for polling at FN=1294098 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294089 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=268<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294180 block_nr=1 scheduling free USF for polling at FN=1294184 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:119 - N3103 exceeded<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FINISHED to RELEASING<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending <br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294267 block_nr=9 scheduling free USF for polling at FN=1294271 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=1.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294297 block_nr=4 scheduling free USF for polling at FN=1294301 of DL TFI=0<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=1294297 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>
[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=416)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:135 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ASSIGNMENT.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:90 - Downlink ACK was received<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294379 block_nr=11 scheduling free USF for polling at FN=1294384 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294384 TLL=0xcb46771f (TRX 0 TS 7)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294410 block_nr=6 scheduling free USF for polling at FN=1294414 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294449 block_nr=3 scheduling free USF for polling at FN=1294453 of UL TFI=1<br>[0;m<br>[1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=416<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294457 block_nr=5 scheduling free USF for polling at FN=1294462 of DL TFI=0<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294453 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xcb46771f <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE<br>[0;m<br>[1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=116, fn=1294650<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x74, Fn=1294650 (16,15,6)<br>[0;m<br>
[0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one:<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:225  Found TFI=1.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to ASSIGN<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment -------------------------<br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294739 block_nr=10 scheduling free USF for polling at FN=1294743 of UL TFI=1<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294743 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 1 TLLI: 0xcb46771f <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from ASSIGN to FLOW<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62<br>[0;m<br>[1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;36m<0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=1294804 block_nr=1 scheduling free USF for polling at FN=1294808 of UL TFI=1<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending <br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block -------------------------<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294808 TLL=0xcb46771f (TRX 0 TS 7)<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xcb46771f <br>[0;m<br>
[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xcb46771f.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169.<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:501 UL TBF=0 timer 3169 expired.<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:536 TBF T3169 timeout during transsmission<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH<br>
[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received<br>[0;m<br>[0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout<br>[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f.<br>
[0;m<br>[0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here **********<br>[0;m</div>
<div>Osmo-PCU> quit<br>% Unknown command.<br>Osmo-PCU> exit<br></div>
<div>Regards,</div>
<div>Vladimir<br></div>
<div class="gmail_quote">On Tue, Oct 30, 2012 at 10:24 AM, jolly <span dir="ltr"><<a href="mailto:andreas@eversberg.eu" target="_blank">andreas@eversberg.eu</a>></span> wrote:<br>
<blockquote style="BORDER-LEFT:#ccc 1px solid;MARGIN:0px 0px 0px 0.8ex;PADDING-LEFT:1ex" class="gmail_quote"><u></u>
<div text="#000000" bgcolor="#ffffff">Vladimir Rolbin wrote: 
<blockquote type="cite">
<div dir="ltr">
<div>Hi Andreas,</div>
<div> </div>
<div>1. If I see well the pcu expects <span style="FONT-FAMILY:'Times New Roman','serif';FONT-SIZE:12pt">PCU_IF_MSG_DATA_CNF data starting from plen..</span></div>
<div><span style="FONT-FAMILY:'Times New Roman','serif';FONT-SIZE:12pt">   This error:</span></div>
<div><span style="FONT-FAMILY:'Times New Roman','serif';FONT-SIZE:12pt"></span> </div>
<div><span style="FONT-FAMILY:'Times New Roman','serif';FONT-SIZE:12pt">   <span lang="EN"><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</span></span></div>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p> </p>
<div>is caused by openBTS's confirm from PCU_IF_SAPI_AGCH handler, the example of the frame sent back to the pcu:</div></div></blockquote>hi vladimir,<br><br>check out pcu_rx_data_cnf() at pcu_l1_if.cpp. it filters the confirm and only passes PCU_IF_SAPI_PCH to gprs_rlcmac_imm_ass_cnf(). in your case above, the uplink assignment on AGCH may result in a confirm, but in this case it should have PCH sapi in order to be ignored:<br>
<br>it might help to add this to pcu_rx_data_cnf():<br><br>case PCU_IF_SAPI_AGCH:<br>    break;<br><br>sysmobts is currently not sending an AGCH confirm via PCH interface, so this is why i did not implement it.<br><br><br>

<blockquote type="cite">
<div dir="ltr">
<div><span lang="EN"><span style="FONT-FAMILY:'Calibri','sans-serif';FONT-SIZE:11pt"><span lang="EN">
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353693 block_nr=4 scheduling free USF for polling at FN=2353697 of DL TFI=0</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353702 block_nr=6 scheduling free USF for polling at FN=2353706 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=2353693 TFI=0 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2353706 TLL=0xec8157f3 (TRX 0 TS 7)</p></span></span></span></div></div></blockquote>the packet control ack seems ok. it is polled at 2353693 with 13 bursts in advance and therefore the block 2352706 is reserved for uplink. (the USF is set accordingly 4 bursts earlier.)<br>
<br>but the packet downlink ack is received 4 bursts too early. i would suggest to set DRLCMAC debugging to DEBUG. at gprs_rlcmac_send_data_block_acknowledged() the debugging shows in which FN it is scheduled. then the frame number to be polled is set there:<br>
<br>...<br>LOGP(DRLCMAC, LOGL_DEBUG, "Polling sheduled in this "<br>    "TS %d\n", ts);<br>...<br>tbf->poll_state = GPRS_RLCMAC_POLL_SCHED;<br>tbf->poll_fn = (fn + 13) % 2715648;<br>...<br><br>you may also just change the log level of that debug line to LOGL_NOTICE.<br>
<br><br>regards,<br><br>andreas<br><br></div></blockquote></div><br></div>