AssetTracker v2: real-time configuration handling seems not always graceful

Hi!

I noticed that if I add a wrong/unexpected value into the No Data List (NOD) of a real-time configuration, the application stops working correctly, throws many different errors, reboots the device and etc.



My setup:

HW: Thingy:91 v1.6.0

SDK: v2.5.0

Modem FW: 1.3.5

AssetTracker v2 with the default build-time configuration except one parameter: I removed CONFIG_LTE_NETWORK_MODE_LTE_M_GPS=y and added CONFIG_LTE_NETWORK_MODE_NBIOT_GPS=y.


The setup works fine until I add, e.g., "GNSS" (usage of capital letters was my mistake led to this issue) to the "nod" list of the real-time cfg.

Then I got the following logs:

Many times of

[00:06:49.620,758] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:06:49.622,467] <inf> app_event_manager: CLOUD_EVT_CONFIG_RECEIVED
[00:06:49.626,525] <inf> app_event_manager: DATA_EVT_CONFIG_SEND
[00:06:49.627,807] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:06:51.629,791] <inf> nrf_cloud_codec_internal: Updating shadow with alertEn:0 and logLvl:1

Then

[00:07:33.544,677] <err> modem_module: Modem error: 0x4, PC: 0x1cd372
[00:07:33.544,769] <wrn> location: nrf_modem_gnss_agnss_expiry_get() failed, err -110
[00:07:33.545,318] <err> nrf_cloud_transport: mqtt_publish failed -110
[00:07:33.545,318] <err> nrf_cloud: nct_cc_send failed, error: -110[00:07:33.545,349] <err> nrf_cloud_integration: nrf_cloud_send, error: -110
[00:07:33.545,379] <wrn> cloud_module: cloud_wrap_state_send, err: -110
[00:07:33.545,410] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:07:33.545,440] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:07:33.545,501] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:07:33.545,532] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:07:33.545,593] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:07:33.545,593] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:07:33.545,654] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:07:33.545,684] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:07:33.545,837] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:07:33.545,867] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:07:33.545,928] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:07:33.545,928] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:07:33.545,989] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:07:33.546,020] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:07:33.546,051] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:07:33.546,081] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:07:33.644,653] <inf> app_event_manager: MODEM_EVT_ERROR - Error code -14
[00:07:33.645,172] <inf> app_event_manager: CLOUD_EVT_DISCONNECTED
[00:07:33.645,599] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:07:33.645,751] <inf> app_event_manager: LOCATION_MODULE_EVT_ACTIVE
[00:07:33.646,148] <inf> app_event_manager: UTIL_EVT_SHUTDOWN_REQUEST
[00:07:33.646,636] <inf> app_event_manager: UI_EVT_SHUTDOWN_READY
[00:07:33.646,728] <wrn> modules_common: Module "ui" shutdown registered
[00:07:33.646,850] <inf> app_event_manager: LOCATION_MODULE_EVT_SHUTDOWN_READY
[00:07:33.646,911] <wrn> modules_common: Module "location" shutdown registered
[00:07:33.647,674] <inf> app_event_manager: APP_EVT_SHUTDOWN_READY
[00:07:33.647,735] <wrn> modules_common: Module "app" shutdown registered
[00:07:33.648,193] <err> lte_lc: Failed to get system mode, error: -1
[00:07:33.648,193] <err> location: Failed to configure GNSS
[00:07:33.648,345] <err> location: Failed to initiate neighbor cell measurements: -14
[00:07:33.648,376] <wrn> location: Current cell ID not valid
[00:07:33.648,406] <wrn> location: No cellular neighbor cells or Wi-Fi access points found
[00:07:33.648,468] <err> location: Location acquisition failed and fallbacks are also done
[00:07:33.648,468] <wrn> location_module: Getting location failed
[00:07:33.648,559] <inf> app_event_manager: LOCATION_MODULE_EVT_DATA_NOT_READY
[00:07:33.648,986] <inf> app_event_manager: LOCATION_MODULE_EVT_INACTIVE
[00:07:33.882,110] <inf> app_event_manager: DATA_EVT_SHUTDOWN_READY
[00:07:33.882,232] <wrn> modules_common: Module "data" shutdown registered
[00:07:33.882,934] <err> modem_info_params: Link data not obtained: -5
[00:07:33.882,934] <err> modem_module: modem_info_params_get, error: -5
[00:07:33.883,026] <inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_NOT_READY
[00:07:33.883,605] <err> lte_lc: Failed to set functional mode. Please check XSYSTEMMODE.
[00:07:33.883,697] <inf> app_event_manager: MODEM_EVT_SHUTDOWN_READY
[00:07:33.883,758] <wrn> modules_common: Module "modem" shutdown registered
[00:07:33.884,460] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:07:33.884,490] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:07:33.884,643] <inf> app_event_manager: CLOUD_EVT_SHUTDOWN_READY
[00:07:33.884,796] <wrn> modules_common: Module "cloud" shutdown registered
[00:07:33.977,722] <inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_DATA_READY
[00:07:33.978,271] <inf> app_event_manager: SENSOR_EVT_FUEL_GAUGE_READY
[00:07:33.978,607] <inf> app_event_manager: SENSOR_EVT_SHUTDOWN_READY
[00:07:33.978,668] <wrn> modules_common: Module "sensor" shutdown registered
[00:07:33.979,003] <inf> app_event_manager: DATA_EVT_DATA_READY
[00:07:34.884,552] <inf> app_event_manager: CLOUD_EVT_CONNECTION_TIMEOUT
*** Booting nRF Connect SDK v2.5.0 ***Rebooting!

