Receiving MQTT Shadow Data before NRF_CLOUD_EVT_READY

[egood]

Hello,

I'm currently debugging an issue we are having with MQTT device shadow interaction on the nrf9160. The issue presents when we push a large amount of config JSON to the device shadow. This typically happens when we are setting up a new device for the first time and need to set all the parameters in the "config" object via the REST API. The issue is when this large delta occurs the device will try and sync it via MQTT and it gets stuck in a connect/disconnect loop. 

I'm currently looking at once specific case that I can get to repeat multiple times. Where the following events occur in sequence:

1. NRF_CLOUD_EVT_TRANSPORT_CONNECTED occurs 

2. NRF_CLOUD_EVT_RX_DATA_SHADOW occurs with the large delta (in my case about 1.3Kb)

3.  NRF_CLOUD_EVT_USER_ASSOCIATED occurs

4.  NRF_CLOUD_EVT_TRANSPORT_DISCONNECTED occurs for reason  -> NRF_CLOUD_DISCONNECT_MISC

5. The LTE connection is reset (not a reboot) and it attempts to connect again and goes through the same sequence.

Now the device never gets a chance to send the shadow delta back up to the cloud because our firmware waits until NRF_CLOUD_EVT_READY before we send any data back to nrfCloud. And because we don't acknowledge the shadow delta it gets sent again the next time we connect, resulting in an endless loop.  

The question that comes to mind is why we are getting shadow data before receiving, NRF_CLOUD_EVT_READY? The documentation here seems to imply this shouldn't happen?

Any insight on how to debug this further would be greatly appreciated.

Thanks!

[Charlie]

Hi Eric,

This issue seems to happen before you push a large amount of config JSON to the device shadow.

Are you able to repeat the issue with other official nRF Cloud samples like Cellular: nRF Cloud multi-service?

Best regards,

Charlie

[egood]

Charlie,

Our code is based on the nRF Cloud MQTT multi-service sample (from SDK v2.4.2) and has basically the same core connection management. I also attempted loading the unmodified sample onto the same hardware in question above and got basically the same results see below logs:

 - - - - - - - - - - - - - - - - TARGET RESET - - - - - - - - - - - - - - - - -
