We have a product in the field using the NRF9160 and AWS IOT MQTT from NRF Connect SDK 3.1.1. It is always connected when awake (power cycle controlled by an external micro) and sends heartbeat messages once a minute as well as other application traffic. We find that after several days of operation without going to sleep it will go into a mode where application content and heartbeat messages stop being received at all. The only thing we see at this point is MQTT Connect and Disconnects every KEEPALIVE timeout which is 20 minutes. This persists through multiple ip address changes and can last for 18 hours+. Eventually we see an AWS broker timeout (KEEPALIVE * 1.5) and we never see another MQTT connect. Interestingly if we go into our carrier's portal we can see that even after days in this state there is still an active PDP context. A power cycle resolves the issue.
When looking at AWS CloudWatch logs for a unit in question querying:
results in:
This reads to me as:
- During the initial issue, mqtt_helper is getting stuck in the connecting state by never receiving it's CONN_ACK but, at a low level, not just missing receiving the event.
- Given that this is TCP and the session remains active after the CONN_ACK is sent, the data must be being delivered to the modem core itself but that data must not propagate to the zephyr IP stack or perhaps up the chain to the MQTT stack.
- Also it happens 20+ times in a row so it's not likely a one off, just missed the response issue (despite that not really being possible due to TCP).
- If we just missed receiving the conn_ack and no application traffic would be passed because we are still just in the connecting phase I'd expect a ping to go out but the ping must be failing. Aborting in the mqtt_helper_poll_loop after the ret = mqtt_live(&mqtt_client);
- This should explain the 20 minute target initiated disconnects (see attached picture)
- The NRF9160 must still be on and running it's L4 reconnects or we wouldn't have PDP context with the sim days afterwards but some how the MQTT library or it's callers are getting totally locked up.
Actual Root Cause:
- Is it possible for the modem to lose it's RX IPC state with the application core?
- Seems like there would be too much missing for it to be lost in it's entirety and we would stop getting L4 reconnects or even MQTT connections. TX must be possible or we wouldn't even get MQTT connects which imply pretty high level operation.
- Modem core memory leak
- We have an issue with very frequent BIP events where the modem core "forgets" it's replying to a CFUN command (issued by zephyr conn_mgr automatically) which we've resolved by setting this: nrf_modem_at_sem_timeout_set(MODEM_AT_SEM_TIMEOUT_MS). I do wonder given the odd nature of having the modem core just stop replying to a CFUN command if we are causing memory leaks in the core by just timing out our command and, if we are having several timeouts in a session maybe they build up and cause the issue.
Relevant modules and configurations:
NRF Connect SDK 3.1.1
- nrf_modem_lib / modem firmware socket offload
CONFIG_NRF_MODEM_LIB, CONFIG_NRF_MODEM_LIB_NET_IF, CONFIG_NET_SOCKETS_OFFLOAD
- Zephyr networking beneath the offloaded socket
CONFIG_DNS_RESOLVER, CONFIG_NET_SOCKETS.
- Zephyr MQTT client
- NCS mqtt_helper
- NCS aws_iot library
- LTE Link Control
CONFIG_LTE_LINK_CONTROL
- Zephyr Connection Manager
Anyways thanks for any time or thoughts you guys have on the matter.
Thanks,
Nick