balapi / netconf-polt

netconf server for use with BAL API
Apache License 2.0
6 stars 3 forks source link

Why deactivating ONU before activating it? #13

Closed wdl2015 closed 1 year ago

wdl2015 commented 1 year ago

Hi Igor,

If BAL calls bbf_xpon_onu_discovered() callback it means this ONU is going through O1~O5 process for activation, it must be currently in inactive state, why we need deactivate this ONU before activating it in this callback?

Thanks a lot in advance for explanation.

/ Handle ONU_DISCOVERED indication / void bbf_xpon_onu_discovered(bcmolt_oltid olt, bcmolt_msg msg) { bcmolt_pon_interface_onu_discovered od = (bcmolt_pon_interface_onu_discovered *)msg; bcmos_bool auto_activated = BCMOS_FALSE; bcmos_errno err;

NC_LOG_DBG("ONU_discovered: onu_id=%u serial_number=%c%c%c%c-%02x%02x%02x%02x\n",
    od->data.onu_id,
    od->data.serial_number.vendor_id.arr[0], od->data.serial_number.vendor_id.arr[1],
    od->data.serial_number.vendor_id.arr[2], od->data.serial_number.vendor_id.arr[3],
    od->data.serial_number.vendor_specific.arr[0], od->data.serial_number.vendor_specific.arr[1],
    od->data.serial_number.vendor_specific.arr[2], od->data.serial_number.vendor_specific.arr[3]);

/* If onu_id is already assigned, that means that ONU is already provisioned.
   In this case activate it */
if (BCMOLT_FIELD_IS_SET(&od->data, pon_interface_onu_discovered_data, onu_id) &&
    od->data.onu_id != BCMOLT_ONU_ID_INVALID)
{
    const xpon_v_ani *onu_info = xpon_v_ani_get_by_id(od->key.pon_ni, od->data.onu_id);
    if (onu_info != NULL && onu_info->admin_state == XPON_ADMIN_STATE_ENABLED)
    {
        bcmolt_onu_set_onu_state set_state;
        bcmolt_onu_key key = { .pon_ni = od->key.pon_ni, .onu_id = od->data.onu_id };

        /* Deactivate first in case it is already active */
        err = _onu_deactivate(od->key.pon_ni, od->data.onu_id, BCMOS_FALSE);
        if (err != BCM_ERR_OK)
        {
            NC_LOG_ERR("ONU.set_onu_state(INACTIVE) failed for (pon-id:%u, onu-id:%u). Error %s\n",
                    key.pon_ni, key.onu_id, bcmos_strerror(err));
        }

Best regards, George Deng

igortern commented 1 year ago

Hi George, The idea is to start ONU provisioning from a well known state. It is possible to query ONU state and deactivate only if active, but I opted not to do it here because deactivating ONU doesn't do any harm if ONU was inactive. ONU discovery handling might need to be revised once someone implements logic for a sync with an active ONU. Regards, Igor

wdl2015 commented 1 year ago

Hi Igor,

Thanks for quick response for this question. Here is a scenario that the deactivation might harm.

Could you review if this is a problem? I removed the ONU deactivation for now and this problem is solved.

Br George Deng

igortern commented 1 year ago

Hi George, I suspect that without ONU deactivation you will run into problem if restart NETCONF server after ONU was activated. Can you try adding nc_config_lock()/nc_config_unlock() calls in bbf_xpon_onu_discovered()? Thanks, Igor

wdl2015 commented 1 year ago

Hi Igor,

1) By "NETCONF server" you mean bcmolt_netconf_server process or netopeer2-server process?

2) Could you detail the scenario "restart NETCONF server after ONU was activated"?

3) Tried adding nc_config_lock()/nc_config_unlock() as follows. Have the same problem for the scenario mentioned previously.

nc_config_logck() and nc_config_unlock are added in bbf_xpon_onu_discovered() like this.

        nc_config_lock(); // george
        /* Deactivate first in case it is already active */
        err = _onu_deactivate(od->key.pon_ni, od->data.onu_id, BCMOS_FALSE);
        if (err != BCM_ERR_OK)
        {
            NC_LOG_ERR("ONU.set_onu_state(INACTIVE) failed for (pon-id:%u, onu-id:%u). Error %s\n",
                    key.pon_ni, key.onu_id, bcmos_strerror(err));
        }

        /* Now activate */
        BCMOLT_OPER_INIT(&set_state, onu, set_onu_state, key);
        BCMOLT_MSG_FIELD_SET(&set_state, onu_state, BCMOLT_ONU_OPERATION_ACTIVE);
        err = bcmolt_oper_submit(netconf_agent_olt_id(), &set_state.hdr);
        if (err == BCM_ERR_OK)
        {
            auto_activated = BCMOS_TRUE;
        }
        else if (!(err == BCM_ERR_STATE && strstr(set_state.hdr.hdr.err_text, "processing") != NULL))
        {
            NC_LOG_ERR("ONU activation failed for %s. Error %s-%s\n",
                onu_info->hdr.name, bcmos_strerror(err), set_state.hdr.hdr.err_text);
        }
        nc_config_unlock(); // george

