tests/tbf/TbfTest.err

********** TBF starts here **********
Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=0
Slot Allocation (Algorithm A) for class 0
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Assign downlink TS=2
- Setting Control TS 2
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL) changing tlli from TLLI=0x00000000 TLLI=0x00002342 ul_changed=0
********** TBF starts here **********
Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0
Slot Allocation (Algorithm A) for class 0
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Assign uplink TS=2 USF=0
- Setting Control TS 2
TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=NULL) changing tlli from TLLI=0x00000000 TLLI=0x00002342 ul_changed=0
TBF(TFI=0 TLLI=0x00002342 DIR=DL STATE=NULL) changing tlli from TLLI=0x00002342 TLLI=0x00004232 ul_changed=1
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=0.
********** TBF starts here **********
Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=45
Slot Allocation (Algorithm A) for class 45
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Skipping TS 2, because not enabled
- Skipping TS 3, because not enabled
- Assign downlink TS=4
- Setting Control TS 4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to FLOW
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)  start Packet Downlink Assignment (PACCH)
+++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++
------------------------- TX : Packet Downlink Assignment -------------------------
Scheduling control message at RTS for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) (TRX=0, TS=4)
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=0 block=0 data=4f 08 20 00 44 02 00 02 08 04 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==0)
- Sending new block at BSN 0
-- Chunk with length 200 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 01 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10 11 12 13 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=4 block=1 data=07 00 01 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10 11 12 13 
Received RTS for PDCH: TRX=0 TS=4 FN=8 block_nr=2 scheduling free USF for polling at FN=13 of TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==1)
- Sending new block at BSN 1
-- Chunk with length 180 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 03 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23 24 25 26 27 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=8 block=2 data=07 00 03 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23 24 25 26 27 
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink acknowledge
- Final ACK received.
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) changes state from FLOW to WAIT RELEASE
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=1.
********** TBF starts here **********
Allocating DL TBF: TFI=1 TRX=0 MS_CLASS=45
Slot Allocation (Algorithm A) for class 45
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Skipping TS 2, because not enabled
- Skipping TS 3, because not enabled
- Assign downlink TS=4
- Setting Control TS 4
********** TBF update **********
Slot Allocation (Algorithm A) for class 45
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Skipping TS 2, because not enabled
- Skipping TS 3, because not enabled
- Assign downlink TS=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) Trigger dowlink assignment on PACCH, because another LLC PDU has arrived in between
Send dowlink assignment on PACCH, because TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) exists
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) starting timer 0.
DL packet loss of IMSI= / TLLI=0x00000000: 0%
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) free
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) New TBF TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) still exists, detaching
********** TBF ends here **********
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) free
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) stopping timer 0.
********** TBF ends here **********
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=0.
********** TBF starts here **********
Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=45
Slot Allocation (Algorithm A) for class 45
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Skipping TS 2, because not enabled
- Skipping TS 3, because not enabled
- Assign downlink TS=4
- Setting Control TS 4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to FLOW
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)  start Packet Downlink Assignment (PACCH)
+++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++
------------------------- TX : Packet Downlink Assignment -------------------------
Scheduling control message at RTS for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) (TRX=0, TS=4)
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=0 block=0 data=4f 08 20 00 44 02 00 02 08 04 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==0)
- Sending new block at BSN 0
-- Chunk with length 200 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 01 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10 11 12 13 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=4 block=1 data=07 00 01 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10 11 12 13 
Received RTS for PDCH: TRX=0 TS=4 FN=8 block_nr=2 scheduling free USF for polling at FN=13 of TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==1)
- Sending new block at BSN 1
-- Chunk with length 180 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 03 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23 24 25 26 27 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=8 block=2 data=07 00 03 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23 24 25 26 27 
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink acknowledge
- Final ACK received.
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) changes state from FLOW to WAIT RELEASE
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=1.
********** TBF starts here **********
Allocating DL TBF: TFI=1 TRX=0 MS_CLASS=45
Slot Allocation (Algorithm A) for class 45
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Skipping TS 2, because not enabled
- Skipping TS 3, because not enabled
- Assign downlink TS=4
- Setting Control TS 4
********** TBF update **********
Slot Allocation (Algorithm A) for class 45
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Skipping TS 2, because not enabled
- Skipping TS 3, because not enabled
- Assign downlink TS=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) Trigger dowlink assignment on PACCH, because another LLC PDU has arrived in between
Send dowlink assignment on PACCH, because TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) exists
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) starting timer 0.
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) free
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) stopping timer 0.
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=ASSIGN) Old TBF TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) still exists, detaching
********** TBF ends here **********
DL packet loss of IMSI= / TLLI=0x00000000: 0%
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) free
********** TBF ends here **********
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=0.
********** TBF starts here **********
Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=45
Slot Allocation (Algorithm A) for class 45
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Skipping TS 2, because not enabled
- Skipping TS 3, because not enabled
- Assign downlink TS=4
- Setting Control TS 4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to FLOW
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)  start Packet Downlink Assignment (PACCH)
+++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++
------------------------- TX : Packet Downlink Assignment -------------------------
Scheduling control message at RTS for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) (TRX=0, TS=4)
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=0 block=0 data=4f 08 20 00 44 02 00 02 08 04 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==0)
- Sending new block at BSN 0
-- Chunk with length 200 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 01 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10 11 12 13 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=4 block=1 data=07 00 01 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10 11 12 13 
Received RTS for PDCH: TRX=0 TS=4 FN=8 block_nr=2 scheduling free USF for polling at FN=13 of TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==1)
- Sending new block at BSN 1
-- Chunk with length 180 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 03 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23 24 25 26 27 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=8 block=2 data=07 00 03 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23 24 25 26 27 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==2)
- Sending new block at BSN 2
-- Chunk with length 160 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 05 28 29 2a 2b 2c 2d 2e 2f 30 31 32 33 34 35 36 37 38 39 3a 3b 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=13 block=3 data=07 00 05 28 29 2a 2b 2c 2d 2e 2f 30 31 32 33 34 35 36 37 38 39 3a 3b 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==3)
- Sending new block at BSN 3
-- Chunk with length 140 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 07 3c 3d 3e 3f 40 41 42 43 44 45 46 47 48 49 4a 4b 4c 4d 4e 4f 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=17 block=4 data=07 00 07 3c 3d 3e 3f 40 41 42 43 44 45 46 47 48 49 4a 4b 4c 4d 4e 4f 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==4)
- Sending new block at BSN 4
-- Chunk with length 120 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 09 50 51 52 53 54 55 56 57 58 59 5a 5b 5c 5d 5e 5f 60 61 62 63 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=21 block=5 data=07 00 09 50 51 52 53 54 55 56 57 58 59 5a 5b 5c 5d 5e 5f 60 61 62 63 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==5)
- Sending new block at BSN 5
-- Chunk with length 100 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 0b 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f 70 71 72 73 74 75 76 77 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=26 block=6 data=07 00 0b 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f 70 71 72 73 74 75 76 77 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==6)
- Sending new block at BSN 6
-- Chunk with length 80 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 0d 78 79 7a 7b 7c 7d 7e 7f 80 81 82 83 84 85 86 87 88 89 8a 8b 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=30 block=7 data=07 00 0d 78 79 7a 7b 7c 7d 7e 7f 80 81 82 83 84 85 86 87 88 89 8a 8b 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==7)
- Sending new block at BSN 7
-- Chunk with length 60 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 0f 8c 8d 8e 8f 90 91 92 93 94 95 96 97 98 99 9a 9b 9c 9d 9e 9f 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=34 block=8 data=07 00 0f 8c 8d 8e 8f 90 91 92 93 94 95 96 97 98 99 9a 9b 9c 9d 9e 9f 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==8)
- Sending new block at BSN 8
-- Chunk with length 40 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 11 a0 a1 a2 a3 a4 a5 a6 a7 a8 a9 aa ab ac ad ae af b0 b1 b2 b3 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=39 block=9 data=07 00 11 a0 a1 a2 a3 a4 a5 a6 a7 a8 a9 aa ab ac ad ae af b0 b1 b2 b3 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==9)
- Sending new block at BSN 9
-- Chunk with length 20 would exactly fit into space (20): add length header with LI=0, to make frame extend to next block, and we are done
data block: 07 00 12 01 b4 b5 b6 b7 b8 b9 ba bb bc bd be bf c0 c1 c2 c3 c4 c5 c6 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=43 block=10 data=07 00 12 01 b4 b5 b6 b7 b8 b9 ba bb bc bd be bf c0 c1 c2 c3 c4 c5 c6 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==10)
- Sending new block at BSN 10
-- Chunk with length 1 is less than remaining space (20): add length header to to delimit LLC frame
Complete DL frame for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)len=200
- Dequeue next LLC for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) (len=200)
-- Chunk with length 200 larger than space (18) left in block: copy only remaining space, and we are done
data block: 07 00 14 07 c7 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10 11 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=47 block=11 data=07 00 14 07 c7 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f 10 11 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==11)
- Sending new block at BSN 11
-- Chunk with length 182 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 17 12 13 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23 24 25 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=52 block=12 data=07 00 17 12 13 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23 24 25 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==12)
- Sending new block at BSN 12
-- Chunk with length 162 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 19 26 27 28 29 2a 2b 2c 2d 2e 2f 30 31 32 33 34 35 36 37 38 39 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=56 block=13 data=07 00 19 26 27 28 29 2a 2b 2c 2d 2e 2f 30 31 32 33 34 35 36 37 38 39 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==13)
- Sending new block at BSN 13
-- Chunk with length 142 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 1b 3a 3b 3c 3d 3e 3f 40 41 42 43 44 45 46 47 48 49 4a 4b 4c 4d 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=60 block=14 data=07 00 1b 3a 3b 3c 3d 3e 3f 40 41 42 43 44 45 46 47 48 49 4a 4b 4c 4d 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==14)
- Sending new block at BSN 14
-- Chunk with length 122 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 1d 4e 4f 50 51 52 53 54 55 56 57 58 59 5a 5b 5c 5d 5e 5f 60 61 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=65 block=15 data=07 00 1d 4e 4f 50 51 52 53 54 55 56 57 58 59 5a 5b 5c 5d 5e 5f 60 61 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==15)
- Sending new block at BSN 15
-- Chunk with length 102 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 1f 62 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f 70 71 72 73 74 75 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=69 block=16 data=07 00 1f 62 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f 70 71 72 73 74 75 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==16)
- Sending new block at BSN 16
-- Chunk with length 82 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 21 76 77 78 79 7a 7b 7c 7d 7e 7f 80 81 82 83 84 85 86 87 88 89 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=73 block=17 data=07 00 21 76 77 78 79 7a 7b 7c 7d 7e 7f 80 81 82 83 84 85 86 87 88 89 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==17)
- Sending new block at BSN 17
-- Chunk with length 62 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 23 8a 8b 8c 8d 8e 8f 90 91 92 93 94 95 96 97 98 99 9a 9b 9c 9d 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=78 block=18 data=07 00 23 8a 8b 8c 8d 8e 8f 90 91 92 93 94 95 96 97 98 99 9a 9b 9c 9d 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==18)
- Sending new block at BSN 18
-- Chunk with length 42 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 25 9e 9f a0 a1 a2 a3 a4 a5 a6 a7 a8 a9 aa ab ac ad ae af b0 b1 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=82 block=19 data=07 00 25 9e 9f a0 a1 a2 a3 a4 a5 a6 a7 a8 a9 aa ab ac ad ae af b0 b1 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==19)
- Sending new block at BSN 19
-- Chunk with length 22 larger than space (20) left in block: copy only remaining space, and we are done
data block: 07 00 27 b2 b3 b4 b5 b6 b7 b8 b9 ba bb bc bd be bf c0 c1 c2 c3 c4 c5 
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=86 block=20 data=07 00 27 b2 b3 b4 b5 b6 b7 b8 b9 ba bb bc bd be bf c0 c1 c2 c3 c4 c5 
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==20)
- Sending new block at BSN 20
-- Chunk with length 2 is less than remaining space (20): add length header to to delimit LLC frame
Complete DL frame for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)len=200
-- Empty chunk, added LLC dummy command of size 16, drained_since=0
-- Chunk with length 16 is less than remaining space (17): add length header to to delimit LLC frame
Complete DL frame for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)len=16
-- No space left, so we are done.
data block: 07 00 28 0a 41 c6 c7 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
- Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
Polling is already sheduled for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW), so we must wait for requesting downlink ack
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=91 block=21 data=07 00 28 0a 41 c6 c7 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink acknowledge
- ack:  (BSN=85)"RRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRR"(BSN=20)  R=ACK I=NACK
- got ack for BSN=20
- got ack for BSN=19
- got ack for BSN=18
- got ack for BSN=17
- got ack for BSN=16
- got ack for BSN=15
- got ack for BSN=14
- got ack for BSN=13
- got ack for BSN=12
- got ack for BSN=11
- got ack for BSN=10
- got ack for BSN=9
- got ack for BSN=8
- got ack for BSN=7
- got ack for BSN=6
- got ack for BSN=5
- got ack for BSN=4
- got ack for BSN=3
- got ack for BSN=2
- got ack for BSN=1
- got ack for BSN=0
- V(B): (V(A)=21)""(V(S)-1=20)  A=Acked N=Nacked U=Unacked X=Resend-Unacked I=Invalid
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==21 .. V(S)==21)
- Sending new block at BSN 21
-- Empty chunk, added LLC dummy command of size 19, drained_since=4
-- Chunk with length 19 is less than remaining space (20): add length header to to delimit LLC frame
Complete DL frame for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)len=19
-- No space left, so we are done.
data block: 07 00 2a 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
- Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
Polling is already sheduled for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW), so we must wait for requesting downlink ack
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=95 block=22 data=07 00 2a 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink acknowledge
- ack:  (BSN=86)"RRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRR"(BSN=21)  R=ACK I=NACK
- got ack for BSN=21
- V(B): (V(A)=22)""(V(S)-1=21)  A=Acked N=Nacked U=Unacked X=Resend-Unacked I=Invalid
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=4
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) downlink (V(A)==22 .. V(S)==22)
- Sending new block at BSN 22
-- Empty chunk, added LLC dummy command of size 19, drained_since=112
-- Chunk with length 19 is less than remaining space (20): add length header to to delimit LLC frame
Complete DL frame for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW)len=19
-- Final block, so we done.
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FLOW) changes state from FLOW to FINISHED
data block: 07 01 2c 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
- Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
Polling is already sheduled for TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FINISHED), so we must wait for requesting downlink ack
Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=203 block=23 data=07 01 2c 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FINISHED) downlink acknowledge
- Final ACK received.
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=FINISHED) changes state from FINISHED to WAIT RELEASE
- No new message, so we release.
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) starting timer 3193.
DL packet loss of IMSI= / TLLI=0x00000000: 0%
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) free
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=WAIT RELEASE) stopping timer 3193.
********** TBF ends here **********