UBLOX_EVK_ODIN_W2 - WIFI - reconnection fails

[JaniSuonpera]

Description

• Type: Bug

---

Bug

Version information
mbed-os-example-client (4bd452e11d5a)
|- easy-connect (15b79c8657b8)
| |- atmel-rf-driver (3cc6010188c0)
| |- esp8266-driver (44fb447c72a3)
| | - ESP8266/ATParser (77734ee44a63) | |- mcr20a-rf-driver (9aac10474702) | - stm-spirit1-rf-driver (bee61bbe6807)
|- mbed-client (31e5ce203cc0)
| |- mbed-client-c (ecfa619e42b2)
| |- mbed-client-classic (4e66929607c3)
| - mbed-client-mbed-tls (7e1b6d815038) |- mbed-os (4c256f045961) - pal (60ce64d5ec35)

Environment details
UBLOX_EVK_ODIN_W2 - WIFI, GCC_ARM

Expected Behavior
Reconnection succeed.

Actual Behavior
Reconnection fails.

Steps to Reproduce

• Startup connection with WIFI
• Turn of WIFI server
• Wait until you see trace [ERROR:] M2MInterface::InvalidParameters
• Turn on WIFI server
  log.txt

[0xc0170]

@andreaslarssonublox @andreaspeterssonublox

[alekshex]

We have an issue with Ethernet also. connect fails, should i open another issue?

[0xc0170]

We have an issue with Ethernet also. connect fails, should i open another issue?

Yes, please.

[alekshex]

created a new issue as requested for Ethernet case #4952

[andreaslarssonublox]

wifi_emac_api.zip
Hi, @JaniSuonpera! I have problems reproducing the issue. It would be very valuable to get some logging of the Wi-Fi connect states and to see if any data is sent to/from the driver. Can you use the attached file to get some more logging?
It's should be located here:
mbed-os-example-client\mbed-os\targets\TARGET_STM\TARGET_STM32F4\TARGET_STM32F439xI\TARGET_UBLOX_EVK_ODIN_W2\sdk\wifi_emac

When trying I only get NetworkError and DnsResolvingFailed. I have waited 150 counts of the simulate_button_click. It seems to work after reconnecting in those cases.

[JaniSuonpera]

Here is log.txt. It will take some time to get reproduces.

[andreaslarssonublox]