Repeat the scenario mentioned previously, see the same error in log.

Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91137: I OMCI_TRANSPORT ] omci_transport.c 206| Retransmission: OLT 0 PON 0 ONU 2 Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91137: D OMCI_TRANSPORT ] omci_transport.c 128| Resending (after ACK timeout) OMCI message to OLT 0 PON 0 ONU ID 2}, (buf = 0x7fa684001240, Msg len = 44, TCI = 0x1), retry msg counter = 1, ar=1 Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91137: D api ] /olt 0;^[[1m^[[32m/api/oper object=onu sub=cpu_packets pon_ni=0 onu_id=2 packet_type=omci calc_crc=yes number_of_packets=1 packet_size=44 buffer=00014f0a00020000000000000000000000000000000 Oct 10 18:57:51 bcmolt_netconf_server[5360]: 000000000000028
^[[0m^[#5
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: E OMCI_SVC ] omci_svc_remote_proxy_if.c 56| OMCI message send Failed for (PON=0, ONU=2)
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: E OMCI_SVC ] omci_svc_remote_proxy_if.c 110| omci_svc_omci_data_req failed: PON=0, ONU=2, rc=Object is in bad state
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: E OMCI_TRANSPORT ] omci_transport.c 144| Failed to send OMCI message to OLT 0 PON 0 ONU ID 2, rc=Error in parameters (Msg val = 0x7fa684001240, len = 44) Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_SVC ] omci_svc_onu.c 2467| key={pon_ni=0, onu_id=2}, op_ref=1: MIB reset request completed successfully
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_SVC ] omci_svc_onu.c 2342| key={pon_ni=0, onu_id=2}, op_ref=1: ONU SM state='mib_reset', event='mib_reset_success'
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_SVC ] omci_svc_onu.c 2342| key={pon_ni=0, onu_id=2}, op_ref=1: ONU SM state='mib_reset', event='start'
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_ME_LAYER ] omci_stack_enc_dec.c 8729| {olt=0 pon_if=0, onu_id=2, cookie=2}: Dump ME: onu_data (2), Entity: 0, Action: MIB_UPLOAD [
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_ME_LAYER ] omci_stack_enc_dec.c 8738| ]
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_TRANSPORT ] omci_transport.c 871| Send OMCI message {OLT:0 PON:0, ONU: 2, class:onu_data, instance:0, msg type:MIB_UPLOAD TCI=2 (0x7fa670000cb0)}, retry msg counter = 0 Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_TRANSPORT ] omci_stack_rx.c 913| 00 02 4D 0A 00 02 00 00 00 00 00 00 00 00 00 00
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_TRANSPORT ] omci_stack_rx.c 913| 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_TRANSPORT ] omci_stack_rx.c 913| 00 00 00 00 00 00 00 00 00 00 00 28
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_TRANSPORT ] omci_transport.c 128| Sending OMCI message to OLT 0 PON 0 ONU ID 2}, (buf = 0x7fa670000cb0, Msg len = 44, TCI = 0x2), retry msg counter = 0, ar=1
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D api ] /olt 0;^[[1m^[[32m/api/oper object=onu sub=cpu_packets pon_ni=0 onu_id=2 packet_type=omci calc_crc=yes number_of_packets=1 packet_size=44 buffer=00024d0a00020000000000000000000000000000000 Oct 10 18:57:51 bcmolt_netconf_server[5360]: 000000000000028
^[[0m^[#5
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: E OMCI_SVC ] omci_svc_remote_proxy_if.c 56| OMCI message send Failed for (PON=0, ONU=2)
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: E OMCI_SVC ] omci_svc_remote_proxy_if.c 110| omci_svc_omci_data_req failed: PON=0, ONU=2, rc=Object is in bad state
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: E OMCI_TRANSPORT ] omci_transport.c 144| Failed to send OMCI message to OLT 0 PON 0 ONU ID 2, rc=Error in parameters (Msg val = 0x7fa670000cb0, len = 44) Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: E OMCI_SVC ] omci_svc_onu.c 944| key={pon_ni=0, onu_id=2}, op_ref=2: omci_svc_omci_mib_upload_req() failed, rc=Error in parameters
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_SVC ] omci_svc_onu.c 2420| key={pon_ni=0, onu_id=2}, op_ref=2: Starting transaction rollback from SM state='inactive'
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: D OMCI_TRANSPORT ] omci_transport.c 645| ONU Init: OLT 0 PON 0 ONU 2
Oct 10 18:57:51 bcmolt_netconf_server[5360]: [91138: E OMCI_SVC ] omci_svc_onu.c 861| key={pon_ni=0, onu_id=2}, op_ref=2: omci_svc_omci_activate_req() failed, rc=Entry already exists/already in requested state

Br George Deng

igortern commented 1 year ago

Hi George,

By "NETCONF server" you mean bcmolt_netconf_server process or netopeer2-server process? Could you detail the scenario "restart NETCONF server after ONU was activated"? Usually I terminate bcmolt_netconf_server and then use start_netconf_server.sh again. It restarts netopeer2-server as well. The scenario is simple: 1) apply configuration that activates an ONU 2) restart NETCONF server 3) apply the same configuration again

