What file extensions are allowed? I had reject problems before if somthing attached..

I think it depends on size and not extension. I could increase the limit if needed. Let me know if get a reject next time. Sent from my Android device. -- Regards, Alexander Chemeris CEO, Fairwaves LLC http://fairwaves.ru 30.10.2012 16:13 пользователь "Vladimir Rolbin" &lt;vrolbin(a)gmail.com&gt; написал: > What file extensions are allowed? I had reject problems before if > somthing attached.. > > Regards, > Vladimir Rolbin > On Tue, Oct 30, 2012 at 2:07 PM, Alexander Chemeris < > alexander.chemeris(a)gmail.com&gt; wrote: > >> Guys, >> >> Just a generic comment. When you post logs - please attach them to >> e-mail as a text file instead of copy-pasting them into the message >> body. >> >> >> -- >> Regards, >> Alexander Chemeris. >> CEO, Fairwaves LLC / ООО УмРадио >> http://fairwaves.ru >> > >

Hi, here is the log with debug info: Welcome to the Osmo-PCU control interface Copyright (C) 2012 by ... License GNU GPL version 2 or later This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Osmo-PCU> Osmo-PCU> Osmo-PCU> Osmo-PCU> Osmo-PCU> Osmo-PCU> log Osmo-PCU> loglogging en Osmo-PCU> logging enenable 1 % Unknown command. Osmo-PCU> logging enable 1 Osmo-PCU> log Osmo-PCU> loglogging fil Osmo-PCU> logging filfilter all 1 Osmo-PCU> log Osmo-PCU> loglogging lev Osmo-PCU> logging levlevel rl Osmo-PCU> logging level rlrlcmac f de Osmo-PCU> logging level rlcmac dedebug Osmo-PCU> Osmo-PCU> Osmo-PCU> Osmo-PCU> Osmo-PCU> Osmo-PCU> [1;32m<0001> pcu_l1_if.cpp:334 BTS available [0;m [1;32m<0001> pcu_l1_if.cpp:335 mcc=452 [0;m [1;32m<0001> pcu_l1_if.cpp:336 mnc=2 [0;m [1;32m<0001> pcu_l1_if.cpp:337 lac=1000 [0;m [1;32m<0001> pcu_l1_if.cpp:338 rac=0 [0;m [1;32m<0001> pcu_l1_if.cpp:339 cell_id=0 [0;m [1;32m<0001> pcu_l1_if.cpp:340 nsei=8 [0;m [1;32m<0001> pcu_l1_if.cpp:345 nse_timer=0 0 0 0 0 0 0 [0;m [1;32m<0001> pcu_l1_if.cpp:353 cell_timer=0 0 0 0 0 0 0 0 0 0 0 [0;m [1;32m<0001> pcu_l1_if.cpp:354 repeat_time=5 [0;m [1;32m<0001> pcu_l1_if.cpp:355 repeat_count=10 [0;m [1;32m<0001> pcu_l1_if.cpp:356 bvci=7 [0;m [1;32m<0001> pcu_l1_if.cpp:357 t3142=20 [0;m [1;32m<0001> pcu_l1_if.cpp:358 t3169=5 [0;m [1;32m<0001> pcu_l1_if.cpp:359 t3191=5 [0;m [1;32m<0001> pcu_l1_if.cpp:360 t3193=1000 (ms) [0;m [1;32m<0001> pcu_l1_if.cpp:361 t3195=5 [0;m [1;32m<0001> pcu_l1_if.cpp:362 n3101=10 [0;m [1;32m<0001> pcu_l1_if.cpp:363 n3103=4 [0;m [1;32m<0001> pcu_l1_if.cpp:364 n3105=8 [0;m [1;32m<0001> pcu_l1_if.cpp:365 cv_countdown=15 [0;m [1;32m<0001> pcu_l1_if.cpp:366 dl_tbf_ext=0 [0;m [1;32m<0001> pcu_l1_if.cpp:367 ul_tbf_ext=0 [0;m [1;32m<0001> pcu_l1_if.cpp:376 initial_cs=1 [0;m [1;32m<0001> pcu_l1_if.cpp:377 initial_mcs=0 [0;m [1;32m<0001> pcu_l1_if.cpp:378 nsvci=4 [0;m [1;32m<0001> pcu_l1_if.cpp:379 local_port=5944 [0;m [1;32m<0001> pcu_l1_if.cpp:380 remote_port=23000 [0;m [1;32m<0001> pcu_l1_if.cpp:381 remote_ip=2130706433 [0;m [1;32m<0001> pcu_l1_if.cpp:82 Sending activate request: trx=0 ts=7 [0;m [1;32m<0001> pcu_l1_if.cpp:429 PDCH: trx=0 ts=7 [0;m [1;35m<0009> gprs_bssgp_pcu.cpp:491 NS-VC 4 is unblocked. [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:532 Sending reset on BVCI 0 [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:540 Sending reset on BVCI 7 [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:548 Sending unblock on BVCI 7 [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=120, fn=1280580 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 0 RACH qbit-ta=0 ra=0x78, Fn=1280580 (5,21,2) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 0 Immediate Assignment Uplink (AGCH) [0;m [1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xace80214 of UL DATA TBF=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=43 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xace80214 len=43 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xace80214 IMSI: 000 len: 9 [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xace80214 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because UL TBF=0 exists for TLLI=0xace80214 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xace80214 Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1280664 TLL=0xace80214 (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xace80214 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=9 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1280690 TLL=0xace80214 (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xace80214 [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xace80214. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=120, fn=1280840 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 0 RACH qbit-ta=0 ra=0x78, Fn=1280840 (5,26,2) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 0 Immediate Assignment Uplink (AGCH) [0;m [1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xace80214 of UL DATA TBF=0. [0;m [1;36m<0005> gprs_rlcmac_data.cpp:882 Got RACH from TLLI=0xace80214 while DL TBF=0 still exists. Killing pending DL TBF [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xace80214. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=17 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xace80214 len=17 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xace80214 IMSI: 000 len: 9 [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xace80214 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=000) [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xace80214 Immediate Assignment Downlink (PCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=ace80214 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=1280907 TLL=0xace80214 (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=9 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:107 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK [0;m [0;33m<0002> gprs_rlcmac_data.cpp:82 - Assignment was on CCCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [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 [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=122, fn=1281151 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=1. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 1 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 1 RACH qbit-ta=0 ra=0x7a, Fn=1281151 (6,31,1) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 1 Immediate Assignment Uplink (AGCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xace80214. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xace80214 of UL DATA TBF=1. [0;m [1;36m<0005> gprs_rlcmac_data.cpp:891 Got RACH from TLLI=0xace80214 while UL TBF=0 still exists. Killing pending UL TBF [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xace80214. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=17 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xace80214 len=17 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xace80214 IMSI: 452022112638582 len: 24 [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xace80214 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=452022112638582) [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xace80214 Immediate Assignment Downlink (PCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=ace80214 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1281219 TLL=0xace80214 (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xace80214 Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xace80214 [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xace80214. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=24 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xace80214 Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=120, fn=1281444 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 0 RACH qbit-ta=0 ra=0x78, Fn=1281444 (6,18,8) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 0 Immediate Assignment Uplink (AGCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xace80214. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xcb46771f of UL DATA TBF=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=8 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=8 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1281522 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=123, fn=1288588 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 0 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1159 TBF: [UPLINK] START TFI: 0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1162 RX: [PCU <- BTS] TFI: 0 RACH qbit-ta=0 ra=0x7b, Fn=1288588 (11,22,2) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1164 TX: START TFI: 0 Immediate Assignment Uplink (AGCH) [0;m [1;36m<0005> gprs_rlcmac_data.cpp:877 Decoded premier TLLI=0xcb46771f of UL DATA TBF=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=150 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=150 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 55 [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because UL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1288698 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [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 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=55 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1288729 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=117, fn=1288901 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x75, Fn=1288901 (12,29,3) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1288993 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=72 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=72 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 111 [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because UL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289058 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289088 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=111 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=118, fn=1289261 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x76, Fn=1289261 (12,32,25) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [1;36m<0005> gprs_rlcmac_data.cpp:437 Got RACH from TLLI=0xcb46771f while DL TBF=0 still exists. Killing pending DL TBF [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289353 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=1289409 TLL=0xcb46771f (TRX 0 TS 7) [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=452022112638582) [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xcb46771f Immediate Assignment Downlink (PCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=cb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:107 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received [0;m [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 [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF [0;m [0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289608 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=1. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289682 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF [0;m [0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289738 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:119 - N3103 exceeded [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FINISHED to RELEASING [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=506 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=506 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=110 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=110 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1289920 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 62 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF [0;m [0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 454 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:158 - Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:515 Releasing due to PACCH assignment timeout. [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f. [0;m [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! [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=116, fn=1290786 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x74, Fn=1290786 (13,27,16) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 UL TBF=0 timer 3169 expired. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:536 TBF T3169 timeout during transsmission [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received [0;m [0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1290878 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 454 [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because UL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1290995 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=506 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=506 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=110 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=110 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291064 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=454 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 62 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=1291203 TFI=0 (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:90 - Downlink ACK was received [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1660 Received acknowledge of all blocks, but without final ack inidcation (don't worry) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1692 Trigger dowlink assignment on PACCH, because another LLC PDU has arrived in between [0;m [0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291411 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=117, fn=1291621 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x75, Fn=1291621 (14,46,19) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291710 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 107 [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=452022112638582) [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xcb46771f Immediate Assignment Downlink (PCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=cb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291788 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=107 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1291983 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292048 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF [0;m [0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:158 - Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:515 Releasing due to PACCH assignment timeout. [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f. [0;m [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! [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:233 TBF: [DOWNLINK] START TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1848 Send dowlink assignment for TBF=0 on PCH, no TBF exist (IMSI=452022112638582) [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xcb46771f Immediate Assignment Downlink (PCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1894 Got IMM.ASS confirm for TLLI=cb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=117, fn=1292613 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x75, Fn=1292613 (14,18,23) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 0 expired. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292711 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF [0;m [0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292754 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 70 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1692 Trigger dowlink assignment on PACCH, because another LLC PDU has arrived in between [0;m [0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292828 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=1292867 TFI=0 (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=506 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=506 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=153 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=153 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting DL TBF=0 timer 3191 while old timer 3191 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1292967 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 62 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:152 TBF in WAIT RELEASE state (T3193), so reuse TBF [0;m [0;33m<0002> gprs_rlcmac.cpp:921 ********** TBF update ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:444 - Assign downlink TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1837 Send dowlink assignment on PACCH, because DL TBF=0 exists for TLLI=0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from WAIT RELEASE to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 416 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 416 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 268 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=1292997 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:158 - Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Downlink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1769 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1772 ------------------------- TX : Packet Downlink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293162 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:316 TBF: [UPLINK] DOWNLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 0. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:337 Recovered downlink assignment for DL TBF=0 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293309 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293374 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=416) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=416 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=1293543 TFI=0 (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:90 - Downlink ACK was received [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=0. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=0 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 506 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [1;34m<0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xcb46771f IMSI: 452022112638582 len: 416 [0;m [0;33m<0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293664 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=416) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1293725 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:368 Error: received PACET CONTROL ACK at no request [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:107 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received [0;m [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 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=416 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=1. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294024 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=268) [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294089 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=268 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:119 - N3103 exceeded [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=0 changes state from FINISHED to RELEASING [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=0 timer 3169 while old timer 3169 pending [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:410 MS requests UL TBF in ack message, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=1. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=1294297 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=416) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:135 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ASSIGNMENT. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:90 - Downlink ACK was received [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1521 Polling is already sheduled for TBF=0, so we must wait for requesting downlink ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294384 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 0 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [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 [0;m [1;33m<0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=416 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1532 Polling sheduled in this TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294453 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping DL TBF=0 timer 3191. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:395 RX: [PCU <- BTS] TFI: 0 TLLI: 0xcb46771f Packet Downlink Ack/Nack [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting DL TBF=0 timer 3193. [0;m [0;33m<0002> gprs_rlcmac.cpp:973 DL TBF=0 changes state from FINISHED to WAIT RELEASE [0;m [1;32m<0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=116, fn=1294650 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1116 MS requests UL TBF on RACH, so we provide one: [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1119 MS requests single block allocation [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1136 RX: [PCU <- BTS] RACH qbit-ta=0 ra=0x74, Fn=1294650 (16,15,6) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 DL TBF=0 timer 3193 expired. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:442 MS requests UL TBF in packet ressource request of single block, so we provide one: [0;m [0;33m<0002> gprs_rlcmac.cpp:214 Searching for first unallocated TFI: TRX=0 first TS=7 [0;m [0;33m<0002> gprs_rlcmac.cpp:225 Found TFI=1. [0;m [0;33m<0002> gprs_rlcmac.cpp:351 ********** TBF starts here ********** [0;m [0;33m<0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=10 [0;m [0;33m<0002> gprs_rlcmac.cpp:421 Slot Allocation (Algorithm A) for class 10 [0;m [0;33m<0002> gprs_rlcmac.cpp:434 - Assign uplink TS=7 USF=1 [0;m [0;33m<0002> gprs_rlcmac.cpp:948 - Setting Control TS 7 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from NULL to ASSIGN [0;m [0;33m<0002> gprs_rlcmac.cpp:983 Starting UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:452 Change control TS to 7 until assinment is complete. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xcb46771f Packet Uplink Assignment (PACCH) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1083 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:1086 ------------------------- TX : Packet Uplink Assignment ------------------------- [0;m [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 [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294743 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:343 TBF: [DOWNLINK] UPLINK ASSIGNED TFI: 1 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from ASSIGN to FLOW [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [1;36m<0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62 [0;m [1;34m<0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xcb46771f len=62 [0;m [0;33m<0002> gprs_rlcmac.cpp:973 UL TBF=1 changes state from FLOW to FINISHED [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [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 [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac.cpp:988 Restarting UL TBF=1 timer 3169 while old timer 3169 pending [0;m [0;33m<0002> gprs_rlcmac_data.cpp:270 +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++ [0;m [0;33m<0002> gprs_rlcmac_data.cpp:273 ------------------------- RX : Uplink Control Block ------------------------- [0;m [0;33m<0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=1294808 TLL=0xcb46771f (TRX 0 TS 7) [0;m [0;33m<0002> gprs_rlcmac_data.cpp:297 RX: [PCU <- BTS] TFI: 1 TLLI: 0xcb46771f Packet Control Ack [0;m [0;33m<0002> gprs_rlcmac_data.cpp:302 TBF: [UPLINK] END TFI: 1 TLLI: 0xcb46771f [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:1005 Stopping UL TBF=1 timer 3169. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m [0;33m<0002> gprs_rlcmac_data.cpp:501 UL TBF=0 timer 3169 expired. [0;m [0;33m<0002> gprs_rlcmac_data.cpp:536 TBF T3169 timeout during transsmission [0;m [0;33m<0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH [0;m [0;33m<0002> gprs_rlcmac_data.cpp:86 - Uplink data was received [0;m [0;33m<0002> gprs_rlcmac_data.cpp:542 TBF will be freed due to timeout [0;m [0;33m<0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xcb46771f. [0;m [0;33m<0002> gprs_rlcmac.cpp:911 ********** TBF ends here ********** [0;m Osmo-PCU> quit % Unknown command. Osmo-PCU> exit Regards, Vladimir On Tue, Oct 30, 2012 at 10:24 AM, jolly &lt;andreas(a)eversberg.eu&gt; wrote:

Vladimir Rolbin wrote: hi vladimir, i missed something. this debug line above does not show us the frame number. you can change that debug line to: LOGP(DRLCMAC, LOGL_DEBUG, "Polling sheduled in this " "TS %d, FN=%d\n", ts, fn); regards, andreas

Hi, Vladimir! Thank you for sending logs and pcap files! I fixed L2 pseudo length bug, this problem was not only in SI13, but also in SI3. Now you can update your OpenBTS repository. 2012/10/31 Vladimir Rolbin &lt;vrolbin(a)gmail.com&gt;om>: PDCH), UE not UE (env -- Regards, Ivan Kluchnikov. http://fairwaves.ru

Hi, Ivan 1) First pls fix the following critical bug, readIndex is modified by readField cause delivered by reference, so every not first iteration it'll have a bad value : *** ./DCCHDispatch.bug.cpp 2012-11-01 12:33:43.000000000 +0200 --- ./DCCHDispatch.cpp 2012-11-01 16:48:29.000000000 +0200 *************** *** 469,474 **** --- 469,475 ---- } L3Frame *l3 = new L3Frame(msg->tail(8), UNIT_DATA); COUT("RX: [ BTS <- PCU ] AGCH: " << *l3); + readIndex = 0; //vr, fix l2Len = msg->readField(readIndex, len); l3->L2Length(l2Len); AGCH->send(l3); or ( I like it more ) *** ./DCCHDispatch.bug.cpp 2012-11-01 12:33:43.000000000 +0200 --- ./DCCHDispatch.fix0.cpp 2012-11-01 17:58:15.000000000 +0200 *************** *** 431,438 **** char buf[MAX_UDP_LENGTH]; - unsigned len = 6; - size_t readIndex = 0; size_t l2Len = 0; // Send to PCU PhConnectInd primitive. --- 431,436 ---- *************** *** 469,475 **** } L3Frame *l3 = new L3Frame(msg->tail(8), UNIT_DATA); COUT("RX: [ BTS <- PCU ] AGCH: " << *l3); ! l2Len = msg->readField(readIndex, len); l3->L2Length(l2Len); AGCH->send(l3); txPhDataIndCnf(*msg, gBTS.time()); --- 467,473 ---- } L3Frame *l3 = new L3Frame(msg->tail(8), UNIT_DATA); COUT("RX: [ BTS <- PCU ] AGCH: " << *l3); ! l2Len = msg->peekField(0, 6); l3->L2Length(l2Len); AGCH->send(l3); txPhDataIndCnf(*msg, gBTS.time()); *************** *** 479,486 **** L3Frame *msg1 = new L3Frame(msg->tail(8*4), UNIT_DATA); L3Frame *msg2 = new L3Frame(msg->tail(8*4), UNIT_DATA); COUT("RX: [ BTS <- PCU ] PCH: " << *msg1); ! readIndex = 24; ! l2Len = msg->readField(readIndex, len); msg1->L2Length(l2Len); msg2->L2Length(l2Len); // HACK -- We send every page twice. --- 477,483 ---- L3Frame *msg1 = new L3Frame(msg->tail(8*4), UNIT_DATA); L3Frame *msg2 = new L3Frame(msg->tail(8*4), UNIT_DATA); COUT("RX: [ BTS <- PCU ] PCH: " << *msg1); ! l2Len = msg->peekField(8*3, 6); msg1->L2Length(l2Len); msg2->L2Length(l2Len); // HACK -- We send every page twice. I would reccomend also to fix BitVector.cpp known bug: void BitVector::unpack(const unsigned char* src) { // Assumes MSB-first packing. unsigned bytes = size()/8; for (unsigned i=0; i<bytes; i++) { fillField(i*8,src[i],8); } unsigned whole = bytes*8; unsigned rem = size() - whole; if (rem==0) return; fillField(whole,src[bytes] >> (8-rem),rem); //here } USRPDevice.cpp known bug: double USRPDevice::setTxGain(double dB) { writeLock.lock(); if (dB > maxTxGain()) dB = maxTxGain(); if (dB < minTxGain()) dB = minTxGain(); LOG(NOTICE) << "Setting TX gain to " << dB << " dB."; if (!m_dbTx->set_gain(dB)) // here LOG(ERR) << "Error setting TX gain"; writeLock.unlock(); return dB; } BSIC calculation: prim->u.info_ind.bsic = (gConfig.getNum("GSM.Identity.BSIC.NCC") << 3) | gConfig.getNum("GSM.Identity.BSIC.BCC"); 2) With up to date OpenBTS pulled from git today and critical fix only I've got the results identical to session 2 and 3 I've recorded yesterday. I attach the file with problematic scenario. I think you may recreate the problem with every SonyErricson supporting 3G and GSM (my env is Suse 11.4 or Ubuntu 11.10, libusb_1_0 and libusrp-3.4.2). Regards, Vladimir

In attachment you can find patch for osmo-pcu.

T3192 is 500 ms for my env set..

Hi, Vladimir! Thank you for your fixes, I will check and apply them tomorrow! In attachment you can find patch for osmo-pcu. I guess, that this patch should fix problem of receiving PACKET DOWNLINK ACK messages with unknown FN. Please, check it with your phones and notify me about results. 2012/11/1 Vladimir Rolbin &lt;vrolbin(a)gmail.com&gt;om>: it'll I've 11.4 -- Regards, Ivan Kluchnikov. http://fairwaves.ru