pdch: Log TS enable/disable transitions

Change-Id: I6780634de4791382ccd25bf7b74f5286420e2c52
This commit is contained in:
Pau Espin 2021-11-09 12:22:48 +01:00
parent 20dfa54508
commit 304b10a8b5
4 changed files with 48 additions and 0 deletions

View File

@ -143,6 +143,7 @@ void pdch_init(struct gprs_rlcmac_pdch *pdch, struct gprs_rlcmac_trx *trx, uint8
void gprs_rlcmac_pdch::enable()
{
LOGPDCH(this, DRLCMAC, LOGL_INFO, "PDCH state: %s => enabled\n", m_is_enabled ? "enabled" : "disabled");
OSMO_ASSERT(m_is_enabled == 0);
INIT_LLIST_HEAD(&paging_list);
@ -155,6 +156,7 @@ void gprs_rlcmac_pdch::enable()
void gprs_rlcmac_pdch::disable()
{
LOGPDCH(this, DRLCMAC, LOGL_INFO, "PDCH state: %s => disabled\n", m_is_enabled ? "enabled" : "disabled");
OSMO_ASSERT(m_is_enabled == 1);
this->free_resources();

View File

@ -10,6 +10,10 @@ Application Information Request received: type=0x00000000 len=0
Packet Application Information will not be sent, no subscribers with active TBF
--- prepare_bts_with_two_dl_tbf_subscr ---
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=5) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=6) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 10
Modifying MS object, TLLI = 0xffffffff, EGPRS MS class 0 -> 11

View File

@ -1,6 +1,8 @@
=== start test_tbf_base ===
=== end test_tbf_base ===
=== start test_tbf_tlli_update ===
PDCH(bts=0,trx=0,ts=2) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=3) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
MS(TLLI=0xffffffff, IMSI=, TA=220, 0/0,) ********** DL-TBF starts here **********
MS(TLLI=0xffffffff, IMSI=, TA=220, 0/0,) Allocating DL TBF
@ -47,6 +49,7 @@ Modifying MS object, TLLI: 0x00002342 -> 0x00004232, already confirmed partly
Modifying MS object, TLLI = 0x00004232, TA 4 -> 6
=== end test_tbf_tlli_update ===
=== start test_tbf_final_ack ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 45
Found first unallocated TRX=0 TFI=0
@ -160,6 +163,7 @@ DL_ASS_TBF(DL-TFI_1){NONE}: Deallocated
MS(TLLI=0xffeeddcc, IMSI=, TA=0, 45/0,) Destroying MS object
=== end test_tbf_final_ack ===
=== start test_tbf_final_ack ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 45
Found first unallocated TRX=0 TFI=0
@ -273,6 +277,7 @@ DL_ASS_TBF(DL-TFI_0){WAIT_ACK}: Deallocated
MS(TLLI=0xffeeddcc, IMSI=, TA=0, 45/0,) Destroying MS object
=== end test_tbf_final_ack ===
=== start test_tbf_delayed_release ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 45
Found first unallocated TRX=0 TFI=0
@ -541,6 +546,7 @@ UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
DL_ASS_TBF(DL-TFI_0){WAIT_ACK}: Deallocated
=== end test_tbf_delayed_release ===
=== start test_tbf_imsi ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 45
Found first unallocated TRX=0 TFI=0
@ -630,6 +636,7 @@ UL_ASS_TBF(DL-TFI_1){NONE}: Deallocated
DL_ASS_TBF(DL-TFI_1){SEND_ASS}: Deallocated
=== end test_tbf_imsi ===
=== start test_tbf_exhaustion ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 45
Modifying MS object, TLLI = 0xffffffff, IMSI '' -> '001001000000000'
@ -1609,6 +1616,7 @@ MS(TLLI=0xc0000020, IMSI=001001000000032, TA=220, 45/0,) No PDCH resource
=== end test_tbf_exhaustion ===
MS(TLLI=0xc0000020, IMSI=001001000000032, TA=220, 45/0,) Destroying MS object
=== start test_tbf_dl_llc_loss ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 45
Modifying MS object, TLLI = 0xffffffff, IMSI '' -> '001001000123456'
@ -1717,6 +1725,7 @@ TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=FINISHED) msg block (BSN 2, CS-1): 07 01
MSG = 07 01 04 4d 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03
=== end test_tbf_dl_llc_loss ===
=== start test_tbf_single_phase ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
Found first unallocated TRX=0 TFI=0
MS requests Uplink resource on CCCH/RACH: ra=0x03 (8 bit) Fn=2654167 qta=31
MS requests single TS uplink transmission (one phase packet access)
@ -1800,6 +1809,7 @@ TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) TX: START Immediate Assignment Do
TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) appending 4 bytes
=== end test_tbf_single_phase ===
=== start test_tbf_two_phase ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -1899,6 +1909,7 @@ TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) Starting timer X2001 [assignment
TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) appending 4 bytes
=== end test_tbf_two_phase ===
=== start test_tbf_ra_update_rach ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -2163,6 +2174,7 @@ TBF(TFI=0 TLLI=0xf5667788 DIR=DL STATE=FINISHED) appending 4 bytes
New MS: TLLI = 0xf5667788, TA = 7, IMSI = 0011223344, LLC = 1
=== end test_tbf_ra_update_rach ===
=== start test_tbf_dl_flow_and_rach_two_phase ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -2336,6 +2348,7 @@ TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) No gaps in received block, last blo
New MS: TLLI = 0xf1223344, TA = 7, IMSI = 0011223344, LLC = 2
=== end test_tbf_dl_flow_and_rach_two_phase ===
=== start test_tbf_dl_flow_and_rach_single_phase ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -2508,6 +2521,7 @@ UL_ACK_TBF(UL-TFI_0){NONE}: state_chg to SCHED_UL_ACK
New MS: TLLI = 0xf1223344, TA = 7, IMSI = 0011223344, LLC = 2
=== end test_tbf_dl_flow_and_rach_single_phase ===
=== start test_tbf_dl_reuse ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -3563,6 +3577,7 @@ TBF(TFI=1 TLLI=0xf1223344 DIR=DL STATE=FINISHED) Scheduled Ack/Nack polling on F
TBF(TFI=1 TLLI=0xf1223344 DIR=DL STATE=FINISHED) msg block (BSN 10, CS-1): 0f 03 14 4d 43 20 50 41 43 4b 45 54 20 30 39 20 28 54 42 46 20 32 29
=== end test_tbf_dl_reuse ===
=== start test_tbf_gprs_egprs ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 45
Modifying MS object, TLLI = 0xffffffff, IMSI '' -> '001001123456789'
@ -3595,6 +3610,10 @@ TBF(TFI=0 TLLI=0xc0006789 DIR=DL STATE=ASSIGN) TX: START Immediate Assignment Do
TBF(TFI=0 TLLI=0xc0006789 DIR=DL STATE=ASSIGN) appending 256 bytes
=== end test_tbf_gprs_egprs ===
=== start test_tbf_ws ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=2) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=3) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=5) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 12
MS(TLLI=0xffffffff, IMSI=, TA=220, 12/0,) ********** DL-TBF starts here **********
@ -3685,6 +3704,7 @@ UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
DL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
=== end test_tbf_ws ===
=== start test_tbf_egprs_two_phase ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -3792,6 +3812,7 @@ TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN EGPRS) Starting timer X2001 [assig
TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN EGPRS) appending 256 bytes
=== end test_tbf_egprs_two_phase ===
=== start test_tbf_egprs_two_phase_spb ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -4022,6 +4043,7 @@ TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN EGPRS) Starting timer X2001 [assig
TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN EGPRS) appending 256 bytes
=== end test_tbf_egprs_two_phase_spb ===
=== start test_tbf_egprs_dl ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Testing MCS-1
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 11
@ -5842,6 +5864,7 @@ UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
DL_ASS_TBF(DL-TFI_0){SEND_ASS}: Deallocated
=== end test_tbf_egprs_dl ===
=== start test_tbf_egprs_retx_dl ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Testing retx for MCS 6 - 6
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 11
@ -6428,6 +6451,7 @@ UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
DL_ASS_TBF(DL-TFI_0){SEND_ASS}: Deallocated
=== end test_tbf_egprs_retx_dl ===
=== start test_tbf_egprs_spb_dl ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Testing retx for MCS 6 to reseg_mcs 3
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 11
@ -6745,6 +6769,7 @@ UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
DL_ASS_TBF(DL-TFI_0){SEND_ASS}: Deallocated
=== end test_tbf_egprs_spb_dl ===
=== start test_tbf_puan_urbb_len ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -6875,6 +6900,10 @@ TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN EGPRS) Starting timer X2001 [assig
TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN EGPRS) appending 256 bytes
=== end test_tbf_puan_urbb_len ===
=== start test_tbf_update_ws ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=2) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=3) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=5) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 11
Modifying MS object, TLLI = 0xffffffff, EGPRS MS class 0 -> 11
@ -6934,6 +6963,7 @@ UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
DL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
=== end test_tbf_update_ws ===
=== start test_tbf_li_decoding ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -7053,6 +7083,7 @@ TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN EGPRS) Starting timer X2001 [assig
TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN EGPRS) appending 256 bytes
=== end test_tbf_li_decoding ===
=== start test_tbf_epdan_out_of_rx_window ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 11
Modifying MS object, TLLI = 0xffffffff, EGPRS MS class 0 -> 11
@ -7105,6 +7136,7 @@ UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
DL_ASS_TBF(DL-TFI_0){SEND_ASS}: Deallocated
=== end test_tbf_epdan_out_of_rx_window ===
=== start test_immediate_assign_rej_multi_block ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x78 (8 bit) Fn=2654167 qta=31
MS requests single TS uplink transmission (one phase packet access)
Creating MS object, TLLI = 0xffffffff
@ -7330,6 +7362,8 @@ Tx Immediate Assignment Reject on AGCH
MS(TLLI=0xffffffff, IMSI=, TA=220, 0/0,) Destroying MS object
=== end test_immediate_assign_rej_multi_block ===
=== start test_immediate_assign_rej_single_block ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=7) PDCH state: enabled => disabled
MS requests Uplink resource on CCCH/RACH: ra=0x70 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
No PDCH available.
@ -7337,6 +7371,7 @@ No PDCH resource for single block allocation
Tx Immediate Assignment Reject on AGCH
=== end test_immediate_assign_rej_single_block ===
=== start test_tbf_egprs_two_phase_puan ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x73 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=2654270 TRX=0 TS=7
@ -8599,6 +8634,7 @@ Got MS: TLLI = 0xf1223344, TA = 7
TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN EGPRS) appending 256 bytes
=== end test_tbf_egprs_two_phase_puan ===
=== start test_packet_access_rej_epdan ===
PDCH(bts=0,trx=0,ts=4) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, TLLI = 0xffffffff, MS class 0 -> 11
Modifying MS object, TLLI = 0xffffffff, EGPRS MS class 0 -> 11
@ -8644,6 +8680,7 @@ UL_ASS_TBF(DL-TFI_0){SEND_ASS_REJ}: state_chg to NONE
packet reject: 40 84 7f f7 6e e6 7e ab 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
=== end test_packet_access_rej_epdan ===
=== start test_packet_access_rej_prr ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
MS requests Uplink resource on CCCH/RACH: ra=0x70 (8 bit) Fn=2654167 qta=31
MS requests single block allocation (two phase packet access)
Allocated a single block at SBFn=52 TRX=0 TS=7
@ -9101,6 +9138,7 @@ UL_ASS_TBF(UL-TFI_0){SEND_ASS}: state_chg to WAIT_ACK
PDCH(bts=0,trx=0,ts=7) FN=2654218 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xffeeddcc DIR=UL STATE=ASSIGN EGPRS)
=== end test_packet_access_rej_prr ===
=== start test_packet_access_rej_prr_no_other_tbfs ===
PDCH(bts=0,trx=0,ts=7) PDCH state: disabled => enabled
Creating MS object, TLLI = 0xffffffff
Modifying MS object, UL TLLI: 0xffffffff -> 0xffeeddcc, not yet confirmed
TBF{NEW}: Allocated

