Project

General

Profile

Bug #4755

Premature OML Radio Carrier(00,00,ff) Opstart

Added by fixeria about 1 month ago. Updated about 1 month ago.

Status:
Feedback
Priority:
Normal
Assignee:
Category:
A-bis OML
Target version:
-
Start date:
09/16/2020
Due date:
% Done:

90%

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

Related to OsmoBTS - Feature #2469: Proper OML MO (managed object) using osmo_fsmFeedback08/29/2017

Related to OsmoBSC - Feature #2470: Proper OML MO (managed object) using osmo_fsmResolved08/29/2017

History

#1 Updated by fixeria about 1 month 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 ()

#2 Updated by fixeria about 1 month 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...

#3 Updated by fixeria about 1 month ago

  • Assignee changed from fixeria to pespin

Handing over to Pau as was discussed in DM.

#4 Updated by pespin about 1 month 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.

#5 Updated by fixeria about 1 month 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.

#6 Updated by pespin about 1 month 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.

See #2469 and #2470.

#7 Updated by pespin about 1 month ago

  • Related to Feature #2469: Proper OML MO (managed object) using osmo_fsm added

#8 Updated by pespin about 1 month ago

  • Related to Feature #2470: Proper OML MO (managed object) using osmo_fsm added

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)