tests/tbf/TbfTest.err

********** TBF starts here **********
Allocating DL TBF: TFI=0 TRX=0 MS_CLASS=0
Creating MS object, TLLI = 0x00000000
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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0x00002342, partly confirmed
Modifying MS object, TLLI = 0x00002342, TA 0 -> 4
********** 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
Attaching TBF to MS object, TLLI = 0x00002342, TBF = TBF(TFI=0 TLLI=0x00002342 DIR=UL STATE=NULL)
Modifying MS object, TLLI: 0x00000000 -> 0x00002342, already confirmed partly
The MS object cannot fully confirm an unexpected TLLI: 0x00004232, partly confirmed
Modifying MS object, TLLI: 0x00002342 -> 0x00004232, already confirmed partly
Modifying MS object, TLLI = 0x00004232, TA 4 -> 6
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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL)
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to FLOW
The MS object cannot fully confirm an unexpected TLLI: 0xffeeddcc, partly confirmed
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0xffeeddcc 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=0xffeeddcc 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==0)
- Dequeue next LLC for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) (len=200)
- Sending new block at BSN 0, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW)
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==1)
- Sending new block at BSN 1, CS=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=0xffeeddcc DIR=DL STATE=FLOW) downlink acknowledge
- Final ACK received.
TBF(TFI=0 TLLI=0xffeeddcc 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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL)
Detaching TBF from MS object, TLLI = 0x00000000, TBF = TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL)
Destroying MS object, TLLI = 0x00000000
Attaching TBF to MS object, TLLI = 0xffeeddcc, TBF = TBF(TFI=1 TLLI=0xffeeddcc DIR=DL STATE=NULL)
Detaching TBF from MS object, TLLI = 0xffeeddcc, TBF = TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=WAIT RELEASE)
********** 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=0xffeeddcc DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TBF(TFI=1 TLLI=0xffeeddcc 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 ends here **********
TBF(TFI=1 TLLI=0xffeeddcc DIR=DL STATE=ASSIGN) free
TBF(TFI=1 TLLI=0xffeeddcc DIR=DL STATE=ASSIGN) stopping timer 0.
Detaching TBF from MS object, TLLI = 0xffeeddcc, TBF = TBF(TFI=1 TLLI=0xffeeddcc DIR=DL STATE=ASSIGN)
********** TBF ends here **********
Destroying MS object, TLLI = 0xffeeddcc
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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL)
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to FLOW
The MS object cannot fully confirm an unexpected TLLI: 0xffeeddcc, partly confirmed
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0xffeeddcc 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=0xffeeddcc 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==0)
- Dequeue next LLC for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) (len=200)
- Sending new block at BSN 0, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW)
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==1)
- Sending new block at BSN 1, CS=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=0xffeeddcc DIR=DL STATE=FLOW) downlink acknowledge
- Final ACK received.
TBF(TFI=0 TLLI=0xffeeddcc 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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL)
Detaching TBF from MS object, TLLI = 0x00000000, TBF = TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL)
Destroying MS object, TLLI = 0x00000000
Attaching TBF to MS object, TLLI = 0xffeeddcc, TBF = TBF(TFI=1 TLLI=0xffeeddcc DIR=DL STATE=NULL)
Detaching TBF from MS object, TLLI = 0xffeeddcc, TBF = TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=WAIT RELEASE)
********** 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=0xffeeddcc DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TBF(TFI=1 TLLI=0xffeeddcc DIR=DL STATE=ASSIGN) starting timer 0.
TBF(TFI=1 TLLI=0xffeeddcc DIR=DL STATE=ASSIGN) free
TBF(TFI=1 TLLI=0xffeeddcc DIR=DL STATE=ASSIGN) stopping timer 0.
Detaching TBF from MS object, TLLI = 0xffeeddcc, TBF = TBF(TFI=1 TLLI=0xffeeddcc DIR=DL STATE=ASSIGN)
********** 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 **********
Destroying MS object, TLLI = 0xffeeddcc
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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL)
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to FLOW
The MS object cannot fully confirm an unexpected TLLI: 0xffeeddcc, partly confirmed
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) append
TBF(TFI=0 TLLI=0xffeeddcc 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=0xffeeddcc 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==0)
- Dequeue next LLC for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) (len=200)
- Sending new block at BSN 0, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW)
Scheduling data message at RTS for DL TFI=0 (TRX=0, TS=4) prio=3
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==1)
- Sending new block at BSN 1, CS=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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==2)
- Sending new block at BSN 2, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==3)
- Sending new block at BSN 3, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==4)
- Sending new block at BSN 4, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==5)
- Sending new block at BSN 5, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==6)
- Sending new block at BSN 6, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==7)
- Sending new block at BSN 7, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==8)
- Sending new block at BSN 8, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==9)
- Sending new block at BSN 9, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==10)
- Sending new block at BSN 10, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW)len=200
- Dequeue next LLC for TBF(TFI=0 TLLI=0xffeeddcc 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==11)
- Sending new block at BSN 11, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==12)
- Sending new block at BSN 12, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==13)
- Sending new block at BSN 13, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==14)
- Sending new block at BSN 14, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==15)
- Sending new block at BSN 15, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==16)
- Sending new block at BSN 16, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==17)
- Sending new block at BSN 17, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==18)
- Sending new block at BSN 18, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==19)
- Sending new block at BSN 19, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==0 .. V(S)==20)
- Sending new block at BSN 20, CS=1
-- 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=0xffeeddcc 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=0xffeeddcc 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=0xffeeddcc 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=0xffeeddcc 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==21 .. V(S)==21)
- Sending new block at BSN 21, CS=1
-- 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=0xffeeddcc 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=0xffeeddcc 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=0xffeeddcc 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=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==22 .. V(S)==22)
- Sending new block at BSN 22, CS=1
-- 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=0xffeeddcc DIR=DL STATE=FLOW)len=19
-- Final block, so we done.
TBF(TFI=0 TLLI=0xffeeddcc 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=0xffeeddcc 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=0xffeeddcc DIR=DL STATE=FINISHED) downlink acknowledge
- Final ACK received.
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FINISHED) changes state from FINISHED to WAIT RELEASE
- No new message, so we release.
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=WAIT RELEASE) starting timer 3193.
DL packet loss of IMSI= / TLLI=0xffeeddcc: 0%
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=WAIT RELEASE) free
TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=WAIT RELEASE) stopping timer 3193.
Detaching TBF from MS object, TLLI = 0xffeeddcc, TBF = TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=WAIT RELEASE)
Destroying MS object, TLLI = 0xffeeddcc
********** 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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL)
TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to FLOW
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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL)
TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL) changes state from NULL to FLOW
The MS object cannot fully confirm an unexpected TLLI: 0xf1000001, partly confirmed
The MS object cannot fully confirm an unexpected TLLI: 0xf1000002, partly confirmed
Modifying MS object, TLLI = 0xf1000001, IMSI '' -> '001001000000001'
Modifying MS object, TLLI = 0xf1000001, IMSI '001001000000001' -> '001001000000002'
TBF(TFI=1 TLLI=0xf1000002 DIR=DL STATE=FLOW) the IMSI '001001000000002' was already assigned to another MS object: TLLI = 0xf1000001, that IMSI will be removed
Modifying MS object, TLLI = 0xf1000001, IMSI '001001000000002' -> ''
Modifying MS object, TLLI = 0xf1000002, IMSI '' -> '001001000000002'
TBF(TFI=1 TLLI=0xf1000002 DIR=DL STATE=FLOW) free
TBF(TFI=1 TLLI=0xf1000002 DIR=DL STATE=FLOW) Software error: Pending downlink assignment. This may not happen, because the assignment message never gets transmitted. Please be sure not to free in this state. PLEASE FIX!
Detaching TBF from MS object, TLLI = 0xf1000002, TBF = TBF(TFI=1 TLLI=0xf1000002 DIR=DL STATE=FLOW)
Destroying MS object, TLLI = 0xf1000002
********** TBF ends here **********
TBF(TFI=0 TLLI=0xf1000001 DIR=DL STATE=FLOW) free
TBF(TFI=0 TLLI=0xf1000001 DIR=DL STATE=FLOW) Software error: Pending downlink assignment. This may not happen, because the assignment message never gets transmitted. Please be sure not to free in this state. PLEASE FIX!
Detaching TBF from MS object, TLLI = 0xf1000001, TBF = TBF(TFI=0 TLLI=0xf1000001 DIR=DL STATE=FLOW)
Destroying MS object, TLLI = 0xf1000001
********** 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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000000, partly confirmed
TBF(TFI=0 TLLI=0xc0000000 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000000, IMSI '' -> '001001000000000'
Send dowlink assignment for TBF(TFI=0 TLLI=0xc0000000 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000000)
TBF(TFI=0 TLLI=0xc0000000 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=0 TLLI=0xc0000000 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 30 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 08 00 23 2b 2b 2b 2b 
TBF(TFI=0 TLLI=0xc0000000 DIR=DL STATE=ASSIGN) append
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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=1 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000001, partly confirmed
TBF(TFI=1 TLLI=0xc0000001 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000001, IMSI '' -> '001001000000001'
Send dowlink assignment for TBF(TFI=1 TLLI=0xc0000001 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000001)
TBF(TFI=1 TLLI=0xc0000001 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=1 TLLI=0xc0000001 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 31 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 18 40 23 2b 2b 2b 2b 
TBF(TFI=1 TLLI=0xc0000001 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=2.
********** TBF starts here **********
Allocating DL TBF: TFI=2 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=2 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000002, partly confirmed
TBF(TFI=2 TLLI=0xc0000002 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000002, IMSI '' -> '001001000000002'
Send dowlink assignment for TBF(TFI=2 TLLI=0xc0000002 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000002)
TBF(TFI=2 TLLI=0xc0000002 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=2 TLLI=0xc0000002 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 32 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 28 80 23 2b 2b 2b 2b 
TBF(TFI=2 TLLI=0xc0000002 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=3.
********** TBF starts here **********
Allocating DL TBF: TFI=3 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=3 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000003, partly confirmed
TBF(TFI=3 TLLI=0xc0000003 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000003, IMSI '' -> '001001000000003'
Send dowlink assignment for TBF(TFI=3 TLLI=0xc0000003 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000003)
TBF(TFI=3 TLLI=0xc0000003 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=3 TLLI=0xc0000003 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 33 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 38 c0 23 2b 2b 2b 2b 
TBF(TFI=3 TLLI=0xc0000003 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=4.
********** TBF starts here **********
Allocating DL TBF: TFI=4 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=4 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000004, partly confirmed
TBF(TFI=4 TLLI=0xc0000004 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000004, IMSI '' -> '001001000000004'
Send dowlink assignment for TBF(TFI=4 TLLI=0xc0000004 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000004)
TBF(TFI=4 TLLI=0xc0000004 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=4 TLLI=0xc0000004 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 34 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 49 00 23 2b 2b 2b 2b 
TBF(TFI=4 TLLI=0xc0000004 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=5.
********** TBF starts here **********
Allocating DL TBF: TFI=5 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=5 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000005, partly confirmed
TBF(TFI=5 TLLI=0xc0000005 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000005, IMSI '' -> '001001000000005'
Send dowlink assignment for TBF(TFI=5 TLLI=0xc0000005 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000005)
TBF(TFI=5 TLLI=0xc0000005 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=5 TLLI=0xc0000005 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 35 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 59 40 23 2b 2b 2b 2b 
TBF(TFI=5 TLLI=0xc0000005 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=6.
********** TBF starts here **********
Allocating DL TBF: TFI=6 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=6 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000006, partly confirmed
TBF(TFI=6 TLLI=0xc0000006 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000006, IMSI '' -> '001001000000006'
Send dowlink assignment for TBF(TFI=6 TLLI=0xc0000006 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000006)
TBF(TFI=6 TLLI=0xc0000006 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=6 TLLI=0xc0000006 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 36 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 69 80 23 2b 2b 2b 2b 
TBF(TFI=6 TLLI=0xc0000006 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=7.
********** TBF starts here **********
Allocating DL TBF: TFI=7 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=7 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000007, partly confirmed
TBF(TFI=7 TLLI=0xc0000007 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000007, IMSI '' -> '001001000000007'
Send dowlink assignment for TBF(TFI=7 TLLI=0xc0000007 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000007)
TBF(TFI=7 TLLI=0xc0000007 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=7 TLLI=0xc0000007 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 37 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 79 c0 23 2b 2b 2b 2b 
TBF(TFI=7 TLLI=0xc0000007 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=8.
********** TBF starts here **********
Allocating DL TBF: TFI=8 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=8 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000008, partly confirmed
TBF(TFI=8 TLLI=0xc0000008 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000008, IMSI '' -> '001001000000008'
Send dowlink assignment for TBF(TFI=8 TLLI=0xc0000008 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000008)
TBF(TFI=8 TLLI=0xc0000008 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=8 TLLI=0xc0000008 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 38 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 8a 00 23 2b 2b 2b 2b 
TBF(TFI=8 TLLI=0xc0000008 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=9.
********** TBF starts here **********
Allocating DL TBF: TFI=9 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=9 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000009, partly confirmed
TBF(TFI=9 TLLI=0xc0000009 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000009, IMSI '' -> '001001000000009'
Send dowlink assignment for TBF(TFI=9 TLLI=0xc0000009 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000009)
TBF(TFI=9 TLLI=0xc0000009 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=9 TLLI=0xc0000009 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 30 39 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 9a 40 23 2b 2b 2b 2b 
TBF(TFI=9 TLLI=0xc0000009 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=10.
********** TBF starts here **********
Allocating DL TBF: TFI=10 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=10 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000000a, partly confirmed
TBF(TFI=10 TLLI=0xc000000a DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000000a, IMSI '' -> '001001000000010'
Send dowlink assignment for TBF(TFI=10 TLLI=0xc000000a DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000010)
TBF(TFI=10 TLLI=0xc000000a DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=10 TLLI=0xc000000a DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 30 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 aa 80 23 2b 2b 2b 2b 
TBF(TFI=10 TLLI=0xc000000a DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=11.
********** TBF starts here **********
Allocating DL TBF: TFI=11 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=11 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000000b, partly confirmed
TBF(TFI=11 TLLI=0xc000000b DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000000b, IMSI '' -> '001001000000011'
Send dowlink assignment for TBF(TFI=11 TLLI=0xc000000b DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000011)
TBF(TFI=11 TLLI=0xc000000b DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=11 TLLI=0xc000000b DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 31 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 ba c0 23 2b 2b 2b 2b 
TBF(TFI=11 TLLI=0xc000000b DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=12.
********** TBF starts here **********
Allocating DL TBF: TFI=12 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=12 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000000c, partly confirmed
TBF(TFI=12 TLLI=0xc000000c DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000000c, IMSI '' -> '001001000000012'
Send dowlink assignment for TBF(TFI=12 TLLI=0xc000000c DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000012)
TBF(TFI=12 TLLI=0xc000000c DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=12 TLLI=0xc000000c DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 32 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 cb 00 23 2b 2b 2b 2b 
TBF(TFI=12 TLLI=0xc000000c DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=13.
********** TBF starts here **********
Allocating DL TBF: TFI=13 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=13 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000000d, partly confirmed
TBF(TFI=13 TLLI=0xc000000d DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000000d, IMSI '' -> '001001000000013'
Send dowlink assignment for TBF(TFI=13 TLLI=0xc000000d DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000013)
TBF(TFI=13 TLLI=0xc000000d DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=13 TLLI=0xc000000d DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 33 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 db 40 23 2b 2b 2b 2b 
TBF(TFI=13 TLLI=0xc000000d DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=14.
********** TBF starts here **********
Allocating DL TBF: TFI=14 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=14 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000000e, partly confirmed
TBF(TFI=14 TLLI=0xc000000e DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000000e, IMSI '' -> '001001000000014'
Send dowlink assignment for TBF(TFI=14 TLLI=0xc000000e DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000014)
TBF(TFI=14 TLLI=0xc000000e DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=14 TLLI=0xc000000e DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 34 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 eb 80 23 2b 2b 2b 2b 
TBF(TFI=14 TLLI=0xc000000e DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=15.
********** TBF starts here **********
Allocating DL TBF: TFI=15 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=15 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000000f, partly confirmed
TBF(TFI=15 TLLI=0xc000000f DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000000f, IMSI '' -> '001001000000015'
Send dowlink assignment for TBF(TFI=15 TLLI=0xc000000f DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000015)
TBF(TFI=15 TLLI=0xc000000f DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=15 TLLI=0xc000000f DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 35 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 00 fb c0 23 2b 2b 2b 2b 
TBF(TFI=15 TLLI=0xc000000f DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=16.
********** TBF starts here **********
Allocating DL TBF: TFI=16 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=16 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000010, partly confirmed
TBF(TFI=16 TLLI=0xc0000010 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000010, IMSI '' -> '001001000000016'
Send dowlink assignment for TBF(TFI=16 TLLI=0xc0000010 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000016)
TBF(TFI=16 TLLI=0xc0000010 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=16 TLLI=0xc0000010 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 36 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 0c 00 23 2b 2b 2b 2b 
TBF(TFI=16 TLLI=0xc0000010 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=17.
********** TBF starts here **********
Allocating DL TBF: TFI=17 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=17 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000011, partly confirmed
TBF(TFI=17 TLLI=0xc0000011 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000011, IMSI '' -> '001001000000017'
Send dowlink assignment for TBF(TFI=17 TLLI=0xc0000011 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000017)
TBF(TFI=17 TLLI=0xc0000011 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=17 TLLI=0xc0000011 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 37 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 1c 40 23 2b 2b 2b 2b 
TBF(TFI=17 TLLI=0xc0000011 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=18.
********** TBF starts here **********
Allocating DL TBF: TFI=18 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=18 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000012, partly confirmed
TBF(TFI=18 TLLI=0xc0000012 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000012, IMSI '' -> '001001000000018'
Send dowlink assignment for TBF(TFI=18 TLLI=0xc0000012 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000018)
TBF(TFI=18 TLLI=0xc0000012 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=18 TLLI=0xc0000012 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 38 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 2c 80 23 2b 2b 2b 2b 
TBF(TFI=18 TLLI=0xc0000012 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=19.
********** TBF starts here **********
Allocating DL TBF: TFI=19 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=19 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000013, partly confirmed
TBF(TFI=19 TLLI=0xc0000013 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000013, IMSI '' -> '001001000000019'
Send dowlink assignment for TBF(TFI=19 TLLI=0xc0000013 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000019)
TBF(TFI=19 TLLI=0xc0000013 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=19 TLLI=0xc0000013 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 31 39 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 3c c0 23 2b 2b 2b 2b 
TBF(TFI=19 TLLI=0xc0000013 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=20.
********** TBF starts here **********
Allocating DL TBF: TFI=20 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=20 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000014, partly confirmed
TBF(TFI=20 TLLI=0xc0000014 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000014, IMSI '' -> '001001000000020'
Send dowlink assignment for TBF(TFI=20 TLLI=0xc0000014 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000020)
TBF(TFI=20 TLLI=0xc0000014 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=20 TLLI=0xc0000014 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 30 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 4d 00 23 2b 2b 2b 2b 
TBF(TFI=20 TLLI=0xc0000014 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=21.
********** TBF starts here **********
Allocating DL TBF: TFI=21 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=21 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000015, partly confirmed
TBF(TFI=21 TLLI=0xc0000015 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000015, IMSI '' -> '001001000000021'
Send dowlink assignment for TBF(TFI=21 TLLI=0xc0000015 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000021)
TBF(TFI=21 TLLI=0xc0000015 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=21 TLLI=0xc0000015 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 31 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 5d 40 23 2b 2b 2b 2b 
TBF(TFI=21 TLLI=0xc0000015 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=22.
********** TBF starts here **********
Allocating DL TBF: TFI=22 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=22 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000016, partly confirmed
TBF(TFI=22 TLLI=0xc0000016 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000016, IMSI '' -> '001001000000022'
Send dowlink assignment for TBF(TFI=22 TLLI=0xc0000016 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000022)
TBF(TFI=22 TLLI=0xc0000016 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=22 TLLI=0xc0000016 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 32 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 6d 80 23 2b 2b 2b 2b 
TBF(TFI=22 TLLI=0xc0000016 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=23.
********** TBF starts here **********
Allocating DL TBF: TFI=23 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=23 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000017, partly confirmed
TBF(TFI=23 TLLI=0xc0000017 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000017, IMSI '' -> '001001000000023'
Send dowlink assignment for TBF(TFI=23 TLLI=0xc0000017 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000023)
TBF(TFI=23 TLLI=0xc0000017 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=23 TLLI=0xc0000017 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 33 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 7d c0 23 2b 2b 2b 2b 
TBF(TFI=23 TLLI=0xc0000017 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=24.
********** TBF starts here **********
Allocating DL TBF: TFI=24 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=24 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000018, partly confirmed
TBF(TFI=24 TLLI=0xc0000018 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000018, IMSI '' -> '001001000000024'
Send dowlink assignment for TBF(TFI=24 TLLI=0xc0000018 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000024)
TBF(TFI=24 TLLI=0xc0000018 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=24 TLLI=0xc0000018 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 34 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 8e 00 23 2b 2b 2b 2b 
TBF(TFI=24 TLLI=0xc0000018 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=25.
********** TBF starts here **********
Allocating DL TBF: TFI=25 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=25 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0000019, partly confirmed
TBF(TFI=25 TLLI=0xc0000019 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0000019, IMSI '' -> '001001000000025'
Send dowlink assignment for TBF(TFI=25 TLLI=0xc0000019 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000025)
TBF(TFI=25 TLLI=0xc0000019 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=25 TLLI=0xc0000019 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 35 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 9e 40 23 2b 2b 2b 2b 
TBF(TFI=25 TLLI=0xc0000019 DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=26.
********** TBF starts here **********
Allocating DL TBF: TFI=26 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=26 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000001a, partly confirmed
TBF(TFI=26 TLLI=0xc000001a DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000001a, IMSI '' -> '001001000000026'
Send dowlink assignment for TBF(TFI=26 TLLI=0xc000001a DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000026)
TBF(TFI=26 TLLI=0xc000001a DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=26 TLLI=0xc000001a DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 36 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 ae 80 23 2b 2b 2b 2b 
TBF(TFI=26 TLLI=0xc000001a DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=27.
********** TBF starts here **********
Allocating DL TBF: TFI=27 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=27 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000001b, partly confirmed
TBF(TFI=27 TLLI=0xc000001b DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000001b, IMSI '' -> '001001000000027'
Send dowlink assignment for TBF(TFI=27 TLLI=0xc000001b DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000027)
TBF(TFI=27 TLLI=0xc000001b DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=27 TLLI=0xc000001b DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 37 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 be c0 23 2b 2b 2b 2b 
TBF(TFI=27 TLLI=0xc000001b DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=28.
********** TBF starts here **********
Allocating DL TBF: TFI=28 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=28 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000001c, partly confirmed
TBF(TFI=28 TLLI=0xc000001c DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000001c, IMSI '' -> '001001000000028'
Send dowlink assignment for TBF(TFI=28 TLLI=0xc000001c DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000028)
TBF(TFI=28 TLLI=0xc000001c DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=28 TLLI=0xc000001c DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 38 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 cf 00 23 2b 2b 2b 2b 
TBF(TFI=28 TLLI=0xc000001c DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=29.
********** TBF starts here **********
Allocating DL TBF: TFI=29 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=29 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000001d, partly confirmed
TBF(TFI=29 TLLI=0xc000001d DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000001d, IMSI '' -> '001001000000029'
Send dowlink assignment for TBF(TFI=29 TLLI=0xc000001d DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000029)
TBF(TFI=29 TLLI=0xc000001d DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=29 TLLI=0xc000001d DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 32 39 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 df 40 23 2b 2b 2b 2b 
TBF(TFI=29 TLLI=0xc000001d DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=30.
********** TBF starts here **********
Allocating DL TBF: TFI=30 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=30 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000001e, partly confirmed
TBF(TFI=30 TLLI=0xc000001e DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000001e, IMSI '' -> '001001000000030'
Send dowlink assignment for TBF(TFI=30 TLLI=0xc000001e DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000030)
TBF(TFI=30 TLLI=0xc000001e DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=30 TLLI=0xc000001e DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 33 30 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 ef 80 23 2b 2b 2b 2b 
TBF(TFI=30 TLLI=0xc000001e DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
 Found TFI=31.
********** TBF starts here **********
Allocating DL TBF: TFI=31 TRX=0 MS_CLASS=45
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=31 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc000001f, partly confirmed
TBF(TFI=31 TLLI=0xc000001f DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc000001f, IMSI '' -> '001001000000031'
Send dowlink assignment for TBF(TFI=31 TLLI=0xc000001f DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000000031)
TBF(TFI=31 TLLI=0xc000001f DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=31 TLLI=0xc000001f DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=30 33 31 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 00 00 01 ff c0 23 2b 2b 2b 2b 
TBF(TFI=31 TLLI=0xc000001f DIR=DL STATE=ASSIGN) append
Searching for first unallocated TFI: TRX=0 first TS=4
No TFI available.
No PDCH resource
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
Creating MS object, TLLI = 0x00000000
Modifying MS object, TLLI = 0x00000000, MS class 0 -> 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
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=0 TLLI=0x00000000 DIR=DL STATE=NULL)
The MS object cannot fully confirm an unexpected TLLI: 0xc0123456, partly confirmed
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=NULL) [DOWNLINK] START
Modifying MS object, TLLI = 0xc0123456, IMSI '' -> '001001000123456'
Send dowlink assignment for TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000123456)
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=34 35 36 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 01 23 45 68 00 23 2b 2b 2b 2b 
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) append
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) append
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) free
Detaching TBF from MS object, TLLI = 0xc0123456, TBF = TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN)
********** 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
Attaching TBF to MS object, TLLI = 0xc0123456, TBF = TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=NULL)
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=NULL) [DOWNLINK] START
Send dowlink assignment for TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=NULL) on PCH, no TBF exist (IMSI=001001000123456)
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=NULL) changes state from NULL to ASSIGN
TX: START TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) Immediate Assignment Downlink (PCH)
Sending data request: trx=0 ts=0 sapi=3 arfcn=0 fn=0 block=0 data=34 35 36 2d 06 3f 30 0c 00 00 7d 80 00 00 00 dc 01 23 45 68 00 23 2b 2b 2b 2b 
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) append
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) downlink (V(A)==0 .. V(S)==0)
- Dequeue next LLC for TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) (len=19)
- Sending new block at BSN 0, CS=1
-- 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=0xc0123456 DIR=DL STATE=ASSIGN)len=19
- Dequeue next LLC for TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) (len=19)
-- No space left, so we are done.
data block: 07 00 00 4d 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 
MSG = 07 00 00 4d 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 01 
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) downlink (V(A)==0 .. V(S)==1)
- Sending new block at BSN 1, CS=1
-- 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=0xc0123456 DIR=DL STATE=ASSIGN)len=19
- Dequeue next LLC for TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) (len=19)
-- No space left, so we are done.
data block: 07 00 02 4d 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 
MSG = 07 00 02 4d 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 02 
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) downlink (V(A)==0 .. V(S)==2)
- Sending new block at BSN 2, CS=1
-- 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=0xc0123456 DIR=DL STATE=ASSIGN)len=19
-- Final block, so we done.
TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) changes state from ASSIGN to FINISHED
data block: 07 01 04 4d 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 
- Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
Polling cannot be sheduled in this TS 7, waiting for TS 4
MSG = 07 01 04 4d 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 
Searching for first unallocated TFI: TRX=0 first TS=7
 Found TFI=0.
MS requests UL TBF on RACH, so we provide one:
Searching for first unallocated TFI: TRX=0 first TS=7
 Found TFI=0.
********** TBF starts here **********
Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0
Creating MS object, TLLI = 0x00000000
Slot Allocation (Algorithm A) for class 0
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Skipping TS 2, because not enabled
- Skipping TS 3, because not enabled
- Skipping TS 4, because not enabled
- Skipping TS 5, because not enabled
- Skipping TS 6, because not enabled
- Assign uplink TS=7 USF=0
- Setting Control TS 7
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=NULL)
Modifying MS object, TLLI = 0x00000000, TA 0 -> 7
TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=NULL) changes state from NULL to FLOW
TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=FLOW) starting timer 3169.
TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=FLOW) [UPLINK] START
TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=FLOW) RX: [PCU <- BTS] RACH qbit-ta=31 ra=0x03, Fn=2654167 (17,25,9)
TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=FLOW) TX: START Immediate Assignment Uplink (AGCH)
Sending data request: trx=0 ts=0 sapi=2 arfcn=0 fn=0 block=0 data=2d 06 3f 10 0f 00 00 03 8b 29 07 00 c8 00 10 0b 2b 2b 2b 2b 2b 2b 2b 
Got 'TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=FLOW)', TA=7
UL DATA TFI=0 received (V(Q)=0 .. V(R)=0)
Modifying MS object, UL TLLI: 0x00000000 -> 0xf1223344, not yet confirmed
Decoded premier TLLI=0xf1223344 of UL DATA TFI=0.
TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) restarting timer 3169 while old timer 3169 pending 
- BSN 0 storing in window (0..63)
- Raising V(R) to 1
- Taking block 0 out, raising V(Q) to 1
- Assembling frames: (len=23)
-- Frame 1 starts at offset 0
- Data length after length fields: 20
- Length after skipping TLLI: 16
TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) complete UL frame that fits precisely in last block: len=16
LLC [PCU -> SGSN] TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) len=16
No bctx
- No gaps in received block, last block: BSN=0 CV=0
- Finished with UL TBF
TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) changes state from FLOW to FINISHED
- Scheduling Ack/Nack, because TLLI is included.
- Scheduling Ack/Nack, because last block has CV==0.
Got MS: TLLI = 0xf1223344, TA = 7
Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654218 block=8 data=47 94 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
MS requests UL TBF on RACH, so we provide one:
MS requests single block allocation
RX: [PCU <- BTS] RACH qbit-ta=31 ra=0x73, Fn=2654167 (17,25,9), SBFn=2654270
TX: Immediate Assignment Uplink (AGCH)
Sending data request: trx=0 ts=0 sapi=2 arfcn=0 fn=0 block=0 data=2d 06 3f 10 0f 00 00 73 8b 29 07 00 c0 0c 5a 43 2b 2b 2b 2b 2b 2b 2b 
Searching for first unallocated TFI: TRX=0 first TS=7
 Found TFI=0.
+++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++
------------------------- RX : Uplink Control Block -------------------------
MS requests UL TBF in packet resource request of single block, so we provide one:
MS does not give us a class.
Searching for first unallocated TFI: TRX=0 first TS=7
 Found TFI=0.
********** TBF starts here **********
Allocating UL TBF: TFI=0 TRX=0 MS_CLASS=0
Creating MS object, TLLI = 0x00000000
Slot Allocation (Algorithm A) for class 0
- Skipping TS 0, because not enabled
- Skipping TS 1, because not enabled
- Skipping TS 2, because not enabled
- Skipping TS 3, because not enabled
- Skipping TS 4, because not enabled
- Skipping TS 5, because not enabled
- Skipping TS 6, because not enabled
- Assign uplink TS=7 USF=0
- Setting Control TS 7
Attaching TBF to MS object, TLLI = 0x00000000, TBF = TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=NULL)
TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=NULL) changes state from NULL to ASSIGN
TBF(TFI=0 TLLI=0x00000000 DIR=UL STATE=ASSIGN) starting timer 3169.
Modifying MS object, UL TLLI: 0x00000000 -> 0xf1223344, not yet confirmed
Modifying MS object, TLLI = 0xf1223344, TA 0 -> 7
Change control TS to 7 until assinment is complete.
Got 'TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN)', TA=7, CS=4
TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN)s start Packet Uplink Assignment (PACCH)
+++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++
------------------------- TX : Packet Uplink Assignment -------------------------
Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) (TRX=0, TS=7)
Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654275 block=21 data=4f 28 5e 24 46 68 8f 1d 00 00 88 00 08 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
UL DATA TFI=0 received (V(Q)=0 .. V(R)=0)
TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) restarting timer 3169 while old timer 3169 pending 
- BSN 0 storing in window (0..63)
- Raising V(R) to 1
- Taking block 0 out, raising V(Q) to 1
- Assembling frames: (len=23)
-- Frame 1 starts at offset 0
- Data length after length fields: 20
TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) complete UL frame that fits precisely in last block: len=20
LLC [PCU -> SGSN] TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) len=20
No bctx
Got MS: TLLI = 0xf1223344, TA = 7