nRF9160 wakeup from RRC idle on incoming traffic, but data is lost

[Stephan Walter]

We are using the nRF9160 with firmware 1.3.6 to establish a DTLS connection to a server, using the Zephyr TLS stack.

The following problem occurs quite frequently: After some idle time, the modem will enter RRC idle and signal this with +CSCON: 0. If the server now sends data, the modem will wake up from RRC idle, but we don't actually receive the packet.

Such a case is documented here and in the attached files.

Packet trace on the server (server has local IP 172.18.16.75): /cfs-file/__key/communityserver-discussions-components-files/4/0284.trace0_2D00_server.pcapng

Packet #30 is an uplink packet from the nRF91 to the server. The server then tries to send data to the client (packets #31-#34). The modem wakes up for each of them, but no data is received:

10:11:11,633	+CSCON: 0
10:11:16,796	+CSCON: 1
10:11:20,263	+CSCON: 0
10:11:22,236	+CSCON: 1
10:11:25,596	+CSCON: 0
10:11:27,996	+CSCON: 1
10:11:33,560	+CSCON: 0
10:11:36,956	+CSCON: 1

At 10:11:38, packet #35 is finally received by the client and a response is sent to the server. This indicates that the connection remained active in the software stack and also in any middleware (NAT etc.).

Modem trace: /cfs-file/__key/communityserver-discussions-components-files/4/1754.trace0.bin The modem trace starts with packet #30 at 10:11:08.

We are aware that being layered on top of UDP, DTLS packets are not guaranteed to be delivered. But the packet loss is so frequent and severe that we suspect some problem in the interaction between modem and LTE-M network.

[Samruddhi Jadhav]

Hi Stephan,

I have discussed internally with the team about this and have some feedback here from them. It would also be great if you could confirm what kind of sw component you are using in your app and also what type of application protocol you are using as it would be helpful to have logs from this. For example, also coap client dbg logs if you are using that. 

Best Regards,

Samruddhi

[Stephan Walter]

Hi Samruddhi,

We are using a custom protocol inside of DTLS with pre-shared keys. We use mbedTLS integrated into Zephyr, not the nRF91's TLS stack. The packets are typically rather short (1 to 200 bytes but sometimes more). The attached file trace0-server.pcapng shows the encrypted traffic. I cannot give you the key for this instance, but I could repeat the test with a different key if that would help. Is there reason to assume that the use of encryption has any influence on the behaviour we observe? I would expect not.

Time-outs and retries are done at the application level, but if several consecutive packets are lost as we see here, we run out of retry attempts.

Did the modem team give any specific information?

To answer Achim's questions: The IP address recorded on the server simply are on a private network. Apart from the NAT mechanism, I'm not aware of any peculiarities like a VPN, but I must admit I don't know the topology on the server side exactly. In this case, eDRX was not active but we do enable in in the case when GPS reception is also used.

[Achim Kraus]

Not that sure, but if an (unintended/unaware) ip-addr/port change happens, and the modem uses 

connect(fd, &dest, sizeof(dest);

then that may drop/filter UDP messages.

[Simon D-M]

Hi Stephan,

Sorry, I'm not coming back with an answer yet, but instead I have more questions...

What version of NCS is your firmware based on?

Can you please do another attempt with MBedTLS logging enabled?

It should more or less look something like this (depending on your NCS version) :

CONFIG_MBEDTLS_DEBUG=y
CONFIG_MBEDTLS_SSL_DEBUG_ALL=y
CONFIG_MBEDTLS_LOG_LEVEL_DBG=y
CONFIG_MBEDTLS_DEBUG_C=y
CONFIG_MBEDTLS_DEBUG_LEVEL=4

MBedTLS logs are quite big, you may need to increase the log buffer size:

CONFIG_LOG_MODE_DEFERRED=y
CONFIG_LOG_BUFFER_SIZE=2048

If you can enable logging from your custom protocol it would be nice too (at least some indications about if data is going out from the app level).

And finally, if you are able to enable the full modem trace it would be also better. Your current modem log is quite limited. You can enable it using this KConfig:

CONFIG_NRF_MODEM_LIB_TRACE_LEVEL_FULL=y

Best regards,

Simon

[Stephan Walter]

Hi Simon,

I was unable to reproduce the issue with mbedTLS logging enabled. There seemed to be too much of a slowdown, so that the DTLS handshake would fail.

I did however enable full modem tracing and was able to record cases in which 3 consecutive packets were lost. While UDP has no reliability guarantee, the ARQ mechanism in LTE should help in my opinion. As seen before, the modem would wake up (+CSCON 1/0) exactly the same number of times as the number of expected packets, but no data seems to be incoming.

In packet trace recorded on the server (trace1-server.pcapng), packets 183, 184 and 185 starting from 14:41:03 are lost.

trace1.zip

Unfortunately when opening the trace in Wireshark from the Cellular Monitor tool, only 11 trace packets show up despite the binary file containing over 400 trace events. I don't know what's going on there.

Best regards,
--Stephan Walter

[Simon D-M]

Hi Stephan,

From the trace we can see that your device indeed connect to the network, entering RCC connected mode, and that the data radio bearer is set up, but the network doesn't deliver any IP data, thus releasing the RRC connection a few seconds later.

This matches the +CSCON notification you reported.

I would recommend you checking this further with the network provider directly as we can't really see more than this from the device perspective...

Best regards,

Simon