Bug #5238
closedTCH/F_PDCH is not properly deactivated in scheduler
100%
Description
Configure at least one ip.access style dynamic timeslot (TCH/F_PDCH) and start the network. Then kill osmo-pcu.
DPCU NOTICE pcu_sock.c:994 PCU socket has LOST connection DOML NOTICE oml.c:90 OC=GPRS-CELL INST=(00,ff,ff): Sending PCU version report to BSC: PCU socket has LOST connection DPCU NOTICE sysinfo.c:202 Disabling GPRS Indicator in SI (No PCU connected) DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 5 0' DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=5,ss=0) (bts=0,trx=0,ts=5,ss=0) not sending REL ACK DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 6 0' DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=6,ss=0) Deactivating PDTCH DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=6,ss=0) Deactivating PTCCH DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=6,ss=0) (bts=0,trx=0,ts=6,ss=0) not sending REL ACK DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 7 0' DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=7,ss=0) Deactivating PDTCH DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=7,ss=0) Deactivating PTCCH DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=7,ss=0) (bts=0,trx=0,ts=7,ss=0) not sending REL ACK DTRX INFO trx_if.c:672 phy0.0: Response message: 'RSP NOHANDOVER 0 5 0' DTRX INFO trx_if.c:672 phy0.0: Response message: 'RSP NOHANDOVER 0 6 0' DTRX INFO trx_if.c:672 phy0.0: Response message: 'RSP NOHANDOVER 0 7 0' DL1P NOTICE l1sap.c:126 (bts=0,trx=0,ts=5,ss=0) assuming active lchan, but state is NONE DL1P ERROR l1sap.c:732 1583426/1194/00/29/14 No lchan for DATA MEAS IND (chan_nr=PDCH on TS5) DPCU NOTICE pcu_sock.c:973 PCU socket not connected, dropping message DL1P NOTICE l1sap.c:126 (bts=0,trx=0,ts=5,ss=0) assuming active lchan, but state is NONE DPCU NOTICE pcu_sock.c:973 PCU socket not connected, dropping message DL1P NOTICE l1sap.c:126 (bts=0,trx=0,ts=5,ss=0) assuming active lchan, but state is NONE DL1P ERROR l1sap.c:732 1583430/1194/04/33/18 No lchan for DATA MEAS IND (chan_nr=PDCH on TS5) DPCU NOTICE pcu_sock.c:973 PCU socket not connected, dropping message DL1P NOTICE l1sap.c:126 (bts=0,trx=0,ts=5,ss=0) assuming active lchan, but state is NONE DPCU NOTICE pcu_sock.c:973 PCU socket not connected, dropping message DL1P NOTICE l1sap.c:126 (bts=0,trx=0,ts=5,ss=0) assuming active lchan, but state is NONE DL1P ERROR l1sap.c:732 1583434/1194/08/37/22 No lchan for DATA MEAS IND (chan_nr=PDCH on TS5) DPCU NOTICE pcu_sock.c:973 PCU socket not connected, dropping message DL1P NOTICE l1sap.c:126 (bts=0,trx=0,ts=5,ss=0) assuming active lchan, but state is NONE DPCU NOTICE pcu_sock.c:973 PCU socket not connected, dropping message DL1P NOTICE l1sap.c:126 (bts=0,trx=0,ts=5,ss=0) assuming active lchan, but state is NONE DL1P ERROR l1sap.c:732 1583439/1194/13/42/27 No lchan for DATA MEAS IND (chan_nr=PDCH on TS5) DPCU NOTICE pcu_sock.c:973 PCU socket not connected, dropping message DL1P NOTICE l1sap.c:126 (bts=0,trx=0,ts=5,ss=0) assuming active lchan, but state is NONE DPCU NOTICE pcu_sock.c:973 PCU socket not connected, dropping message
As can be seen from the logs, TS5/PDCH is not being deactivated in the scheduler:
DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 5 0' DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=5,ss=0) (bts=0,trx=0,ts=5,ss=0) not sending REL ACK DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 6 0' DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=6,ss=0) Deactivating PDTCH DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=6,ss=0) Deactivating PTCCH DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=6,ss=0) (bts=0,trx=0,ts=6,ss=0) not sending REL ACK
So AFAIU, the lower layers keep trying to decode Uplink blocks on TS5 and therefore produce L1SAP DATA.ind, which in turn cause the errors/warnings.
Updated by fixeria over 2 years ago
With a bit more verbose logging, it can be seen that for some reason osmo-bts attempts to deactivate chan_nr=TCH/F on TS5:
DL1C INFO l1sap.c:2076 (bts=0,trx=0,ts=5,ss=0) deactivating channel chan_nr=TCH/F on TS5 trx=0 DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 5 0' DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=5,ss=0) (bts=0,trx=0,ts=5,ss=0) not sending REL ACK DL1C INFO l1sap.c:2076 (bts=0,trx=0,ts=6,ss=0) deactivating channel chan_nr=PDCH on TS6 trx=0 DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 6 0' DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=6,ss=0) Deactivating PDTCH DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=6,ss=0) Deactivating PTCCH DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=6,ss=0) (bts=0,trx=0,ts=6,ss=0) not sending REL ACK
This is why both PDTCH and PTCCH remain active in the scheduler. But why TCH/F?
Updated by fixeria over 2 years ago
- Project changed from OsmoPCU to OsmoBTS
- Subject changed from TCH/F_PDCH timeslots flood logs on osmo-pcu disconnect to TCH/F_PDCH is not properly deactivated in scheduler
- Category set to osmo-bts-trx
- Assignee set to fixeria
fixeria wrote:
This is why both PDTCH and PTCCH remain active in the scheduler. But why TCH/F?
This is clearly explained in gsm_lchan2chan_nr():
case GSM_PCHAN_TCH_F_PDCH:
/* For ip.access style dyn TS, we always want to use the chan_nr as if it was TCH/F.
* We're using custom PDCH ACT and DEACT messages that use the usual chan_nr values. */
chan_nr = gsm_lchan_as_pchan2chan_nr(lchan, GSM_PCHAN_TCH_F);
break;
Updated by fixeria over 2 years ago
On the other hand, channel activation as TCH/F still works somehow:
DPCU INFO pcu_sock.c:853 Activate request received: TRX=0 TS=5 DL1C INFO l1sap.c:2043 (bts=0,trx=0,ts=5,ss=0) activating channel TCH/F on TS5 DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=5,ss=0) Activating PDTCH DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=5,ss=0) Activating PTCCH DL1C NOTICE scheduler.c:1159 (bts=0,trx=0,ts=5) Set mode for PDTCH (rsl_cmode=0, tch_mode=0, handover=0) DL1C NOTICE scheduler.c:1159 (bts=0,trx=0,ts=5) Set mode for PTCCH (rsl_cmode=0, tch_mode=0, handover=0)
Updated by fixeria over 2 years ago
- Status changed from New to In Progress
- % Done changed from 0 to 20
fixeria wrote:
On the other hand, channel activation as TCH/F still works somehow:
This is why, see bts_model_l1sap_down() in 'src/osmo-bts-trx/l1_if.c':
/* trx_chan_desc[] in scheduler.c uses the RSL_CHAN_OSMO_PDCH cbits
* (0xc0) to indicate the need for PDTCH and PTCCH SAPI activation.
* However, 0xc0 is a cbits pattern exclusively used for Osmocom style
* dyn TS (a non-standard RSL Chan Activ mod); hence, for IPA style dyn
* TS, the chan_nr will never reflect 0xc0 and we would omit the
* PDTCH,PTTCH SAPIs. To properly de-/activate the PDTCH SAPIs in
* scheduler.c, make sure the 0xc0 cbits are set for de-/activating PDTCH
* lchans, i.e. both Osmocom and IPA style dyn TS. (For Osmocom style dyn
* TS, the chan_nr typically already reflects 0xc0, while it doesn't for
* IPA style.) */
if (lchan->type == GSM_LCHAN_PDTCH)
chan_nr = RSL_CHAN_OSMO_PDCH | (chan_nr & ~RSL_CHAN_NR_MASK);
This snippet is not present in the branch responsible for deactivation, so this is why it fails. I am inclined to remove this workaround and introduce two variants of gsm_lchan2chan_nr() instead: one for the RSL, another for everything else.
Updated by fixeria over 2 years ago
- Status changed from In Progress to Feedback
- % Done changed from 20 to 80
With these patches applied, deactivation works as expected.
https://gerrit.osmocom.org/c/osmo-bts/+/25580 gsm_lchan2chan_nr(): separate RSL specific variant of this API [NEW]
https://gerrit.osmocom.org/c/osmo-bts/+/25581 osmo-bts-trx: bts_model_l1sap_down(): remove chan_nr patching [NEW]
DL1C NOTICE l1sap.c:2076 (bts=0,trx=0,ts=5,ss=0) Deactivating channel PDCH on TS5 DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 5 0' DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=5,ss=0) Deactivating PDTCH DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=5,ss=0) Deactivating PTCCH DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=5,ss=0) (bts=0,trx=0,ts=5,ss=0) not sending REL ACK DL1C NOTICE l1sap.c:2076 (bts=0,trx=0,ts=6,ss=0) Deactivating channel PDCH on TS6 DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 6 0' DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=6,ss=0) Deactivating PDTCH DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=6,ss=0) Deactivating PTCCH DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=6,ss=0) (bts=0,trx=0,ts=6,ss=0) not sending REL ACK DL1C NOTICE l1sap.c:2076 (bts=0,trx=0,ts=7,ss=0) Deactivating channel PDCH on TS7 DTRX INFO trx_if.c:255 phy0.0: Enqueuing TRX control command 'CMD NOHANDOVER 7 0' DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=7,ss=0) Deactivating PDTCH DL1C NOTICE scheduler.c:1097 (bts=0,trx=0,ts=7,ss=0) Deactivating PTCCH DRSL NOTICE rsl.c:1286 (bts=0,trx=0,ts=7,ss=0) (bts=0,trx=0,ts=7,ss=0) not sending REL ACK
No error messages observed after osmo-pcu disconnects.
Updated by fixeria over 2 years ago
- Status changed from Feedback to Resolved
- % Done changed from 80 to 100
Applied in changeset osmo-bts|e51fb333ae4c165757e21adcf5061688eab057d2.