*** Booting Zephyr OS build v3.3.99-ncs1-1 ***
[00:00:00.250,946] \033[0m<dbg> led_control: start_led_pattern: LED Pattern Requested\033[0m
[00:00:00.250,976] \033[0m<inf> connection: Setting up modem...\033[0m
[00:00:10.185,699] \033[0m<inf> main: nRF Cloud MQTT multi-service sample has started.\033[0m
[00:00:10.185,729] \033[0m<dbg> connection: await_lte_connection: Awaiting LTE Connection\033[0m
[00:00:10.185,791] \033[0m<dbg> led_control: led_animation_thread_fn: LED Management Started\033[0m
[00:00:10.185,791] \033[0m<dbg> led_control: led_animation_thread_fn: LED Pattern Started\033[0m
[00:00:10.185,882] \033[0m<dbg> connection: consume_device_message: Consuming an enqueued device message\033[0m
[00:00:10.199,737] \033[0m<dbg> connection: setup_modem: Modem library initialized.\033[0m
[00:00:10.199,737] \033[0m<inf> connection: Setting up nRF Cloud library...\033[0m
[00:00:10.207,855] \033[0m<inf> connection: Setting up LTE...\033[0m
[00:00:10.208,557] \033[0m<inf> connection: Starting connection to LTE network...\033[0m
[00:00:10.257,537] \033[0m<inf> connection: Connecting to LTE network. This may take several minutes...\033[0m
[00:00:10.257,537] \033[0m<inf> connection: Waiting for connection to LTE network...\033[0m
[00:00:10.257,568] \033[0m<dbg> led_control: start_led_pattern: LED Pattern Requested\033[0m
[00:00:10.257,598] \033[0m<dbg> connection: await_lte_connection: Awaiting LTE Connection\033[0m
[00:00:11.645,507] \033[0m<dbg> connection: lte_event_handler: LTE_EVENT: Network registration status 2, Searching\033[0m
[00:00:11.645,568] \033[0m<dbg> connection: lte_event_handler: LTE_EVENT: LTE cell changed: Cell ID: 118021391, Tracking area: 24838\033[0m
[00:00:11.645,629] \033[0m<dbg> connection: lte_event_handler: LTE_EVENT: Active LTE mode changed: LTE-M\033[0m
[00:00:16.202,575] \033[0m<dbg> connection: lte_event_handler: LTE_EVENT: RRC mode: Connected\033[0m
[00:00:18.461,151] \033[0m<dbg> connection: lte_event_handler: LTE_EVENT: Modem domain event, type: Search done\033[0m
[00:00:18.466,369] \033[0m<dbg> connection: lte_event_handler: LTE_EVENT: Network registration status 5, Registered Roaming\033[0m
[00:00:18.466,705] \033[0m<inf> connection: Connected to LTE network\033[0m
[00:00:18.466,735] \033[0m<inf> connection: Connecting to nRF Cloud...\033[0m
[00:00:18.466,735] \033[0m<inf> connection: Next connection retry in 30 seconds\033[0m
[00:00:18.466,766] \033[0m<dbg> connection: await_cloud_connected: Awaiting Cloud Connection\033[0m
[00:00:18.466,827] \033[0m<dbg> connection: await_cloud_ready: Awaiting Cloud Ready\033[0m
[00:00:18.466,857] \033[0m<dbg> connection: cloud_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING\033[0m
[00:00:18.567,382] \033[0m<dbg> connection: lte_event_handler: LTE_EVENT: PSM parameter update: TAU: 3240, Active time: -1\033[0m
[00:00:18.570,678] \033[0m<dbg> connection: await_cloud_ready: Awaiting Cloud Ready\033[0m
[00:00:23.246,063] \033[1;31m<err> nrf_cloud_transport: MQTT input error: -128\033[0m
[00:00:23.246,154] \033[1;31m<err> nrf_cloud_transport: Error disconnecting from cloud: -128\033[0m
[00:00:23.246,185] \033[0m<dbg> connection: cloud_event_handler: NRF_CLOUD_EVT_TRANSPORT_DISCONNECTED\033[0m
[00:00:23.246,215] \033[0m<inf> connection: nRF Cloud failed to become ready. Resetting connection.\033[0m
[00:00:23.246,246] \033[0m<inf> connection: Disconnecting from nRF Cloud\033[0m
[

[Charlie]

But this log shows your device is not connected with the nRF Cloud at all.

Have you correctly provisioned your device to nRF Cloud?  There is guidance about nRF Cloud Access Provisioning - Software and Protocols - Cellular IoT guides - Nordic DevZone (nordicsemi.com). You need to follow the flowchart "Own CA" branch for your product.

Best regards,

Charlie

[egood]

Charlie,

This device is provisioned. It was connecting to nrfCloud and functioning fine prior to us pushing the update to the shadow via MQTT. As I mentioned this i a very repeatable issue and I have done it on multiple devices that have been provisioned and working correctly prior to pushing the config update to REST. 

Additionally, on our custom firmware as mentioned in the first post we are getting the shadow JSON that we pushed to the device we just never get the NRF_CLOUD_EVT_READY event and therefor don't process the shadow JSON. I imagine it wouldn't be possible to get the shadow for the device if it wasn't provisioned correctly on the cloud.  

Eric

[egood]

Charlie,

Here is a log from the exact same device running our custom firmware (I loaded it again after running the MQTT sample mentioned above), note I have not changed the state of nrfCloud (shadow) or the device certs between firmware loads.

You can can see that we get shadow data before receiving the NRF_CLOUD_EVT_READY event. We simply get NRF_CLOUD_EVT_TRANSPORT_DISCONNECTED occurs for reason - NRF_CLOUD_DISCONNECT_MISC (3)

[egood]

Any update on this? This is preventing us from releasing our MQTT firmware.  

[Charlie]

Hi Eric,

Sorry for the late reply. I was occupied by other tasks last week. I will try to help you solve the issue this week if possible.

I have tried to reproduce this issue with  Cellular: nRF Cloud multi-service today. NRF_CLOUD_EVT_RX_DATA_SHADOW indeed happens before NRF_CLOUD_EVT_USER_ASSOCIATED, but I did not see anything that prevents NRF_CLOUD_EVT_READY happening.
Is it possible that some configuration from your JSON file disturbed the cloud connecting process? Could you share more detailed information to help me reproduce your failing test with nRF Cloud multi-service before?

[00:00:02.223,602] <inf> connection: Connecting to nRF Cloud...
[00:00:02.223,602] <inf> connection: Next connection retry in 30 seconds
[00:00:02.223,632] <dbg> connection: await_cloud_connected: Awaiting Cloud Connection
[00:00:02.223,724] <dbg> connection: await_cloud_ready: Awaiting Cloud Ready
[00:00:02.223,754] <dbg> connection: cloud_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING
[00:00:02.224,639] <dbg> connection: lte_event_handler: LTE_EVENT: PSM parameter update: TAU: 9000, Active time: -1
[00:00:02.227,905] <dbg> connection: await_cloud_ready: Awaiting Cloud Ready
[00:00:04.647,521] <dbg> connection: cloud_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTED
[00:00:05.166,015] <inf> nrf_cloud_codec_internal: AlertsEn changed to 0
[00:00:05.166,015] <inf> nrf_cloud_codec_internal: LogLvl changed to 1
[00:00:05.167,724] <dbg> connection: cloud_event_handler: NRF_CLOUD_EVT_RX_DATA_SHADOW
[00:00:05.212,036] <dbg> connection: cloud_event_handler: NRF_CLOUD_EVT_USER_ASSOCIATED
[00:00:05.806,671] <dbg> connection: cloud_event_handler: NRF_CLOUD_EVT_READY
[00:00:05.806,732] <inf> connection: Connected to nRF Cloud
[00:00:05.807,525] <inf> application: Waiting for modem to determine current date and time
[00:00:05.807,556] <inf> application: Current date and time determined

Best regards,

Charlie

[egood]

Charlie,

The issue only happens when a large chunk of JSON is posted to the shadow via the REST API. As mentioned in the first post it's about 1.3KB of data that gets sent. 

I can send you the JSON from our config object in a private message or you can reach out to me via email, if you want to test it on your device to reproduce my exact issue. However, I suspect it may have to do with the size of the update we are trying to make. 

Another thing I will note is that this issue is made worse when you attempt to clean out the shadow by sending "config":null via the REST API because the device still has not be able to acknowledge the large config object write, so now two shadow updates are queued. The only way I have found to "reset" the shadow and clear the issue is to delete the device from nrfCloud and then re-add with new keys. 

Eric

[egood]

Charlie,

I have reproduced the issue on the out of box example for nrfCloud multi-service on the nrf9160-DK:

nrfConnect SDK: v2.5.0

modem FW: v1.3.5

Build Config: nrf9160dk_nrf9160_ns, optimized for size (-Os) 

The only changes to the example were to prj.conf so I could see logs from the nrf_cloud module in detail and capture the logs.

# Added for debugging
CONFIG_USE_SEGGER_RTT=y
CONFIG_LOG_BACKEND_RTT=y
CONFIG_NRF_CLOUD_LOG_LEVEL_DBG=y

Here is what I did:

1. Loaded example and let it boot and run normally. 

2. Once it was connected and running normally I sent a large chunk of JSON to the config section of the shadow via the nrfCloud REST APIs. I did this via Postman. The command sent is here:

curl --location --request PATCH 'https://api.nrfcloud.com/v1/devices/nrf-XXXXXXXXXXXXXXX/state' \
--header 'Content-Type: application/json' \
--header 'Authorization: Bearer XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX' \
--data '{
    "desired": {
        "config": { 
            "cloud": { 
                "cloudEnv": "mqttStage", 
                "accountId": "AXXXX", 
                "farmId": "FXXXX", 
                "deviceId": "VXXXX", 
                "msgActPer_sec": 120, 
                "msgIdlPer_sec": 600 
            },
            "devType":0, 
            "sensorSampInterval_ms": 1000, 
            "currentLoops": [ 
                {
                    "i": 0, 
                    "en": 1, 
                    "type": 0, 
                    "a": 0, 
                    "m": 0.001, 
                    "b": 0.0, 
                    "units": "mA" 
                },
                {
                    "i": 1,
                    "en": 1,
                    "type": 0,
                    "a": 0,
                    "m": 0.001,
                    "b": 0.0,
                    "units": "mA"
                }
            ],
            "voltSensors": [ 
                {
                    "i": 0, 
                    "en": 0, 
                    "type": 0, 
                    "a": 0.0, 
                    "m": 0.0, 
                    "b": 0.0, 
                    "units": "none" 
                }
            ],
            "flowSensors": [ 
                {
                    "i": 0, 
                    "en": 0, 
                    "sampPer_ms": 1000, 
                    "m": 1.0, 
                    "b": 0.0, 
                    "units": "none", 
                    "maxR": 0.0, 
                    "minR": 0.0, 
                    "accType": 1, 
                    "accPerc": 1.0 
                },
                {
                    "i": 1,
                    "en": 0,
                    "sampPer_ms": 1000,
                    "m": 0.0,
                    "b": 0.0,
                    "units": "none",
                    "maxR": 0.0,
                    "minR": 0.0,
                    "accType": 0,
                    "accPerc": 0.0
                }
            ],
            "valves": [ 
                {
                    "i": 0, 
                    "en": 1, 
                    "type": 2, 
                    "pw_ms": 1000, 
                    "timeout_ms": 60000 
                }
            ],
            "irrigation": { 
                "flowI": 0, 
                "relayMirror": 1 
            }
        }
    }
}'

In the below logs you can see the system running normally until [00:03:18.845,397] where we get POLLERR from nrf_cloud. This is the same error I get from the nrfCloud module on our custom firmware after writing the JSON. The full log for the described session below:

*** Booting nRF Connect SDK v2.5.0 ***
[00:00:16.729,492] <inf> main: nRF Cloud multi-service sample has started, version: 1.0.0, protocol: MQTT
[00:00:16.729,553] <inf> cloud_connection: Setting up nRF Cloud library...
[00:00:16.923,736] <dbg> nrf_cloud_transport: nct_client_id_set: client_id = nrf-350457790695389
[00:00:16.924,194] <dbg> nrf_cloud_transport: nct_topics_populate: accepted_topic: nrf-350457790695389/shadow/get/accepted
[00:00:16.924,255] <dbg> nrf_cloud_transport: nct_topics_populate: rejected_topic: $aws/things/nrf-350457790695389/shadow/get/rejected
[00:00:16.924,285] <dbg> nrf_cloud_transport: nct_topics_populate: update_delta_topic: $aws/things/nrf-350457790695389/shadow/update/delta
[00:00:16.924,346] <dbg> nrf_cloud_transport: nct_topics_populate: update_topic: $aws/things/nrf-350457790695389/shadow/update
[00:00:16.924,377] <dbg> nrf_cloud_transport: nct_topics_populate: shadow_get_topic: $aws/things/nrf-350457790695389/shadow/get
[00:00:16.924,438] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 1
[00:00:16.924,468] <inf> cloud_connection: Waiting for network ready...
+CEREG: 2,"6106","07094711",7
+CSCON: 1
+CGEV: ME PDN ACT 0,0
+CNEC_ESM: 50,0
+CEREG: 5,"6106","07094711",7,,,"00011110","11100000"
[00:00:24.753,906] <inf> cloud_connection: Network connectivity gained!
%XTIME: "0A","4230811291810A","01"
[00:00:25.754,028] <inf> cloud_connection: Network is ready
[00:00:25.754,058] <inf> cloud_connection: Connecting to nRF Cloud
[00:00:25.754,089] <inf> cloud_connection: Connected to nRF Cloud
[00:00:25.754,150] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 1
[00:00:26.086,883] <dbg> nrf_cloud_transport: nct_connect: IPv4 address: 52.7.128.187
[00:00:26.086,914] <dbg> nrf_cloud_transport: nct_mqtt_connect: MQTT clean session flag: 1
[00:00:28.799,072] <dbg> nrf_cloud: nrf_cloud_run: Cloud connection request sent
[00:00:29.161,010] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_CONNACK: result 0
[00:00:29.161,041] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 2
[00:00:29.161,071] <dbg> nrf_cloud_transport: nct_cc_connect: nct_cc_connect
[00:00:29.162,078] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 3
[00:00:29.488,952] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_SUBACK: id = 100 result = 0
[00:00:29.488,983] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 4
[00:00:29.489,074] <dbg> nrf_cloud_transport: nct_cc_send: mqtt_publish: id = 200 opcode = 0 len = 0, topic: $aws/things/nrf-350457790695389/shadow/get
[00:00:29.489,959] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 5
[00:00:29.851,013] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 200 result = 0
[00:00:29.851,043] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 5
[00:00:29.994,232] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 16684 len = 544, topic = nrf-350457790695389/shadow/get/accepted
[00:00:29.994,537] <dbg> nrf_cloud_fsm: cc_rx_data_handler: CC RX on topic nrf-350457790695389/shadow/get/accepted: {"desired":{"pairing":{"state":"paired","topics":{"d2c":"prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/d2c","c2d":"prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/+/r"}},"nrfcloud_mqtt_topic_prefix":"prod/08e77791-23c4-4c38-982c-4097624a1789/","control":{"logLvl":3}},"reported":{"control":{"alertsEn":true,"logLvl":3}},"config":{"activeMode":true,"locationTimeout":300,"activeWaitTime":120,"movementResolution":120,"movementTimeout":3600,"accThreshAct":4,"accThreshInact":4,"accTimeoutInact":60,"nod":[]}}
[00:00:29.996,063] <dbg> nrf_cloud_codec_internal: nrf_cloud_shadow_control_decode: Control inside of desired
[00:00:29.996,063] <dbg> nrf_cloud_codec_internal: nrf_cloud_shadow_control_decode: alertsEn not found
[00:00:29.996,215] <dbg> nrf_cloud_codec_internal: nrf_cloud_shadow_control_decode: No response needed. Got shadow: {"desired":{"pairing":{"state":"paired","topics":{"d2c":"prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/d2c","c2d":"prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/+/r"}},"nrfcloud_mqtt_topic_prefix":"prod/08e77791-23c4-4c38-982c-4097624a1789/","control":{"logLvl":3}},"reported":{"control":{"alertsEn":true,"logLvl":3}},"config":{"activeMode":true,"locationTimeout":300,"activeWaitTime":120,"movementResolution":120,"movementTimeout":3600,"accThreshAct":4,"accThreshInact":4,"accTimeoutInact":60,"nod":[]}}
[00:00:29.996,887] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 5
[00:00:29.999,084] <dbg> nrf_cloud_fsm: cc_rx_data_handler: New state: 7
[00:00:30.001,556] <dbg> nrf_cloud_transport: nct_dc_endpoint_set: nct_dc_endpoint_set
[00:00:30.001,922] <dbg> nrf_cloud_transport: nct_dc_endpoint_get: nct_dc_endpoint_get
[00:00:30.044,158] <dbg> nrf_cloud_transport: nct_cc_send: mqtt_publish: id = 301 opcode = 1 len = 959, topic: $aws/things/nrf-350457790695389/shadow/update
[00:00:30.249,633] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 7
[00:00:30.797,058] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 301 result = 0
[00:00:30.797,088] <dbg> nrf_cloud_transport: nct_dc_connect: nct_dc_connect
[00:00:30.797,882] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 8
[00:00:31.051,147] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_SUBACK: id = 101 result = 0
[00:00:31.051,177] <dbg> nrf_cloud_transport: nct_save_session_state: Setting session state: 1
[00:00:31.052,429] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 9
[00:00:31.054,473] <inf> application: Waiting for modem to determine current date and time
[00:00:31.054,504] <inf> application: Current date and time determined
[00:00:31.055,786] <dbg> nrf_cloud_transport: nct_cc_send: mqtt_publish: id = 1001 opcode = 1 len = 104, topic: $aws/things/nrf-350457790695389/shadow/update
[00:00:31.066,070] <inf> nrf_cloud_pgps: Storage base:0xEB000, size:86016
[00:00:31.066,955] <inf> nrf_cloud_pgps: Checking P-GPS header: Schema version:0, type:0, num:0, count:0
[00:00:31.066,986] <inf> nrf_cloud_pgps:   size:0, period (minutes):0, GPS day:0, GPS time:0
[00:00:31.067,016] <wrn> nrf_cloud_pgps: One or more fields are wrong
[00:00:31.068,115] <dbg> nrf_cloud_codec_internal: json_send_to_cloud: Created request: {"appId":"PGPS","messageType":"DATA","data":{"predictionCount":42,"predictionIntervalMinutes":240,"startGpsDay":16143,"startGpsTimeOfDaySeconds":76782}} (size: 152)
[00:00:31.070,739] <dbg> nrf_cloud_codec_internal: json_send_to_cloud: Request sent to cloud
[00:00:31.070,770] <inf> nrf_cloud_pgps: Requesting 42 predictions...
[00:00:31.108,062] <dbg> nrf_cloud_codec_internal: json_send_to_cloud: Created request: {"appId":"AGPS","messageType":"DATA","data":{"mcc":310,"mnc":410,"tac":24838,"eci":118048529,"rsrp":-100,"types":[1,9,4,5,6,7,8]}} (size: 130)
[00:00:31.109,191] <dbg> nrf_cloud_codec_internal: json_send_to_cloud: Request sent to cloud
[00:00:31.109,497] <inf> nrf_cloud_pgps: Searching for prediction
[00:00:31.109,527] <inf> nrf_cloud_pgps: Predictions not loaded yet
[00:00:31.171,356] <inf> application: Temperature is 23 degrees C
[00:00:31.298,065] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1001 result = 0
[00:00:31.314,086] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1000 result = 0
[00:00:31.482,818] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1002 result = 0
[00:00:31.491,149] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1003 result = 0
[00:00:31.763,336] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1004 result = 0
[00:00:31.828,948] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 1 len = 211, topic = prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/agps/r
[00:00:31.833,953] <dbg> nrf_cloud_fsm: agnss_process: A-GNSS data processed
[00:00:31.833,953] <inf> nrf_cloud_pgps: Searching for prediction
[00:00:31.833,984] <inf> nrf_cloud_pgps: Predictions not loaded yet
[00:00:33.833,496] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 16684 len = 58, topic = prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/pgps/r
[00:00:33.833,801] <dbg> nrf_cloud_codec_internal: nrf_cloud_pgps_response_decode: host: pgps.nrfcloud.com
[00:00:33.833,862] <dbg> nrf_cloud_codec_internal: nrf_cloud_pgps_response_decode: path: public/16143-79200_16150-64800.bin
[00:00:33.834,167] <inf> download_client: Downloading: public/16143-79200_16150-64800.bin [0]
[00:00:33.834,197] <dbg> nrf_cloud_fsm: pgps_process: P-GPS data processed
[00:00:34.045,349] <inf> download_client: Setting up TLS credentials, sec tag count 1
[00:00:34.045,471] <inf> download_client: Connecting to pgps.nrfcloud.com
[00:00:36.446,655] <inf> download_client: Downloaded 1500/84268 bytes (1%)
[00:00:36.446,685] <inf> nrf_cloud_pgps: Checking P-GPS header: Schema version:1, type:10, num:1, count:42
[00:00:36.446,716] <inf> nrf_cloud_pgps:   size:2006, period (minutes):240, GPS day:16143, GPS time:79200
[00:00:36.446,777] <inf> nrf_cloud_pgps: pgps_header: Schema version:1, type:10, num:1, count:42
[00:00:36.446,777] <inf> nrf_cloud_pgps:   size:2006, period (minutes):240, GPS day:16143, GPS time:79200
[00:00:36.898,345] <inf> download_client: Downloaded 3000/84268 bytes (3%)
[00:00:36.898,468] <inf> nrf_cloud_pgps: Storing prediction num:0 idx:0 for gps sec:1394834400
[00:00:37.290,405] <inf> download_client: Downloaded 4500/84268 bytes (5%)
[00:00:37.290,557] <inf> nrf_cloud_pgps: Storing prediction num:1 idx:1 for gps sec:1394848800
[00:00:37.422,882] <inf> nrf_cloud_pgps: Searching for prediction
[00:00:37.423,004] <inf> nrf_cloud_pgps: GPS unit needs ephemerides. Injecting 32.
[00:00:37.860,443] <inf> download_client: Downloaded 6000/84268 bytes (7%)
[00:00:38.214,111] <inf> download_client: Downloaded 7500/84268 bytes (8%)
[00:00:38.214,172] <inf> nrf_cloud_pgps: Storing prediction num:2 idx:2 for gps sec:1394863200
[00:00:38.617,462] <inf> download_client: Downloaded 9000/84268 bytes (10%)
[00:00:38.617,553] <inf> nrf_cloud_pgps: Storing prediction num:3 idx:3 for gps sec:1394877600
[00:00:39.144,500] <inf> download_client: Downloaded 10500/84268 bytes (12%)
[00:00:39.144,622] <inf> nrf_cloud_pgps: Storing prediction num:4 idx:4 for gps sec:1394892000
[00:00:39.558,441] <inf> download_client: Downloaded 12000/84268 bytes (14%)
[00:00:39.977,478] <inf> download_client: Downloaded 13500/84268 bytes (16%)
[00:00:39.977,539] <inf> nrf_cloud_pgps: Storing prediction num:5 idx:5 for gps sec:1394906400
[00:00:40.542,419] <inf> download_client: Downloaded 15000/84268 bytes (17%)
[00:00:40.542,541] <inf> nrf_cloud_pgps: Storing prediction num:6 idx:6 for gps sec:1394920800
[00:00:40.939,544] <inf> download_client: Downloaded 16500/84268 bytes (19%)
[00:00:40.939,697] <inf> nrf_cloud_pgps: Storing prediction num:7 idx:7 for gps sec:1394935200
[00:00:41.525,482] <inf> download_client: Downloaded 18000/84268 bytes (21%)
[00:00:41.915,222] <inf> download_client: Downloaded 19500/84268 bytes (23%)
[00:00:41.915,283] <inf> nrf_cloud_pgps: Storing prediction num:8 idx:8 for gps sec:1394949600
[00:00:42.247,955] <inf> download_client: Downloaded 21000/84268 bytes (24%)
[00:00:42.248,046] <inf> nrf_cloud_pgps: Storing prediction num:9 idx:9 for gps sec:1394964000
[00:00:42.723,510] <inf> download_client: Downloaded 22500/84268 bytes (26%)
[00:00:42.723,663] <inf> nrf_cloud_pgps: Storing prediction num:10 idx:10 for gps sec:1394978400
[00:00:43.123,901] <inf> download_client: Downloaded 24000/84268 bytes (28%)
[00:00:43.655,517] <inf> download_client: Downloaded 25500/84268 bytes (30%)
[00:00:43.655,578] <inf> nrf_cloud_pgps: Storing prediction num:11 idx:11 for gps sec:1394992800
[00:00:44.235,534] <inf> download_client: Downloaded 27000/84268 bytes (32%)
[00:00:44.235,656] <inf> nrf_cloud_pgps: Storing prediction num:12 idx:12 for gps sec:1395007200
[00:00:44.599,914] <inf> download_client: Downloaded 28500/84268 bytes (33%)
[00:00:44.600,067] <inf> nrf_cloud_pgps: Storing prediction num:13 idx:13 for gps sec:1395021600
[00:00:45.159,912] <inf> download_client: Downloaded 30000/84268 bytes (35%)
[00:00:45.610,595] <inf> download_client: Downloaded 31500/84268 bytes (37%)
[00:00:45.610,687] <inf> nrf_cloud_pgps: Storing prediction num:14 idx:14 for gps sec:1395036000
[00:00:45.988,739] <inf> download_client: Downloaded 33000/84268 bytes (39%)
[00:00:45.988,830] <inf> nrf_cloud_pgps: Storing prediction num:15 idx:15 for gps sec:1395050400
[00:00:46.514,862] <inf> download_client: Downloaded 34500/84268 bytes (40%)
[00:00:46.515,014] <inf> nrf_cloud_pgps: Storing prediction num:16 idx:16 for gps sec:1395064800
[00:00:46.959,625] <inf> download_client: Downloaded 36000/84268 bytes (42%)
[00:00:47.333,618] <inf> download_client: Downloaded 37500/84268 bytes (44%)
[00:00:47.333,679] <inf> nrf_cloud_pgps: Storing prediction num:17 idx:17 for gps sec:1395079200
[00:00:47.892,730] <inf> download_client: Downloaded 39000/84268 bytes (46%)
[00:00:47.892,852] <inf> nrf_cloud_pgps: Storing prediction num:18 idx:18 for gps sec:1395093600
[00:00:48.337,707] <inf> download_client: Downloaded 40500/84268 bytes (48%)
[00:00:48.337,860] <inf> nrf_cloud_pgps: Storing prediction num:19 idx:19 for gps sec:1395108000
[00:00:48.893,798] <inf> download_client: Downloaded 42000/84268 bytes (49%)
[00:00:49.257,720] <inf> download_client: Downloaded 43500/84268 bytes (51%)
[00:00:49.257,812] <inf> nrf_cloud_pgps: Storing prediction num:20 idx:20 for gps sec:1395122400
[00:00:49.727,783] <inf> download_client: Downloaded 45000/84268 bytes (53%)
[00:00:49.727,905] <inf> nrf_cloud_pgps: Storing prediction num:21 idx:21 for gps sec:1395136800
[00:00:50.319,702] <inf> download_client: Downloaded 46500/84268 bytes (55%)
[00:00:50.319,854] <inf> nrf_cloud_pgps: Storing prediction num:22 idx:22 for gps sec:1395151200
[00:00:50.775,421] <inf> download_client: Downloaded 48000/84268 bytes (56%)
[00:00:51.197,509] <inf> download_client: Downloaded 49500/84268 bytes (58%)
[00:00:51.197,601] <inf> nrf_cloud_pgps: Storing prediction num:23 idx:23 for gps sec:1395165600
[00:00:51.735,778] <inf> download_client: Downloaded 51000/84268 bytes (60%)
[00:00:51.735,900] <inf> nrf_cloud_pgps: Storing prediction num:24 idx:24 for gps sec:1395180000
[00:00:52.139,892] <inf> download_client: Downloaded 52500/84268 bytes (62%)
[00:00:52.140,075] <inf> nrf_cloud_pgps: Storing prediction num:25 idx:25 for gps sec:1395194400
[00:00:52.697,479] <inf> download_client: Downloaded 54000/84268 bytes (64%)
[00:00:53.110,443] <inf> download_client: Downloaded 55500/84268 bytes (65%)
[00:00:53.110,504] <inf> nrf_cloud_pgps: Storing prediction num:26 idx:26 for gps sec:1395208800
[00:00:53.878,967] <inf> download_client: Downloaded 57000/84268 bytes (67%)
[00:00:53.879,089] <inf> nrf_cloud_pgps: Storing prediction num:27 idx:27 for gps sec:1395223200
[00:00:54.414,855] <inf> download_client: Downloaded 58500/84268 bytes (69%)
[00:00:54.415,039] <inf> nrf_cloud_pgps: Storing prediction num:28 idx:28 for gps sec:1395237600
[00:00:54.808,868] <inf> download_client: Downloaded 60000/84268 bytes (71%)
[00:00:55.177,917] <inf> download_client: Downloaded 61500/84268 bytes (72%)
[00:00:55.178,009] <inf> nrf_cloud_pgps: Storing prediction num:29 idx:29 for gps sec:1395252000
[00:00:55.764,648] <inf> download_client: Downloaded 63000/84268 bytes (74%)
[00:00:55.764,770] <inf> nrf_cloud_pgps: Storing prediction num:30 idx:30 for gps sec:1395266400
[00:00:56.232,940] <inf> download_client: Downloaded 64500/84268 bytes (76%)
[00:00:56.233,093] <inf> nrf_cloud_pgps: Storing prediction num:31 idx:31 for gps sec:1395280800
[00:00:56.800,689] <inf> download_client: Downloaded 66000/84268 bytes (78%)
[00:00:57.295,928] <inf> download_client: Downloaded 67500/84268 bytes (80%)
[00:00:57.296,020] <inf> nrf_cloud_pgps: Storing prediction num:32 idx:32 for gps sec:1395295200
[00:00:57.779,632] <inf> download_client: Downloaded 69000/84268 bytes (81%)
[00:00:57.779,754] <inf> nrf_cloud_pgps: Storing prediction num:33 idx:33 for gps sec:1395309600
[00:00:58.424,957] <inf> download_client: Downloaded 70500/84268 bytes (83%)
[00:00:58.425,109] <inf> nrf_cloud_pgps: Storing prediction num:34 idx:34 for gps sec:1395324000
[00:00:58.948,913] <inf> download_client: Downloaded 72000/84268 bytes (85%)
[00:00:59.373,718] <inf> download_client: Downloaded 73500/84268 bytes (87%)
[00:00:59.373,809] <inf> nrf_cloud_pgps: Storing prediction num:35 idx:35 for gps sec:1395338400
[00:00:59.938,751] <inf> download_client: Downloaded 75000/84268 bytes (89%)
[00:00:59.938,873] <inf> nrf_cloud_pgps: Storing prediction num:36 idx:36 for gps sec:1395352800
[00:01:00.313,049] <inf> download_client: Downloaded 76500/84268 bytes (90%)
[00:01:00.313,201] <inf> nrf_cloud_pgps: Storing prediction num:37 idx:37 for gps sec:1395367200
[00:01:00.888,000] <inf> download_client: Downloaded 78000/84268 bytes (92%)
[00:01:01.257,049] <inf> download_client: Downloaded 79500/84268 bytes (94%)
[00:01:01.257,141] <inf> nrf_cloud_pgps: Storing prediction num:38 idx:38 for gps sec:1395381600
[00:01:01.671,020] <inf> download_client: Downloaded 81000/84268 bytes (96%)
[00:01:01.671,142] <inf> nrf_cloud_pgps: Storing prediction num:39 idx:39 for gps sec:1395396000
[00:01:02.250,030] <inf> download_client: Downloaded 82500/84268 bytes (97%)
[00:01:02.250,183] <inf> nrf_cloud_pgps: Storing prediction num:40 idx:40 for gps sec:1395410400
[00:01:02.616,760] <inf> download_client: Downloaded 84000/84268 bytes (99%)
[00:01:02.997,222] <inf> download_client: Downloaded 84268/84268 bytes (100%)
[00:01:02.997,314] <inf> nrf_cloud_pgps: Storing prediction num:41 idx:41 for gps sec:1395424800
[00:01:03.129,699] <inf> nrf_cloud_pgps: All P-GPS data received. Done.
[00:01:03.129,730] <inf> nrf_cloud_pgps: Searching for prediction
[00:01:03.129,852] <inf> nrf_cloud_pgps: GPS unit needs ephemerides. Injecting 32.
[00:01:03.130,035] <inf> download_client: Download complete
[00:01:03.130,065] <inf> nrf_cloud_pgps: Download client done
+CSCON: 0
[00:01:11.179,931] <inf> location: Method specific timeout expired
[00:01:11.180,389] <inf> location: Location retrieval failed using 'GNSS', trying with 'Cellular' next
%NCELLMEAS: 0,"07094711","310410","6106",771,5110,206,41,13,71337,5110,393,35,2,0,65115
%NCELLMEAS: 0,"07094711","310410","6106",771,65115,5110,206,40,13,72482,1,0,"0708DD0F","310410","6106",65535,0,5110,393,35,3,72482,0,0,"061CFB03","311580","0801",65535,0,5035,263,41,18,72539,0,0
[00:01:12.993,591] <dbg> nrf_cloud_codec_internal: nrf_cloud_cell_pos_req_json_encode: Encoding lte_lc_cells_info with ncells_count: 1 and gci_cells_count: 2
[00:01:13.000,274] <dbg> nrf_cloud_codec_internal: json_send_to_cloud: Created request: {"appId":"GROUND_FIX","messageType":"DATA","data":{"lte":[{"eci":118048529,"mcc":310,"mnc":410,"tac":24838,"earfcn":5110,"rsrp":-100,"rsrq":-13,"adv":771,"nmr":[{"earfcn":5110,"pci":393,"rsrp":-105,"rsrq":-18.5}]},{"eci":118021391,"mcc":310,"mnc":410,"tac":24838,"earfcn":5110,"rsrp":-105,"rsrq":-18},{"eci":102562563,"mcc":311,"mnc":580,"tac":2049,"earfcn":5035,"rsrp":-99,"rsrq":-10.5}]}} (size: 390)
[00:01:13.004,821] <dbg> nrf_cloud_codec_internal: json_send_to_cloud: Request sent to cloud
+CSCON: 1
[00:01:13.763,214] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1005 result = 0
[00:01:14.085,205] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 16684 len = 131, topic = prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/ground_fix/r
[00:01:14.086,517] <inf> location: LOCATION_REQ_MODE_ALL: all methods done
[00:01:14.086,578] <inf> application: Location Updated: 35.723004 N -97.578562 W, accuracy: 620.0 m, Method: Cellular
[00:01:14.086,639] <dbg> nrf_cloud_fsm: location_process: Location data sent to provided callback
+CSCON: 0
[00:01:31.171,386] <inf> application: Temperature is 23 degrees C
+CSCON: 1
[00:01:31.931,823] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1006 result = 0
+CSCON: 0
[00:02:31.171,417] <inf> application: Temperature is 22 degrees C
+CSCON: 1
[00:02:32.050,659] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1007 result = 0
+CSCON: 0
[00:02:54.207,550] <inf> location: Method specific timeout expired
[00:02:54.207,580] <wrn> location: GNSS timed out possibly due to too short GNSS time windows
[00:02:54.208,007] <inf> location: Location retrieval failed using 'GNSS', trying with 'Cellular' next
%NCELLMEAS: 0,"07094711","310410","6106",752,5110,206,39,13,173737,5110,450,34,3,0,5110,393,33,2,0,154318
%NCELLMEAS: 0,"07094711","310410","6106",752,154318,5110,206,39,13,173737,1,0,"070C0D0F","310410","6106",65535,0,5110,450,34,3,173737,0,0
[00:02:54.414,520] <dbg> nrf_cloud_codec_internal: nrf_cloud_cell_pos_req_json_encode: Encoding lte_lc_cells_info with ncells_count: 2 and gci_cells_count: 1
[00:02:54.420,288] <dbg> nrf_cloud_codec_internal: json_send_to_cloud: Created request: {"appId":"GROUND_FIX","messageType":"DATA","data":{"lte":[{"eci":118048529,"mcc":310,"mnc":410,"tac":24838,"earfcn":5110,"rsrp":-101,"rsrq":-13,"adv":752,"nmr":[{"earfcn":5110,"pci":450,"rsrp":-106,"rsrq":-18},{"earfcn":5110,"pci":393,"rsrp":-107,"rsrq":-18.5}]},{"eci":118230287,"mcc":310,"mnc":410,"tac":24838,"earfcn":5110,"rsrp":-106,"rsrq":-18}]}} (size: 352)
[00:02:54.421,783] <dbg> nrf_cloud_codec_internal: json_send_to_cloud: Request sent to cloud
+CSCON: 1
[00:02:55.322,998] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1008 result = 0
[00:02:55.558,410] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 16684 len = 132, topic = prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/ground_fix/r
[00:02:55.559,692] <inf> location: LOCATION_REQ_MODE_ALL: all methods done
[00:02:55.559,783] <inf> application: Location Updated: 35.686866 N -97.557778 W, accuracy: 1823.0 m, Method: Cellular
[00:02:55.559,844] <dbg> nrf_cloud_fsm: location_process: Location data sent to provided callback
+CSCON: 0
+CSCON: 1
[00:03:18.845,397] <dbg> nrf_cloud: nrf_cloud_run: Socket error: POLLERR
[00:03:18.845,397] <dbg> nrf_cloud: nrf_cloud_run: Cloud connection was unexpectedly closed
[00:03:18.845,428] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 1
[00:03:18.845,458] <inf> cloud_connection: Disconnecting from nRF Cloud
[00:03:18.845,520] <inf> cloud_connection: Disconnected from nRF Cloud
[00:03:18.845,520] <inf> cloud_connection: Retrying in 30 seconds...
[00:03:18.845,581] <dbg> nrf_cloud_transport: nct_disconnect: nct_disconnect
[00:03:18.846,710] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_DISCONNECT: result = -122
[00:03:18.846,740] <dbg> nrf_cloud_fsm: drop_event_handler: Dropping FSM transition 10, current state 1
+CSCON: 0
[00:03:31.171,447] <inf> application: Temperature is 22 degrees C
[00:03:48.845,642] <inf> cloud_connection: Waiting for network ready...
[00:03:48.845,672] <inf> cloud_connection: Network is ready
[00:03:48.845,703] <inf> cloud_connection: Connecting to nRF Cloud
[00:03:48.845,733] <inf> cloud_connection: Connected to nRF Cloud
[00:03:48.845,794] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 1
+CSCON: 1
[00:03:49.234,497] <dbg> nrf_cloud_transport: nct_connect: IPv4 address: 54.234.211.168
[00:03:51.461,181] <dbg> nrf_cloud: nrf_cloud_run: Cloud connection request sent
[00:03:51.942,596] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_CONNACK: result 0
[00:03:51.942,596] <dbg> nrf_cloud_transport: nct_save_session_state: Setting session state: 0
[00:03:51.943,389] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 2
[00:03:51.943,420] <dbg> nrf_cloud_transport: nct_cc_connect: nct_cc_connect
[00:03:51.944,213] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 3
[00:03:52.295,501] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_SUBACK: id = 100 result = 0
[00:03:52.295,532] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 4
[00:03:52.295,593] <dbg> nrf_cloud_transport: nct_cc_send: mqtt_publish: id = 200 opcode = 0 len = 0, topic: $aws/things/nrf-350457790695389/shadow/get
[00:03:52.296,478] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 5
[00:03:52.556,549] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 200 result = 0
[00:03:52.556,579] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 5
[00:03:52.703,918] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 16684 len = 544, topic = nrf-350457790695389/shadow/get/accepted
[00:03:52.704,193] <dbg> nrf_cloud_fsm: cc_rx_data_handler: CC RX on topic nrf-350457790695389/shadow/get/accepted89/m/d/nrf-350457790695389/ground_fix/r: {"desired":{"pairing":{"state":"paired","topics":{"d2c":"prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/d2c","c2d":"prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/+/r"}},"nrfcloud_mqtt_topic_prefix":"prod/08e77791-23c4-4c38-982c-4097624a1789/","control":{"logLvl":3}},"reported":{"control":{"alertsEn":true,"logLvl":3}},"config":{"activeMode":true,"locationTimeout":300,"activeWaitTime":120,"movementResolution":120,"movementTimeout":3600,"accThreshAct":4,"accThreshInact":4,"accTimeoutInact":60,"nod":[]}}
[00:03:52.705,718] <dbg> nrf_cloud_codec_internal: nrf_cloud_shadow_control_decode: Control inside of desired
[00:03:52.705,718] <dbg> nrf_cloud_codec_internal: nrf_cloud_shadow_control_decode: alertsEn not found
[00:03:52.705,871] <dbg> nrf_cloud_codec_internal: nrf_cloud_shadow_control_decode: No response needed. Got shadow: {"desired":{"pairing":{"state":"paired","topics":{"d2c":"prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/d2c","c2d":"prod/08e77791-23c4-4c38-982c-4097624a1789/m/d/nrf-350457790695389/+/r"}},"nrfcloud_mqtt_topic_prefix":"prod/08e77791-23c4-4c38-982c-4097624a1789/","control":{"logLvl":3}},"reported":{"control":{"alertsEn":true,"logLvl":3}},"config":{"activeMode":true,"locationTimeout":300,"activeWaitTime":120,"movementResolution":120,"movementTimeout":3600,"accThreshAct":4,"accThreshInact":4,"accTimeoutInact":60,"nod":[]}}
[00:03:52.706,573] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 5
[00:03:52.708,770] <dbg> nrf_cloud_fsm: cc_rx_data_handler: New state: 7
[00:03:52.711,242] <dbg> nrf_cloud_transport: nct_dc_endpoint_set: nct_dc_endpoint_set
[00:03:52.711,639] <dbg> nrf_cloud_transport: nct_dc_endpoint_get: nct_dc_endpoint_get
[00:03:52.713,134] <dbg> nrf_cloud_transport: nct_cc_send: mqtt_publish: id = 301 opcode = 1 len = 361, topic: $aws/things/nrf-350457790695389/shadow/update
[00:03:52.938,812] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 7
[00:03:53.289,642] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 301 result = 0
[00:03:53.289,672] <dbg> nrf_cloud_transport: nct_dc_connect: nct_dc_connect
[00:03:53.290,374] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 8
[00:03:53.447,662] <dbg> nrf_cloud: nrf_cloud_run: Socket error: POLLERR
[00:03:53.447,692] <dbg> nrf_cloud: nrf_cloud_run: Cloud connection was unexpectedly closed
[00:03:53.447,723] <dbg> nrf_cloud: nfsm_set_current_state_and_notify: state: 1
[00:03:53.447,753] <inf> cloud_connection: Disconnecting from nRF Cloud
[00:03:53.447,784] <inf> cloud_connection: Disconnected from nRF Cloud
[00:03:53.447,814] <inf> cloud_connection: Retrying in 30 seconds...
[00:03:53.447,875] <dbg> nrf_cloud_transport: nct_disconnect: nct_disconnect
[00:03:53.536,193] <dbg> nrf_cloud_transport: nct_mqtt_evt_handler: MQTT_EVT_DISCONNECT: result = -122
[00:03:53.536,224] <dbg> nrf_cloud_fsm: drop_event_handler: Dropping FSM transition 10, current state 1

mqtt_debug.zip

I have also attached a zipped folder of the full sample that was used above. This should be everything you need to reproduce the issue consistently on any unit.