View File

@ -1,9 +1,11 @@
PDCH(bts=0,trx=0,ts=0) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=0) Trying to reserve already reserved FN 72
PDCH(bts=0,trx=0,ts=0) Trying to reserve already reserved FN 78
PDCH(bts=0,trx=0,ts=0) Trying to reserve already reserved FN 72
PDCH(bts=0,trx=0,ts=0) Trying to reserve already reserved FN 78
PDCH(bts=0,trx=0,ts=0) Trying to release unregistered SBA (FN=78, TA=0)
PDCH(bts=0,trx=0,ts=0) Timeout for registered SBA (FN=72, TA=0)
PDCH(bts=0,trx=0,ts=0) PDCH state: disabled => enabled
Creating MS object, TLLI = 0x12345678
MS(TLLI=0x12345678, IMSI=, TA=220, 0/0,) Attaching DL TBF: TBF(TFI=-1 TLLI=0x12345678 DIR=DL STATE=NEW)
PDCH(bts=0,trx=0,ts=0) Expiring FN=2715613 but previous FN=2715608 is still reserved!
@ -41,6 +43,8 @@ PDCH(bts=0,trx=0,ts=0) Expiring FN=43 but previous FN=34 is still reserved!
PDCH(bts=0,trx=0,ts=0) Timeout for registered POLL (FN=34, reason=UL_ASS): TBF(TFI=-1 TLLI=0x12345678 DIR=DL STATE=NEW)
PDCH(bts=0,trx=0,ts=0) Expiring FN=43 but previous FN=39 is still reserved!
PDCH(bts=0,trx=0,ts=0) Timeout for registered POLL (FN=39, reason=UL_ASS): TBF(TFI=-1 TLLI=0x12345678 DIR=DL STATE=NEW)
PDCH(bts=0,trx=0,ts=0) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=0) PDCH state: disabled => enabled
PDCH(bts=0,trx=0,ts=0) POLL scheduled at FN 26 + 13 = 39
PDCH(bts=0,trx=0,ts=0) UL block already scheduled at FN 91 + 13 = 104
PDCH(bts=0,trx=0,ts=0) POLL scheduled at FN 91 + 17 = 108