I checked the log and it looks like the Wi-Fi link is up and can send/receive data, see line 2138 and 2461.
I was able to reproduce the InvalidParameters error by doing several power up/down cycles of the AP.
When debugging I found that the if-statement on line sn_coap_protocol.c:859 fails:

          if (handle->count_resent_msgs >= handle->sn_coap_resending_queue_msgs) {

This is the call stack:

          sn_coap_protocol_linked_list_send_msg_store()  C++ (gdb)
          sn_coap_protocol_build()             C++ (gdb)
          sn_nsdl_internal_coap_send()      C++ (gdb)
          sn_nsdl_update_registration()      C++ (gdb)
          M2MNsdlInterface::send_update_registration()    C++ (gdb)
          M2MNsdlInterface::timer_expired()          C++ (gdb)
          M2MTimerPimpl::timer_expired()              C++ (gdb)
          tasklet_func()     C++ (gdb)
          eventOS_scheduler_dispatch_event()        C++ (gdb)
          eventOS_scheduler_run()              C++ (gdb)
          event_loop_thread()        C++ (gdb)
          osThreadGetId() C++ (gdb)
          0x00000200        

By changing the value of count_resent_msgs to 0 it seemed to work again so I guess there is something in COAP that is not working correctly with the registration.

[0xc0170]

By changing the value of count_resent_msgs to 0 it seemed to work again so I guess there is something in COAP that is not working correctly with the registration.

@JaniSuonpera Can you confirm this?

[JaniSuonpera]

I agree that is UBLOX driver issue.

This needs more investigation. If set count_resent_msgs to 0 we might lost some package, which is required to resend.

[ghseb]

I observed the same or a similar issue when using a cellular module (non UBLOX, custom driver, UDP only) and would be happy for a fix.

Some background from my side:

If cellular connection is lost mbed-client calls NetworkStack::socket_close(). After a successful close it tries to reestablish the connection by calling NetworkStack::socket_open(), NetworkStack::socket_attach() and NetworkStack::socket_bind(). Then M2MInterfaceImpl::state_update_registration() is called somehow. Within this method _nsdl_interface.send_update_registration() returns false and _nsdl_interface.send_register_message() also returns false because of if (handle->count_resent_msgs >= handle->sn_coap_resending_queue_msgs) like mentioned before.
The outcome is [ERROR:] M2MInterface::InvalidParameters and no communication is happening anymore.

Maybe also the behaviour of a Network Driver that is expected by mbed-client should be documented in more details.

Call Stack:

		Core #0 (Suspended)	
			state_update_registration(0x20020A80, 0x00000000) at m2minterfaceimpl.cpp:847,17 (0x8038bf8)	
			state_function(0x20020A80, '\t' (0x09), 0x00000000) at m2minterfaceimpl.cpp:1.025,13 (0x8038e5a)	
			state_engine(0x20020A80) at m2minterfaceimpl.cpp:980,9 (0x8038dae)	
			internal_event(0x20020A80, '\t' (0x09), 0x00000000) at m2minterfaceimpl.cpp:963,5 (0x8038d68)	
			state_register_address_resolved(0x20020A80, 0x20002870 (event_thread_stk + 6032)) at m2minterfaceimpl.cpp:816,17 (0x8038b96)	
			state_function(0x20020A80, '\a' (0x07), 0x20002870 (event_thread_stk + 6032)) at m2minterfaceimpl.cpp:1.019,13 (0x8038e46)	
			state_engine(0x20020A80) at m2minterfaceimpl.cpp:980,9 (0x8038dae)	
			internal_event(0x20020A80, '\a' (0x07), 0x20002870 (event_thread_stk + 6032)) at m2minterfaceimpl.cpp:963,5 (0x8038d68)	
			address_ready(0x20020A80, 0x200218FC, LWM2MServer, 3335) at m2minterfaceimpl.cpp:488,9 (0x8038436)	
			dns_handler(0x200218E8) at m2mconnectionhandlerpimpl.cpp:344,17 (0x804d0dc)	
			connection_event_handler(0x2000460C (startup_event_pool + 252)) at m2mconnectionhandlerpimpl.cpp:60,13 (0x804ccf0)	
			eventOS_scheduler_dispatch_event() at event.c:339,5 (0x804f76a)	
			eventOS_scheduler_run() at event.c:363,14 (0x804f796)	
			event_loop_thread(0x00000000) at ns_event_loop.c:85,5 (0x804f390)	
			osThreadExit() at rtx_thread.c:1.650,1 (0x8020250)	

[0xc0170]

cc @yogpan01 @JanneKiiskila

[ghseb]

Adding sn_nsdl_clear_coap_resending_queue(_nsdl_interface.get_nsdl_handle()); at two locations seems to keep mbed-client running. Mabe it would also be possible to put this reset directly into the state-transition methods of STATE_IDLE.

It seems that afterwards a new registration is required.

void M2MInterfaceImpl::state_register_address_resolved( EventData *data)
{
    tr_debug("M2MInterfaceImpl::state_register_address_resolved");
    if(data) {
        ResolvedAddressData *event = static_cast<ResolvedAddressData *> (data);

        sn_nsdl_addr_type_e address_type = SN_NSDL_ADDRESS_TYPE_IPV6;

        M2MInterface::NetworkStack stack = event->_address->_stack;

        if(M2MInterface::LwIP_IPv4 == stack) {
            tr_debug("M2MInterfaceImpl::state_register_address_resolved : IPv4 address");
            address_type = SN_NSDL_ADDRESS_TYPE_IPV4;
        } else if((M2MInterface::LwIP_IPv6 == stack) ||
                  (M2MInterface::Nanostack_IPv6 == stack)) {
            tr_debug("M2MInterfaceImpl::state_register_address_resolved : IPv6 address");
            address_type = SN_NSDL_ADDRESS_TYPE_IPV6;
        }
        _connection_handler.start_listening_for_data();
        _nsdl_interface.set_server_address((uint8_t*)event->_address->_address,event->_address->_length,
                                           event->_port, address_type);
        switch (_reconnection_state) {
            case M2MInterfaceImpl::None:
            case M2MInterfaceImpl::FullRegistration:
                if(!_nsdl_interface.send_register_message()) {
                    // If resource creation fails then inform error to application
                    tr_error("M2MInterfaceImpl::state_register_address_resolved : M2MInterface::InvalidParameters");
                    sn_nsdl_clear_coap_resending_queue(_nsdl_interface.get_nsdl_handle()); // Reset resend queue
                    internal_event(STATE_IDLE);
                    _observer.error(M2MInterface::InvalidParameters);
                }
                break;
            case M2MInterfaceImpl::WithUpdate:
                // Start registration update in case it is reconnection logic because of network issue.
                internal_event(STATE_UPDATE_REGISTRATION);
                break;
        }
    }
}

void M2MInterfaceImpl::state_update_registration(EventData *data)
{
    tr_debug("M2MInterfaceImpl::state_update_registration");
    uint32_t lifetime = 0;
    if(data) {
        M2MUpdateRegisterData *event = static_cast<M2MUpdateRegisterData *> (data);
        // Create new resources if any
        if (!event->_object_list.empty()) {
            _nsdl_interface.create_nsdl_list_structure(event->_object_list);
        }
        lifetime = event->_lifetime;
    }

    bool success = _nsdl_interface.send_update_registration(lifetime);
    if(!success) {
        if(_reconnection_state == M2MInterfaceImpl::WithUpdate) {
            _reconnection_state = M2MInterfaceImpl::FullRegistration;
            if(!_nsdl_interface.send_register_message()) {
                tr_error("M2MInterfaceImpl::state_update_registration : M2MInterface::InvalidParameters");
                sn_nsdl_clear_coap_resending_queue(_nsdl_interface.get_nsdl_handle()); // Reset resend queue
                internal_event(STATE_IDLE);
                _observer.error(M2MInterface::InvalidParameters);
            }
        }
    }
}

[andreaslarssonublox]

@JaniSuonpera I have created a new binary that might solve this issue. I have not had time to verify it yet. Maybe you can try? See #5287