If nc_config_lock()/.unlock() doesn't help, another option is:

Thanks, Igor

wdl2015 commented 1 year ago

Hi Igor,

Thanks a lot. Clear now. Trying your proposal.

Do you think below is an option?

Br George Deng

igortern commented 1 year ago

Hi George,

In case of embedded OMCI ONU activation is a lengthy process that involves O2->O5 transition followed by the initial OMCI provisioning. I think instead of checking onu_state=="processing", need to add some activation_in_progress flag in xpon_v_ani structure.

Thanks, Igor

On Tue, Oct 11, 2022 at 4:55 PM dengguochen2003 @.***> wrote:

Hi Igor,

Thanks a lot. Clear now. Trying your proposal.

Do you think below is an option?

  • Check ONU state. If it is "processing" don't do _onu_deactivate() because "processing" means this ONU is going from O2 to O5 for activation. If it is "active" do _onu_deactivate().

Br George Deng

— Reply to this email directly, view it on GitHub https://github.com/balapi/netconf-polt/issues/13#issuecomment-1274123282, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEX4KW57YQ6VJTW7PDQ5HODWCT6MZANCNFSM6AAAAAARBAMSOA . You are receiving this because you commented.Message ID: @.***>

-- This electronic communication and the information and any files transmitted with it, or attached to it, are confidential and are intended solely for the use of the individual or entity to whom it is addressed and may contain information that is confidential, legally privileged, protected by privacy laws, or otherwise restricted from disclosure to anyone else. If you are not the intended recipient or the person responsible for delivering the e-mail to the intended recipient, you are hereby notified that any use, copying, distributing, dissemination, forwarding, printing, or copying of this e-mail is strictly prohibited. If you received this e-mail in error, please return the e-mail to the sender, delete it from your computer, and destroy any printed copy of it.

wdl2015 commented 1 year ago

Hi Igor,

It is a nice idea to add one more flag activation_in_progress which indicates the ONU&OMCI is ready.

BTW: What we are considering are the "ONU reboot" and "OLT reboot" scenarios. Met the issue in this ticket for the OLT reboot scenario.

static void omci_svc_state_up_sequence_end_event_start(bcmonu_mgmt_onu_key key, omci_svc_onu onu_context, void context) { bcmos_errno rc; bcmonu_mgmt_onu_cfg onu_cfg; bcmolt_oltid olt_id = onu_context->onu_cfg->hdr.hdr.olt_id; onu_context->state = OMCI_SVC_ONU_STATE_ID_ACTIVE_WORKING; onu_context->oper_status = BCMONU_MGMT_STATUS_UP; OMCI_SVC_LOG(INFO, olt_id, key, NULL, "ONU added successfully (is_up=true)\n");

/* update cfg DB first, since notify calls does a GET on the onu */
if (BCM_ERR_OK == onu_context->last_err)
{
    /* update sm cfg DB */
    onu_cfg = onu_context->onu_cfg;
    rc = omci_svc_sm_cfg_db_update_entry(onu_cfg);
    if (BCM_ERR_OK != rc)
        OMCI_SVC_LOG(ERROR, olt_id, key, &onu_cfg->hdr.hdr, "ONU cfg DB update Failed\n");
}

if (onu_context->cb)
    onu_context->cb(onu_context->context, onu_context->last_err);

rc = vlan_subif_reapply_to_onu_flows(key->pon_ni, key->onu_id);
if (BCM_ERR_OK != rc)
{
    OMCI_SVC_LOG(ERROR, olt_id, key, NULL, "Reapply vlan subif to ONU failed.\n");
}

Br, George Deng

venkatkakumani commented 1 year ago

Can you provide the patch for this issue?