<div dir="ltr"><p>Hi Andreas,<br> <br>1. If I see well the pcu expects PCU_IF_MSG_DATA_CNF data starting from plen..<br> This error:<br> <br> <0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)<br>
<0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)<br> <br>is caused by openBTS's confirm from PCU_IF_SAPI_AGCH handler, the example of the frame sent back to the pcu:<br>
<br>1351419034.590852 3048246128: [ PCU -> BTS ] AGCH: L2Length 11 primitive=UNIT_DATA raw=(063f100f400279cbe40000c8001d002b2b2b2b2b2b2b)<br>1351419034.590927 3048246128: [ BTS -> PCU ] PhPchCnf: 2d063f100f400279cbe40000c8001d002b2b2b2b2b2b2b<br>
If decoded the rest octets realy do not start with expected bit sequence (HH01) :<br> [Protocols in frame: user_dlt:gsm_a_ccch]<br>DLT: 147, Payload: gsm_a_ccch (GSM CCCH)<br>GSM CCCH - Immediate Assignment<br> L2 Pseudo Length<br>
0010 11.. = L2 Pseudo Length value: 11<br> Protocol Discriminator: Radio Resources Management messages<br> .... 0110 = Protocol discriminator: Radio Resources Management messages (0x06)<br> 0000 .... = Skip Indicator: 0<br>
Message Type: Immediate Assignment<br> Page Mode<br> .... 0000 = Page Mode: Normal paging (0)<br> Dedicated mode or TBF<br> 0001 .... = Dedicated mode or TBF: This message assigns an uplink TBF or is the second message of two in a two-message assignment of an uplink or downlink TBF (1)<br>
Packet Channel Description<br> 0000 1... = Spare bits (ignored by receiver)<br> .... .111 = Timeslot: 7<br> 010. .... = Training Sequence: 2<br> ...0 .... = Hopping channel: No<br> .... 00.. = Spare<br>
Single channel : ARFCN 2<br> Request Reference<br> Random Access Information (RA): 121<br> 1100 1... = T1': 25<br> .... .011 111. .... = T3: 31<br> ...0 0100 = T2: 4<br> [RFN: 33232]<br>
Timing Advance<br> Timing advance value: 0<br> Mobile Allocation<br> Length: 0<br> IA Rest Octets<br> H... ....: First Discriminator Bit: High<br> .H.. ....: Second Discriminator Bit: High<br>
..0. ....: Discriminator Bit: Packet Assignment<br> ...0 ....: Discriminator Bit: Packet Uplink Assignment<br> Packet Uplink Assignment<br> .... 1...: Packet Uplink Assignment: Normal<br> .... .000 00.. .... = TFI_Assignment: 0<br>
..0. .... = Polling: no action is required from MS<br> ...0 ....: Allocation Type: Dynamic Allocation (mandatory after Rel-4)<br> .... 000. = USF: 0<br> .... ...0 = USF_granularity: the mobile station shall transmit one RLC/MAC block<br>
0... ....: P0: Not Present<br> .00. .... = Channel_Coding_Command: CS-1 (0)<br> ...1 .... = TLLI_Block_Channel_Coding: mobile station shall use coding scheme as specified by the corresponding CHANNEL CODING COMMAND or EGPRS CHANNEL CODING COMMAND field<br>
.... 1...: Alpha: Present<br> .... .101 0... .... = Alpha: 1.0 (10)<br> .000 00.. = Gamma: 0 dB (0)<br> .... ..0.: Timing Advance Index: Not Present<br> .... ...0: TBF Starting Time: Not Present<br>
L... ....: Additions in R99: Not Present<br> .L.. ....: Additions in Rel-6: Not Present<br> Padding Bits: default padding<br> <br>2. To make things clearer I've added several additional prints:<br>
diff -i -w ./osmo-pcu-jolly_git_11_10_12/src/gprs_rlcmac_data.cpp ./temp/osmo-pcu-jolly_git_20_08_12/src/gprs_rlcmac_data.cpp <br>283a284,290<br>> else<br>> {<br>> LOGP(DRLCMAC, LOGL_NOTICE, "PACKET CONTROL ACK with "<br>
> "expected FN=%u TLL=0x%08x (TRX %d TS %d)\n",<br>> fn, tlli, trx, ts);<br>> }<br>> <br>472a480,483<br>> case MT_PACKET_UPLINK_DUMMY_CONTROL_BLOCK: //vr, added<br>> LOGP(DRLCMAC, LOGL_NOTICE, "RX: [PCU <- BTS] FIXME: Packet uplink dummy control block\n");<br>
> break;<br>> <br>474c485<br>< LOGP(DRLCMAC, LOGL_NOTICE, "RX: [PCU <- BTS] unknown control block received\n");<br>---<br>> LOGP(DRLCMAC, LOGL_NOTICE, "RX: [PCU <- BTS] unknown control block received %d\n", ul_control_block->u.MESSAGE_TYPE);</p>
<p>and<br>diff -i -w ./osmo-pcu-jolly_git_11_10_12/src/gprs_rlcmac_sched.cpp ./temp/osmo-pcu-jolly_git_20_08_12/src/gprs_rlcmac_sched.cpp<br>255c255<br>< LOGP(DRLCMACSCHED, LOGL_DEBUG, "Received RTS for PDCH: TRX=%d "<br>
---<br>> LOGP(DRLCMACSCHED, LOGL_INFO, "Received RTS for PDCH: TRX=%d "</p>
<div>Packet uplink dummy control block is sent by Nokia 5000d, possibly requires handling.. <br>So in the following example (the full pcu and bts log I'll put later):<br><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353693 block_nr=4 scheduling free USF for polling at FN=2353697 of DL TFI=0<br>
...<br><0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=2353693 TFI=0 (TRX 0 TS 7) <br>we have a clue that the ack was expected on FN=2353697 but received erlier on FN=2353693. <br> I will add drlcmac debugging to inverstigate it...<br>
<br>Regards,<br>Vladimir Rolbin<br> <br>p.s.</div>
<div> </div>
<div><span lang="EN">
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 288</p>
<p><0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xec8157f3</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=416</p>
<p><0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353515 block_nr=11 scheduling free USF for polling at FN=2353520 of DL TFI=0</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353602 block_nr=7 scheduling free USF for polling at FN=2353606 of DL TFI=0</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506</p>
<p><0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353628 block_nr=1 scheduling free USF for polling at FN=2353632 of DL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2353632 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=75</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=75</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 233</p>
<p><0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xec8157f3</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353693 block_nr=4 scheduling free USF for polling at FN=2353697 of DL TFI=0</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353702 block_nr=6 scheduling free USF for polling at FN=2353706 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=2353693 TFI=0 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2353706 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK.</p>
<p><0002> gprs_rlcmac_data.cpp:82 - Assignment was on CCCH</p>
<p><0002> gprs_rlcmac_data.cpp:90 - Downlink ACK was received</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506</p>
<p><0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=288)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353784 block_nr=1 scheduling free USF for polling at FN=2353788 of DL TFI=0</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=288</p>
<p><0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=233)</p>
<p><0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=233</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2353853 block_nr=5 scheduling free USF for polling at FN=2353858 of DL TFI=0</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=114, fn=2354039</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xec8157f3.</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2354126 block_nr=8 scheduling free USF for polling at FN=2354131 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2354131 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=70</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2354204 block_nr=2 scheduling free USF for polling at FN=2354209 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2354209 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 70</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xec8157f3 Immediate Assignment Downlink (PCH)</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=70</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2354295 block_nr=11 scheduling free USF for polling at FN=2354300 of DL TFI=0</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 70</p>
<p><0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xec8157f3</p>
<p><0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Downlink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2354477 block_nr=5 scheduling free USF for polling at FN=2354482 of DL TFI=0</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=118, fn=2354491</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:158 - Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT.</p>
<p><0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH</p>
<p><0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet</p>
<p><0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Downlink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2354529 block_nr=5 scheduling free USF for polling at FN=2354534 of DL TFI=0</p>
<p><0005> gprs_rlcmac_data.cpp:437 Got RACH from TLLI=0xec8157f3 while DL TBF=0 still exists. Killing pending DL TBF</p>
<p><0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xec8157f3.</p>
<p><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!</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2354577 block_nr=4 scheduling free USF for polling at FN=2354581 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2354581 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=506</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=506</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=184</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=184</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2354789 block_nr=5 scheduling free USF for polling at FN=2354794 of UL TFI=0</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 62</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xec8157f3 Immediate Assignment Downlink (PCH)</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 506</p>
<p><0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xec8157f3</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 468</p>
<p><0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xec8157f3</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2354794 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62</p>
<p><0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2354941 block_nr=4 scheduling free USF for polling at FN=2354945 of DL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=2354941 TFI=0 (TRX 0 TS 7)</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506</p>
<p><0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=468)</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK.</p>
<p><0002> gprs_rlcmac_data.cpp:82 - Assignment was on CCCH</p>
<p><0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet</p>
<p><0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xec8157f3 Immediate Assignment Downlink (PCH)</p>
<p><0002> gprs_rlcmac_data.cpp:529 Continue flow after IMM.ASS confirm</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2355106 block_nr=6 scheduling free USF for polling at FN=2355110 of DL TFI=0</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=468</p>
<p><0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2355197 block_nr=3 scheduling free USF for polling at FN=2355201 of DL TFI=0</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=113, fn=2355401</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xec8157f3.</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2355487 block_nr=10 scheduling free USF for polling at FN=2355491 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2355491 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2355552 block_nr=1 scheduling free USF for polling at FN=2355556 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2355556 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=117, fn=2357508</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2357593 block_nr=4 scheduling free USF for polling at FN=2357597 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2357597 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=70</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=70</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 86</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Downlink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2357654 block_nr=6 scheduling free USF for polling at FN=2357658 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2357658 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2357684 block_nr=1 scheduling free USF for polling at FN=2357688 of UL TFI=0</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=86</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2357688 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2357706 block_nr=6 scheduling free USF for polling at FN=2357710 of DL TFI=0</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=117, fn=2357860</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0005> gprs_rlcmac_data.cpp:437 Got RACH from TLLI=0xec8157f3 while DL TBF=0 still exists. Killing pending DL TBF</p>
<p><0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xec8157f3.</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2357944 block_nr=1 scheduling free USF for polling at FN=2357948 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2357948 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=506</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=506</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=327</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=327</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2358174 block_nr=6 scheduling free USF for polling at FN=2358178 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2358178 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 62</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xec8157f3 Immediate Assignment Downlink (PCH)</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 506</p>
<p><0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xec8157f3</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 164</p>
<p><0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xec8157f3</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62</p>
<p><0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=506)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2358347 block_nr=10 scheduling free USF for polling at FN=2358351 of DL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=2358347 TFI=0 (TRX 0 TS 7)</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=506</p>
<p><0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=164)</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=164</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK.</p>
<p><0002> gprs_rlcmac_data.cpp:82 - Assignment was on CCCH</p>
<p><0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet</p>
<p><0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xec8157f3 Immediate Assignment Downlink (PCH)</p>
<p><0002> gprs_rlcmac_data.cpp:529 Continue flow after IMM.ASS confirm</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2358568 block_nr=1 scheduling free USF for polling at FN=2358572 of DL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0</p>
<p><0004> gprs_rlcmac_data.cpp:1660 Received acknowledge of all blocks, but without final ack inidcation (don't worry)</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2358598 block_nr=8 scheduling free USF for polling at FN=2358603 of DL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2358603 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2358659 block_nr=10 scheduling free USF for polling at FN=2358663 of DL TFI=0</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2358663 block_nr=11 scheduling free USF for polling at FN=2358668 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=2358659 TFI=0 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2358668 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK.</p>
<p><0002> gprs_rlcmac_data.cpp:82 - Assignment was on CCCH</p>
<p><0002> gprs_rlcmac_data.cpp:90 - Downlink ACK was received</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2358750 block_nr=7 scheduling free USF for polling at FN=2358754 of DL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0</p>
<p><0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xec8157f3.</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=116, fn=2369528</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2369614 block_nr=6 scheduling free USF for polling at FN=2369618 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2369618 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2369679 block_nr=9 scheduling free USF for polling at FN=2369683 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2369683 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 62</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xec8157f3 Immediate Assignment Downlink (PCH)</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 62</p>
<p><0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xec8157f3</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62</p>
<p><0004> gprs_rlcmac_data.cpp:1461 - Dequeue next LLC for TBF=0 (len=62)</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2369800 block_nr=1 scheduling free USF for polling at FN=2369804 of DL TFI=0</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 62</p>
<p><0002> gprs_bssgp_pcu.cpp:149 TBF: APPEND TFI: 0 TLLI: 0xec8157f3</p>
<p><0002> gprs_rlcmac_data.cpp:1764 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Downlink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2369848 block_nr=0 scheduling free USF for polling at FN=2369852 of DL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2369852 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2369891 block_nr=10 scheduling free USF for polling at FN=2369895 of DL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:376 PACKET DOWNLINK ACK with unknown FN=2369891 TFI=0 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:180 - Timeout for polling PACKET DOWNLINK ACK.</p>
<p><0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH</p>
<p><0002> gprs_rlcmac_data.cpp:92 - No downlink ACK received yet</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2369978 block_nr=6 scheduling free USF for polling at FN=2369982 of DL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:388 Recovered downlink ack for DL TBF=0</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=116, fn=2370143</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xec8157f3.</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2370225 block_nr=3 scheduling free USF for polling at FN=2370229 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2370229 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=50</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=50</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2370303 block_nr=9 scheduling free USF for polling at FN=2370307 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2370307 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0008> gprs_bssgp_pcu.cpp:145 LLC [SGSN -> PCU] = TLLI: 0xec8157f3 IMSI: 452022112638582 len: 62</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1801 TX: START TFI: 0 TLLI: 0xec8157f3 Immediate Assignment Downlink (PCH)</p>
<p><0004> gprs_rlcmac_data.cpp:1453 Complete DL frame for TBF=0: len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2370394 block_nr=6 scheduling free USF for polling at FN=2370398 of DL TFI=0</p>
<p><0002> gprs_rlcmac.cpp:895 Free DL TBF=0 with TLLI=0xec8157f3.</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=118, fn=2378009</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2378094 block_nr=7 scheduling free USF for polling at FN=2378098 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2378098 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2378159 block_nr=10 scheduling free USF for polling at FN=2378163 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=2378159 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:107 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK</p>
<p><0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH</p>
<p><0002> gprs_rlcmac_data.cpp:86 - Uplink data was received</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2378228 block_nr=2 scheduling free USF for polling at FN=2378233 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2378410 block_nr=8 scheduling free USF for polling at FN=2378415 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2378488 block_nr=2 scheduling free USF for polling at FN=2378493 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:119 - N3103 exceeded</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=116, fn=2379067</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=1 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 1 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2379156 block_nr=0 scheduling free USF for polling at FN=2379160 of UL TFI=1</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2379160 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=1: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 1 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2379221 block_nr=3 scheduling free USF for polling at FN=2379225 of UL TFI=1</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2379225 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=1 with TLLI=0xec8157f3.</p>
<p><0002> gprs_rlcmac_data.cpp:536 TBF T3169 timeout during transsmission</p>
<p><0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH</p>
<p><0002> gprs_rlcmac_data.cpp:86 - Uplink data was received</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=112, fn=2381154</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2381240 block_nr=1 scheduling free USF for polling at FN=2381244 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2381244 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2381301 block_nr=3 scheduling free USF for polling at FN=2381305 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2381305 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=115, fn=2385350</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2385435 block_nr=9 scheduling free USF for polling at FN=2385439 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2385439 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2385500 block_nr=0 scheduling free USF for polling at FN=2385504 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2385504 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p><0001> pcu_l1_if.cpp:256 RACH request received: sapi=1 qta=0, ra=116, fn=2393714</p>
<p><0002> gprs_rlcmac_data.cpp:1138 TX: Immediate Assignment Uplink (AGCH)</p>
<p><0002> gprs_rlcmac_data.cpp:1876 Got IMM.ASS confirm, but rest octets do not start with bit sequence 'HH01' (Packet Downlink Assignment)</p>
<p><0002> gprs_rlcmac.cpp:354 Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=10</p>
<p><0002> gprs_rlcmac.cpp:948 - Setting Control TS 7</p>
<p><0002> gprs_rlcmac_data.cpp:1069 TBF: START TFI: 0 TLLI: 0xec8157f3 Packet Uplink Assignment (PACCH)</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2393798 block_nr=7 scheduling free USF for polling at FN=2393802 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:288 PACKET CONTROL ACK with expected FN=2393802 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0005> gprs_rlcmac_data.cpp:740 Complete UL frame for TBF=0: len=62</p>
<p><0008> gprs_rlcmac.cpp:1760 LLC [PCU -> SGSN] TFI: 0 TLLI: 0xec8157f3 len=62</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2393863 block_nr=10 scheduling free USF for polling at FN=2393867 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:281 PACKET CONTROL ACK with unknown FN=2393863 TLL=0xec8157f3 (TRX 0 TS 7)</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:107 - Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK</p>
<p><0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH</p>
<p><0002> gprs_rlcmac_data.cpp:86 - Uplink data was received</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2393984 block_nr=2 scheduling free USF for polling at FN=2393989 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2394028 block_nr=0 scheduling free USF for polling at FN=2394032 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0</p>
<p><0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7 FN=2394075 block_nr=11 scheduling free USF for polling at FN=2394080 of UL TFI=0</p>
<p><0002> gprs_rlcmac_data.cpp:100 Poll timeout for UL TBF=0</p>
<p><0002> gprs_rlcmac_data.cpp:119 - N3103 exceeded</p>
<p><0002> gprs_rlcmac_data.cpp:536 TBF T3169 timeout during transsmission</p>
<p><0002> gprs_rlcmac_data.cpp:84 - Assignment was on PACCH</p>
<p><0002> gprs_rlcmac_data.cpp:86 - Uplink data was received</p>
<p><0002> gprs_rlcmac.cpp:895 Free UL TBF=0 with TLLI=0xec8157f3.</p>
<p>....</p></span></div>
<div class="gmail_quote">On Sat, Oct 27, 2012 at 7:15 AM, jolly <span dir="ltr"><<a href="mailto:andreas@eversberg.eu" target="_blank">andreas@eversberg.eu</a>></span> wrote:<br>
<blockquote style="BORDER-LEFT:#ccc 1px solid;MARGIN:0px 0px 0px 0.8ex;PADDING-LEFT:1ex" class="gmail_quote">Vladimir Rolbin wrote:<br>> <0002> gprs_rlcmac_data.cpp:1183 TX: START TFI: 0 Immediate Assignment<br>
> Uplink (AGCH)<br>> <0002> gprs_rlcmac_data.cpp:1895 Got IMM.ASS confirm, but rest octets<br>> do not start with bit sequence 'HH01' (Packet Downlink Assignment)<br>> <0006> gprs_rlcmac_sched.cpp:260 Received RTS for PDCH: TRX=0 TS=7<br>
> FN=168510 block_nr=7 scheduling free USF for polling at FN=168514 of<br>> DL TFI=1<br>> <0002> gprs_rlcmac_data.cpp:395 PACKET DOWNLINK ACK with unknown<br>> FN=168519 TFI=1 (TRX 0 TS 7)<br>> <0002> gprs_rlcmac_data.cpp:100 Poll timeout for DL TBF=1<br>
hi vladimir,<br><br>there seems to be several problems. i can clearly see the two above:<br><br>PCU sends immediate assignment message to BTS. it consists of three<br>bytes with the last three digits of the IMSI, plus the complete IMM.ASS<br>
message including pseudo length byte and padding. the assignment seems<br>ok, because the phone follows the assignment. the IMM.ASS confirm from<br>BTS must not include the three digits of IMSI, but the complete message.<br>
the confirm must be sent to PCU after the assignment is sent (or<br>sheduled) on PCH. this is required, because it may take seconds,<br>depending on paging group configuration.<br><br>the second problem is wrong scheduling. if you would have set drlcmac<br>
debugging, you would see when polling is scheduled. the scheduled FN<br>must be 13 bursts (3 blocks) in advance of the RTS FN. 8 or 9 bursts<br>later, the scheduler must schedule "free USF for polling" for the next<br>
block, which is 4 or 5 bursts later. since i don't see the drlcmac<br>debugging in your log, i cannot verify it.<br><br>regards,<br><br>andreas<br><br><br></blockquote></div><br></div>