diff --git a/src/pdch.cpp b/src/pdch.cpp index 8e70ffca..c1c7714c 100644 --- a/src/pdch.cpp +++ b/src/pdch.cpp @@ -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(); diff --git a/tests/app_info/AppInfoTest.err b/tests/app_info/AppInfoTest.err index d39e9520..1a9fab02 100644 --- a/tests/app_info/AppInfoTest.err +++ b/tests/app_info/AppInfoTest.err @@ -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 diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err index bc817b2e..ec0981c3 100644 --- a/tests/tbf/TbfTest.err +++ b/tests/tbf/TbfTest.err @@ -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 diff --git a/tests/ulc/PdchUlcTest.err b/tests/ulc/PdchUlcTest.err index 411c3f39..c7357c57 100644 --- a/tests/ulc/PdchUlcTest.err +++ b/tests/ulc/PdchUlcTest.err @@ -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