Issues with NCP device at higher data rate recieved from SED

[Brian (Geek)]

Hello,

My product is developed on mqttsn example of nRF5 SDK for Thread. Current setup is having one SED and one NCP device connected to OTBR ( having Nordic Image). 

So issue arises when i transfer data from  SED at high data rate i.e (1 payload of size 95 bytes/100ms). And i have confirmed from Thread group discussion that a device in network can send data at this rate if there aren't any other devices in the network. So after 10-15 minutes of continuously running my SED  suddenly changes it's state to 1, which causes it to stop transmitting data.

I would like to know the reason behind this sort of behaviour:

1. Is it NCP firmware issue. Do i have to change any parameters or allocate memory blocks in NCP firmware to handle such a fast speed data reception from sleepy device ? Because i think my NCP device gets uninitialized than get initialized again as its in while loop in the NCP firmware. And when my NCP device gets de-initialized due to some issue my SED go to state 1. This could be a possible issue, but i am not sure if this is the case.

Does data rate 100ms have any imapct on NCP device connected to OTBR ? And if yes how to debug or solve ?

2. If it's not a NCP issue, than i would like to know why my SED are getting its state changed to 1 ?

[Simonr]

Hi

my SED  suddenly changes it's state to 1

Sorry, but what do you mean by the state changing to 1? What was the state prior to this, and what exactly is "state 1"?

1. If all the data arrives to the NCP correctly without any corruptions, I don't see why it would be an issue on the NCP side of the application, since the SED is the side that is having trouble as far as I can tell.

2. Can you check whether this state change always happens after a set amount of time, this might be some timer trigging somewhere between 10 and 15 minutes that requires it to stop transmitting, perhaps that it needs to update its status to the network for example? Do you see any kind of error when this state change occurs. A sniffer trace of this occurring might be helpful to narrow down what happens exactly. You can use an nRF52840 DK or Dongle and the nRF Sniffer for 802.15.4 to do this.

Best regards,

Simon

[Brian (Geek)]

Simonr said:

What was the state prior to this, and what exactly is "state 1"?

I meant thread device gets into  "OT_DEVICE_ROLE_DETACHED" state, previously it was in in "OT_DEVICE_ROLE_CHILD" state. 

Simonr said:

If all the data arrives to the NCP correctly without any corruptions, I don't see why it would be an issue on the NCP side of the application, since the SED is the side that is having trouble as far as I can tell.

Okay.   

Simonr said:

Do you see any kind of error when this state change occurs.

At the Info level i don't see any sort of error, it just changes is state and reconnect back to thread network in 2-3 seconds. 

Simonr said:

Can you check whether this state change always happens after a set amount of time, this might be some timer trigging somewhere between 10 and 15 minutes that requires it to stop transmitting, perhaps that it needs to update its status to the network for example

Yes this happen every time but the time duration is not specific. Sometimes it happens after hours, sometimes after 30-40 minutes. 

Simonr said:

A sniffer trace of this occurring might be helpful to narrow down what happens exactly. You can use an nRF52840 DK or Dongle and the nRF Sniffer for 802.15.4 to do this.

Below is the Sniffer trace of the issue which i am facing. In the sniffer trace, the issue arises  between  time slot of 16:43:20 (packet no: 3318)  -  16:44:00 (packet no: 39666). There is no communication after time 16:43:24.125260 (packet number: 38879).

Here is sniffer capture:

Parameters used Channel: 11 PAN ID: 0xABCD , masterkey: 00112233445566778899aabbccddeeff

 

SED_State_Disabled1.pcapng

Hopefully you can find issue out of this ?

[Brian (Geek)]

anyone there ?

[Simonr]

Hi

Sorry about the late reply. Unfortunately we haven't been able to track down what causes this from your sniffer trace, since it seems like the end device still transmits data to the parent after packet 38879 as well, just not the data you've set it up to transmit, right? 

Would you be able to provide device logs, preferably with increased log level, as that will likely help us see what exactly is going on on the SED application's side?

Best regards,

Simon

[Brian (Geek)]

Simonr said:

it seems like the end device still transmits data to the parent after packet 38879 as well, just not the data you've set it up to transmit, right? 

My end device is transmitting at data rate of 100ms with the help of hardware timer interrupt triggering at 100 ms. When my device gets disabled suddenly (i.e thread state 1), I am executing timer stop function to stop publishing data at 100 ms. So I thought the packets which are getting transmitted (after 38879) could be of re-transmission attempt from mqtt-sn protocol, but that also shouldn't happen because I can see my device state as 1 (disabled) at that point of time as well. 

Simonr said:

Would you be able to provide device logs, preferably with increased log level, as that will likely help us see what exactly is going on on the SED application's side?

My firmware are using multiple peripherals like CLI (thread cmd), QSPI (external flash), SAADC (voltage measurement), TWI (sensor), Hardware Timers (send data at 100ms ), App Timers (3-4 single shot app timers and 2 repeated app timer for maintaining the state machine) and also library such as CJSON to parse the received payload. Can any one of this peripheral create issue ? 

I will try to provide logs but it's difficult to capture logs even at Log level  set to INFO as it goes too fast due to my transmission speed. But will try again to capture that. 

Basic info level log that I can see -

- MQTTSN publish getting acknowledged

- Suddenly thread device state changes to 1 (reason unknown).

- Device continue to publish although it should stop but it doesn't again reason unknown. (as device state is disabled and also I am stopping hardware timer if Thread device state is less than Child state). 

- Than after few 4_5 seconds I get error of memory, can't allocate memory for OT Message returned from otUDPNewMessage function. 

Above is the exact sequence of events I get at info level. But I will try to capture more logs at debug level of I could.