After the reboot

[00:01:17.233,825] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:01:18.370,330] <inf> app_event_manager: CLOUD_EVT_CONFIG_RECEIVED
[00:01:18.374,359] <inf> app_event_manager: DATA_EVT_CONFIG_SEND
[00:01:18.375,946] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:01:18.379,638] <inf> nrf_cloud_codec_internal: Updating shadow with alertEn:0 and logLvl:1
[00:01:19.534,271] <inf> nrf_cloud_codec_internal: Updating shadow with alertEn:0 and logLvl:1
[00:01:19.536,682] <inf> app_event_manager: CLOUD_EVT_CONFIG_RECEIVED
[00:01:19.541,015] <inf> app_event_manager: DATA_EVT_CONFIG_SEND
[00:01:19.542,480] <inf> nrf_cloud_codec_internal: Updating shadow with alertEn:0 and logLvl:1
[00:01:19.543,212] <err> qos: No available entries in pending message list
[00:01:19.543,212] <wrn> qos: No list entries available, error: -12
[00:01:19.543,273] <wrn> cloud_module: Cannot add message, internal pending list is full
[00:01:19.544,616] <inf> app_event_manager: CLOUD_EVT_CONFIG_RECEIVED
[00:01:19.549,377] <inf> app_event_manager: DATA_EVT_CONFIG_SEND
[00:01:19.549,987] <err> qos: No available entries in pending message list
[00:01:19.550,018] <wrn> qos: No list entries available, error: -12
[00:01:19.550,079] <wrn> cloud_module: Cannot add message, internal pending list is full
[00:01:20.507,263] <inf> nrf_cloud_codec_internal: Updating shadow with alertEn:0 and logLvl:1
[00:01:20.509,552] <inf> app_event_manager: CLOUD_EVT_CONFIG_RECEIVED
[00:01:20.513,885] <inf> app_event_manager: DATA_EVT_CONFIG_SEND
[00:01:20.515,350] <inf> nrf_cloud_codec_internal: Updating shadow with alertEn:0 and logLvl:1

A bit later

