AWS IoT library socket disconnection after one minute

[Dominic]

Been scratching my head over this one for a few hours..

I am testing out the AWS IoT library in version 1.3.1 of nrf Connect SDK. Connect, subscribe, and ping are all working correctly as evidenced by the logs. However, after one minute the socket connection always closes. In this example I have the keep-alive interval set to 20s to show successful PING and PINGRESP messages but this happens regardless of the configured keep-alive internal.

*** Booting Zephyr OS build v2.3.0-rc1-ncs1 ***
Application Started
modem_key_mgmt_delete(1, 0) => result=0
modem_key_mgmt_delete(1, 1) => result=0
modem_key_mgmt_delete(1, 2) => result=0
modem_key_mgmt_write => result=0
modem_key_mgmt_write => result=0
modem_key_mgmt_write => result=0
LTE Link Connecting ...
LTE Link Connected!
[00:00:24.241,455] <dbg> aws_iot.broker_init: IPv4 Address found 18.219.99.192
[00:00:28.221,923] <dbg> aws_iot.mqtt_evt_handler: MQTT client connected!
[00:00:28.229,492] <dbg> aws_iot.topic_subscribe: Subscribing to application topic: test
AWS IoT connected
AWS IoT ready
[00:00:28.541,900] <dbg> aws_iot.mqtt_evt_handler: MQTT_EVT_SUBACK: id = 7520 result = 0
Pinging broker
[00:00:48.237,060] <dbg> aws_iot.mqtt_evt_handler: MQTT_EVT_PINGRESP: result = 0
Pinging broker
[00:01:07.919,677] <dbg> aws_iot.mqtt_evt_handler: MQTT_EVT_PINGRESP: result = 0
[00:01:26.500,427] <dbg> aws_iot.mqtt_evt_handler: MQTT_EVT_DISCONNECT: result = -128
AWS IoT disconnected
Socket error: POLLNVAL
The AWS IoT socket was unexpectedly closed.

 

Cloudwatch logs show nothing more than a successful connect and disconnect:

EVENT:MQTT Client Connect MESSAGE: IpAddress: <redacted> SourcePort: 61993
EVENT:MQTT Client Disconnect MESSAGE: IpAddress: <redacted> SourcePort: 61993

The polling thread option has not been added in v1.3.1 but I am running a similar thread in main.c

#define AWS_IOT_POLL_TIMEOUT_MS 500

struct pollfd fds[] = {

        {.fd = aws_config->socket,

         .events = POLLIN}};

    while (true)

    {

        err = poll(fds, ARRAY_SIZE(fds), AWS_IOT_POLL_TIMEOUT_MS);

        if (err == 0)

        {

            if (aws_iot_keepalive_time_left() < AWS_IOT_POLL_TIMEOUT_MS)

            {

                aws_iot_ping();

                printk("Pinging broker\n");

            }

            continue;

        }

        if ((fds[0].revents & POLLIN) == POLLIN)

        {

            aws_iot_input();

            continue;

        }

        if ((fds[0].revents & POLLNVAL) == POLLNVAL)

        {

            printk("Socket error: POLLNVAL\n");

            printk("The AWS IoT socket was unexpectedly closed.\n");

            return;

        }

        if ((fds[0].revents & POLLHUP) == POLLHUP)

        {

            printk("Socket error: POLLHUP\n");

            printk("Connection was closed by the AWS IoT broker.\n");

            return;

        }

        if ((fds[0].revents & POLLERR) == POLLERR)

        {

            printk("Socket error: POLLERR\n");

            printk("AWS IoT broker connection was unexpectedly closed.\n");

            return;

        }

    }

Anyone have some ideas what it could be? Thanks!

[Sigurd]

Hi,

I am testing out the AWS IoT library in version 1.3.1 of nrf Connect SDK

 There has been a lot of work done to the AWS IoT library since v1.3.x,  there is now also a dedicated aws_iot sample for this library on the master branch.

Please test with the master branch, and see if that solves the issue. I also recommend testing with the latest modem firmware, v.1.2.1

[Dominic]

Today I updated the modem firmare to v1.2.1 and tried running the aws iot example from the master branch, neither solved the issue. I did notice that the modem was switching between RRC idle and connected modes a few times so I decreased the keep-alive interval to keep the connection open. This also did not fix the issue. It is always 60 seconds between broker connection and disconnection.

*** Booting Zephyr OS build v2.3.0-rc1-ncs1-2409-g81abf77417fd  ***
[00:00:00.000,305] <err> board_nonsecure: AT socket could not be opened
[00:00:00.000,579] <err> board_nonsecure: thingy91_magpio_configure failed with error: -14
The AWS IoT sample started, version: v1.0.0
LTE cell changed: Cell ID: 30512907, Tracking area: 11651
PSM parameter update: TAU: -1, Active time: -1
RRC mode: Connected
Network registration status: Connected - roaming
DATE_TIME_OBTAINED_MODEM
AWS_IOT_EVT_CONNECTING
[00:00:05.418,365] <dbg> aws_iot.broker_init: IPv4 Address found 13.58.33.200
[00:00:09.063,110] <dbg> aws_iot.aws_iot_cloud_poll: AWS broker connection request sent.
[00:00:09.405,792] <inf> aws_fota: Created notify_next_topic $aws/things/nrf91-test/jobs/notify-next
[00:00:09.406,188] <inf> aws_fota: Created get_topic $aws/things/nrf91-test/jobs/$next/get/#
[00:00:09.406,494] <inf> aws_fota: previously subscribed to notify-next topic
[00:00:09.406,860] <inf> aws_jobs: Publish topic: $aws/things/nrf91-test/jobs/$next/get
[00:00:09.407,165] <inf> aws_jobs: Publish payload {"clientToken": ""}
[00:00:09.454,223] <dbg> aws_iot.mqtt_evt_handler: MQTT client connected!
AWS_IOT_EVT_CONNECTED
Persistent session enabled
Publishing: {
                "state":        {
                                                "reported":     {
                                                                                        "app_version":  "v1.0.0",
                                                                                                                                        "batv": 4093,
                                                                                                                                                                        "ts":   1600447218196
                                                                                                                                                                                                        }
                                                                                                                                                                                                                }
                                                                                                                                                                                                                 } to AWS IoT broker
[00:00:09.502,716] <dbg> aws_iot.aws_iot_send: Publishing to topic: $aws/things/nrf91-test/shadow/update
AWS_IOT_EVT_READY
[00:00:09.601,654] <dbg> aws_iot.mqtt_evt_handler: MQTT_EVT_PUBACK: id = 4244 result = 0
[00:00:09.610,595] <inf> aws_fota: Checking for an available job
[00:00:09.611,145] <inf> aws_fota: No queued jobs for this device
[00:01:05.726,165] <dbg> aws_iot.mqtt_evt_handler: MQTT_EVT_DISCONNECT: result = -128
AWS_IOT_EVT_DISCONNECTED
[00:01:06.226,623] <dbg> aws_iot.aws_iot_cloud_poll: Socket error: POLLNVAL
[00:01:06.226,867] <dbg> aws_iot.aws_iot_cloud_poll: The cloud socket was unexpectedly closed.
AWS_IOT_EVT_DISCONNECTED
RRC mode: Idle
RRC mode: Connected
Network registration status: Connected - roaming
RRC mode: Idle

[Dominic]

Switched from the included iBasis SIM to a Bell SIM and the problem disappears so it appears to be something at the carrier level. Will not be troubleshooting this any further for the time being.