Actions
Bug #4755
closedPremature OML Radio Carrier(00,00,ff) Opstart
Start date:
09/16/2020
Due date:
% Done:
100%
Spec Reference:
Description
During the A-bis/OML bootstrapping, osmo-bsc sends Opstart to the Radio Carrier MO twice:
$ tshark -r /tmp/oml.pcap -Y "gsm_abis_oml.fom.obj_class == 0x02" 14 0.009785 127.0.0.1 → 127.0.0.1 OML 88 OML Radio Carrier(00,00,ff) State Changed Event Report NULL Power off Locked 37 0.019692 127.0.0.1 → 127.0.0.1 OML 88 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled OK Locked 39 0.021458 127.0.0.1 → 127.0.0.1 OML 80 OML Radio Carrier(00,00,ff) Software Activated Report 89 0.039537 127.0.0.1 → 127.0.0.1 OML 80 OML Radio Carrier(00,00,ff) Opstart (!) 90 0.039675 127.0.0.1 → 127.0.0.1 OML 80 OML Radio Carrier(00,00,ff) Opstart ACK 91 0.039967 127.0.0.1 → 127.0.0.1 OML 87 OML Radio Carrier(00,00,ff) Set Radio Carrier Attributes 92 0.041042 127.0.0.1 → 127.0.0.1 OML 87 OML Radio Carrier(00,00,ff) Set Radio Carrier Attributes ACK 101 0.045359 127.0.0.1 → 127.0.0.1 OML 82 OML Radio Carrier(00,00,ff) Change Administrative State Unlocked 102 0.046372 127.0.0.1 → 127.0.0.1 OML 82 OML Radio Carrier(00,00,ff) Change Administrative State ACK Unlocked 103 0.046480 127.0.0.1 → 127.0.0.1 OML 88 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled OK Unlocked 105 0.047801 127.0.0.1 → 127.0.0.1 OML 80 OML Radio Carrier(00,00,ff) Opstart (!) 106 0.048047 127.0.0.1 → 127.0.0.1 OML 82 OML Radio Carrier(00,00,ff) Opstart NACK
According to 3GPP TS 12.21, figure 2, we shall send it once, after the "Attribute setting" step. Therefore, the first Opstart (packet 89) is premature, and shall not be sent. The code in osmo-bsc looks correct: we send the Opstart in sw_activ_rep() after sending of both Set Radio Carrier Attributes and Change Administrative State.
case NM_OC_RADIO_CARRIER: {
/*
* Locking the radio carrier will make it go
* offline again and we would come here. The
* framework should determine that there was
* no change and avoid recursion.
*
* This code is here to make sure that on start
* a TRX remains locked.
*/
int rc_state = trx->mo.nm_state.administrative;
/* Patch ARFCN into radio attribute */
struct msgb *msgb = nanobts_attr_radio_get(trx->bts, trx);
abis_nm_set_radio_attr(trx, msgb->data, msgb->len);
msgb_free(msgb);
abis_nm_chg_adm_state(trx->bts, foh->obj_class,
trx->bts->bts_nr, trx->nr, 0xff,
rc_state);
abis_nm_opstart(trx->bts, foh->obj_class, trx->bts->bts_nr,
trx->nr, 0xff);
break;
}
Related issues
Updated by fixeria over 3 years ago
- Status changed from New to In Progress
- % Done changed from 0 to 20
I did some instrumentation, and here is how we end up calling abis_nm_opstart() twice:
Premature Opstart¶
pwndbg> bt #0 abis_nm_opstart (bts=0x5555559edab0, obj_class=2 '\002', i0=0 '\000', i1=0 '\000', i2=255 '\377') at abis_nm.c:2134 #1 0x000055555562b7c3 in nm_statechg_event (evt=8, nsd=0x7fffffffbc90) at bts_ipaccess_nanobts.c:191 #2 0x000055555562c056 in bts_ipa_nm_sig_cb (subsys=2, signal=8, handler_data=0x0, signal_data=0x7fffffffbc90) at bts_ipaccess_nanobts.c:343 #3 0x00007ffff7c791bc in osmo_signal_dispatch (subsys=2, signal=8, signal_data=0x7fffffffbc90) at signal.c:118 #4 0x00005555555df7c2 in abis_nm_rx_statechg_rep (mb=0x5555559fc950) at abis_nm.c:299 #5 0x00005555555e02e9 in abis_nm_rcvmsg_report (mb=0x5555559fc950, bts=0x5555559edab0) at abis_nm.c:477 #6 0x00005555555e2059 in abis_nm_rcvmsg_fom (mb=0x5555559fc950) at abis_nm.c:890 #7 0x00005555555e29bd in abis_nm_rcvmsg (msg=0x5555559fc950) at abis_nm.c:1050 #8 0x000055555562cf13 in ipaccess_sign_link (msg=0x5555559fc950) at bts_ipaccess_nanobts.c:635 #9 0x00007ffff7f82971 in handle_ts1_read (bfd=0x5555559fdce0) at ../../../src/libosmo-abis/src/input/ipaccess.c:405 #10 ipaccess_fd_cb (bfd=0x5555559fdce0, what=1) at ../../../src/libosmo-abis/src/input/ipaccess.c:544 #11 0x00007ffff7c786c3 in osmo_fd_disp_fds (_eset=<optimized out>, _wset=<optimized out>, _rset=<optimized out>) at select.c:227 #12 _osmo_select_main (polling=<optimized out>) at select.c:265 #13 0x00007ffff7c78d37 in osmo_select_main_ctx (polling=<optimized out>) at select.c:291 #14 0x000055555567e44d in main (argc=3, argv=0x7fffffffe1b8) at osmo_bsc_main.c:957 #15 0x00007ffff79d9152 in __libc_start_main () from /usr/lib/libc.so.6 #16 0x00005555555dda1e in _start ()
Expected Opstart¶
pwndbg> bt #0 abis_nm_opstart (bts=0x5555559edab0, obj_class=2 '\002', i0=0 '\000', i1=0 '\000', i2=255 '\377') at abis_nm.c:2134 #1 0x000055555562bd35 in sw_activ_rep (mb=0x5555559fc950) at bts_ipaccess_nanobts.c:296 #2 0x000055555562c043 in bts_ipa_nm_sig_cb (subsys=2, signal=0, handler_data=0x0, signal_data=0x5555559fc950) at bts_ipaccess_nanobts.c:340 #3 0x00007ffff7c791bc in osmo_signal_dispatch (subsys=2, signal=0, signal_data=0x5555559fc950) at signal.c:118 #4 0x00005555555e0359 in abis_nm_rcvmsg_report (mb=0x5555559fc950, bts=0x5555559edab0) at abis_nm.c:481 #5 0x00005555555e2059 in abis_nm_rcvmsg_fom (mb=0x5555559fc950) at abis_nm.c:890 #6 0x00005555555e29bd in abis_nm_rcvmsg (msg=0x5555559fc950) at abis_nm.c:1050 #7 0x000055555562cf13 in ipaccess_sign_link (msg=0x5555559fc950) at bts_ipaccess_nanobts.c:635 #8 0x00007ffff7f82971 in handle_ts1_read (bfd=0x5555559fdce0) at ../../../src/libosmo-abis/src/input/ipaccess.c:405 #9 ipaccess_fd_cb (bfd=0x5555559fdce0, what=1) at ../../../src/libosmo-abis/src/input/ipaccess.c:544 #10 0x00007ffff7c786c3 in osmo_fd_disp_fds (_eset=<optimized out>, _wset=<optimized out>, _rset=<optimized out>) at select.c:227 #11 _osmo_select_main (polling=<optimized out>) at select.c:265 #12 0x00007ffff7c78d37 in osmo_select_main_ctx (polling=<optimized out>) at select.c:291 #13 0x000055555567e44d in main (argc=3, argv=0x7fffffffe1b8) at osmo_bsc_main.c:957 #14 0x00007ffff79d9152 in __libc_start_main () from /usr/lib/libc.so.6 #15 0x00005555555dda1e in _start ()
Updated by fixeria over 3 years ago
Please see:
https://gerrit.osmocom.org/c/osmo-bsc/+/20162 fix nm_statechg_event(): do not send premature Opstart to Radio Carrier
This is how the message flow looks like with this patch applied:
40 14.861915792 127.0.0.1 → 127.0.2.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled Not installed Locked 75 14.862455473 127.0.0.1 → 127.0.2.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled Not installed Locked 95 14.864691831 127.0.0.1 → 127.0.2.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled OK Locked 99 14.864903256 127.0.0.1 → 127.0.2.1 OML 78 OML Radio Carrier(00,00,ff) Software Activated Report 184 14.867696364 127.0.2.1 → 127.0.0.1 OML 85 OML Radio Carrier(00,00,ff) Set Radio Carrier Attributes 187 14.867760749 127.0.0.1 → 127.0.2.1 OML 85 OML Radio Carrier(00,00,ff) Set Radio Carrier Attributes ACK 189 14.867822871 127.0.2.1 → 127.0.0.1 OML 80 OML Radio Carrier(00,00,ff) Change Administrative State Unlocked 191 14.867903702 127.0.0.1 → 127.0.2.1 OML 80 OML Radio Carrier(00,00,ff) Change Administrative State ACK Unlocked 194 14.867965384 127.0.2.1 → 127.0.0.1 OML 78 OML Radio Carrier(00,00,ff) Opstart 197 14.868022784 127.0.0.1 → 127.0.2.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled OK Unlocked 198 14.868041954 127.0.0.1 → 127.0.2.1 OML 78 OML Radio Carrier(00,00,ff) Opstart ACK 232 14.868891303 127.0.0.1 → 127.0.2.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled Not installed Unlocked 257 14.869878437 127.0.0.1 → 127.0.2.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Enabled OK Unlocked
I am not sure if it's a proper solution, somehow the State Changed look different now. But it still works.
It would be useful to look at the OML traces of a commercial BTS, because the specs. are not clear enough.
Also, it still looks like a mess without proper MO FSMs...
Updated by fixeria over 3 years ago
- Assignee changed from fixeria to pespin
Handing over to Pau as was discussed in DM.
Updated by pespin over 3 years ago
- Status changed from In Progress to Feedback
- % Done changed from 20 to 90
I updated the patch and tested it. I think the issue can be closed once merged.
Updated by fixeria over 3 years ago
This is how the signalling looks now:
20 1.480114821 127.0.0.1 → 127.0.0.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled Not installed Locked 36 1.480524392 127.0.0.1 → 127.0.0.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled Not installed Locked 63 1.482073447 127.0.0.1 → 127.0.0.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled OK Locked 67 1.482318955 127.0.0.1 → 127.0.0.1 OML 78 OML Radio Carrier(00,00,ff) Software Activated Report 142 1.488214368 127.0.0.1 → 127.0.0.1 OML 85 OML Radio Carrier(00,00,ff) Set Radio Carrier Attributes 147 1.488429685 127.0.0.1 → 127.0.0.1 OML 85 OML Radio Carrier(00,00,ff) Set Radio Carrier Attributes ACK 149 1.488546731 127.0.0.1 → 127.0.0.1 OML 80 OML Radio Carrier(00,00,ff) Change Administrative State Unlocked 152 1.488633566 127.0.0.1 → 127.0.0.1 OML 80 OML Radio Carrier(00,00,ff) Change Administrative State ACK Unlocked 160 1.489203743 127.0.0.1 → 127.0.0.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled OK Unlocked 193 1.490375741 127.0.0.1 → 127.0.0.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Disabled Not installed Unlocked (!) 320 1.495459686 127.0.0.1 → 127.0.0.1 OML 78 OML Radio Carrier(00,00,ff) Opstart 323 1.495527544 127.0.0.1 → 127.0.0.1 OML 78 OML Radio Carrier(00,00,ff) Opstart ACK 326 1.496398955 127.0.0.1 → 127.0.0.1 OML 86 OML Radio Carrier(00,00,ff) State Changed Event Report Enabled OK Unlocked
I am worried about packet 193, why would a Radio Carrier be Not installed if it already changed state to Disabled before?
This was also the case for the initial version of my patch.
Updated by pespin over 3 years ago
That's actually coming from BTS, so no reall worries here. It does so because there's no proper NM FSM in the BTS neither, so at some point when A)RSL is brought up or B) phy_link becomes enabled, the other requirement A or B is not yet fullfilled, so it switches to not installed. I'd say this is not an issue so far and can be improved once we decide to spend time on FSMs.
Updated by pespin over 3 years ago
- Related to Feature #2469: Proper OML MO (managed object) using osmo_fsm added
Updated by pespin over 3 years ago
- Related to Feature #2470: Proper OML MO (managed object) using osmo_fsm added
Updated by pespin over 3 years ago
- Status changed from Feedback to Resolved
- % Done changed from 90 to 100
Issue not appearing anymore after new OML FMS are in place in osmo-bts+osmo-bsc.
Actions