[00:04:00.551,971] <inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_DATA_READY
[00:04:00.553,192] <inf> app_event_manager: SENSOR_EVT_FUEL_GAUGE_READY
[00:04:00.609,680] <inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY
[00:04:12.031,768] <wrn> cloud_module: cloud_wrap_state_send, err: -128
--- 4 messages dropped ---
[00:04:12.031,829] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.031,860] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.031,890] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.031,921] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.031,982] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,012] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,073] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,073] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,135] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,165] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,196] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,226] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,287] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,287] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,348] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,379] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,409] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,440] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,501] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,501] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,562] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,592] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,653] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,653] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,714] <err> nrf_cloud_integration: nrf_cloud_send, error: -13
[00:04:12.032,714] <wrn> cloud_module: cloud_wrap_state_send, err: -13
[00:04:12.032,897] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:04:12.033,233] <err> cloud_module: Unknown data type
[00:04:12.033,325] <err> nrf_cloud_transport: mqtt_publish failed -11
[00:04:12.033,386] <err> nrf_cloud_fsm: nct_cc_send failed -11
[00:04:12.034,484] <inf> app_event_manager: CLOUD_EVT_CONFIG_RECEIVED
[00:04:12.278,900] <inf> app_event_manager: DATA_EVT_CONFIG_SEND
[00:04:12.279,541] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:04:12.279,785] <err> nrf_cloud_transport: mqtt_publish failed -128
[00:04:12.279,785] <err> nrf_cloud: nct_cc_send failed, error: -128
[00:04:12.279,815] <err> nrf_cloud_integration: nrf_cloud_send, error: -128
[00:04:12.279,815] <wrn> cloud_module: cloud_wrap_state_send, err: -128
[00:04:13.033,325] <inf> app_event_manager: CLOUD_EVT_CONNECTION_TIMEOUT
[00:04:13.033,843] <err> nrf_cloud_integration: nrf_cloud_connect, error: -11
[00:04:28.279,876] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:04:28.280,029] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:04:28.280,181] <err> cloud_module: Unknown data type
[00:04:28.280,273] <err> nrf_cloud_transport: mqtt_publish failed -128
[00:04:28.280,273] <err> nrf_cloud: nct_cc_send failed, error: -128
[00:04:28.280,303] <err> nrf_cloud_integration: nrf_cloud_send, error: -128
[00:04:28.280,303] <wrn> cloud_module: cloud_wrap_state_send, err: -128
[00:04:44.280,029] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:04:44.280,181] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:04:44.280,303] <err> cloud_module: Unknown data type
[00:04:44.280,426] <err> nrf_cloud_transport: mqtt_publish failed -128
[00:04:44.280,426] <err> nrf_cloud: nct_cc_send failed, error: -128
[00:04:44.280,456] <err> nrf_cloud_integration: nrf_cloud_send, error: -128
[00:04:44.280,456] <wrn> cloud_module: cloud_wrap_state_send, err: -128
[00:04:45.034,027] <inf> app_event_manager: CLOUD_EVT_CONNECTION_TIMEOUT
[00:04:45.034,545] <err> nrf_cloud_integration: nrf_cloud_connect, error: -11
[00:04:55.546,966] <inf> app_event_manager: DATA_EVT_DATA_READY
[00:05:00.545,745] <inf> app_event_manager: APP_EVT_DATA_GET_ALL
[00:05:00.546,325] <inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, LOCATION)
[00:05:00.550,476] <inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_DATA_READY
[00:05:00.551,422] <inf> app_event_manager: SENSOR_EVT_FUEL_GAUGE_READY
[00:05:00.609,222] <inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY
[00:05:49.034,729] <inf> app_event_manager: CLOUD_EVT_CONNECTION_TIMEOUT
[00:05:49.035,278] <err> nrf_cloud_integration: nrf_cloud_connect, error: -11
[00:05:54.715,362] <wrn> location: RRC connection was not released in 5 minutes. Starting GNSS anyway.
[00:05:54.728,240] <inf> app_event_manager: LOCATION_MODULE_EVT_TIMEOUT
[00:05:54.728,698] <inf> app_event_manager: LOCATION_MODULE_EVT_INACTIVE
[00:05:54.729,492] <inf> app_event_manager: DATA_EVT_DATA_READY
[00:06:00.545,745] <inf> app_event_manager: APP_EVT_DATA_GET_ALL
[00:06:00.546,325] <inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, LOCATION)
[00:06:00.647,094] <inf> app_event_manager: LOCATION_MODULE_EVT_ACTIVE
[00:06:00.651,611] <inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_DATA_READY
[00:06:00.652,557] <inf> app_event_manager: SENSOR_EVT_FUEL_GAUGE_READY
[00:06:00.710,754] <inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY
+CSCON: 0
[00:06:06.963,897] <err> location: Failed to configure GNSS

Then I was getting "[00:20:45.037,384] <err> nrf_cloud_integration: nrf_cloud_connect, error: -11" again and again. There was no connection to the cloud. I had to reboot the device manually.

After the reboot I got many messages like the following:

[00:00:49.473,937] <inf> nrf_cloud_codec_internal: Updating shadow with alertEn:0 and logLvl:1
[00:00:49.542,785] <inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS
[00:00:50.152,954] <inf> app_event_manager: CLOUD_EVT_CONFIG_RECEIVED
[00:00:50.156,951] <inf> app_event_manager: DATA_EVT_CONFIG_SEND
[00:00:50.158,325] <err> qos: No available entries in pending message list
[00:00:50.158,325] <wrn> qos: No list entries available, error: -12
[00:00:50.158,386] <wrn> cloud_module: Cannot add message, internal pending list is full
[00:00:50.160,522] <inf> nrf_cloud_codec_internal: Updating shadow with alertEn:0 and logLvl:1

Then I removed the "GNSS" string from the "nod" list and the app finally got back to the correct work.

This is not a one-time issue - I reproduced it several times (with different wrong values in the "nod" list).

This issue is absolutely not critical for testing and demo projects. But can be dangerous for production usage.

Thank you!

Related