"Unhandled data received from nRF Cloud"

[Torje]

Hello Nordic and fellow developers!

After migrating to NCS 2.2.0, I got some new and exciting error messages in my application. They are related to nRFCloud usage.

Whenever I receive data from the cloud, I get these errors. The seemingly do not affect anything, as everything still works as it should. But I fear I might be doing something wrong, or that the libraries are doing something wrong.

The following log snippet is from connecting to the cloud and requesting agps data:

[00:00:13.422,729] [<inf> voqdr: NRF_MODEM_GNSS_EVT_AGPS_REQ
[00:00:13.428,741] [<inf> voqdr: Assistance data needed, ephe 0xffffffff, alm 0xffffffff, flags 0x3b
[00:00:13.438,537] [<inf> voqdr: Connecting to LTE network
[00:00:13.444,885] [<inf> voqdr: reg_status: 1
[00:00:13.449,645] [<inf> voqdr: The device is already registered with an LTE network
[00:00:13.457,824] [<inf> voqdr: Connecting to nRF Cloud
[00:00:13.464,599] [<dbg> voqdr: cloud_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING
[00:00:15.985,870] [<dbg> voqdr: cloud_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTED
[00:00:16.572,906] [<dbg> voqdr: cloud_event_handler: NRF_CLOUD_EVT_RX_DATA_SHADOW
[00:00:16.580,780] [<dbg> voqdr: cloud_event_handler: 287 bytes received from cloud
[00:00:16.588,867] [1;31m<err> voqdr: json_from_cloud: {"desired":{"pairing":{"state":"paired","topics":{"d2c":"prod/xx/m/d/dev-imei/d2c","c2d":"prod/xx/m/d/dev-imei/+/r"}},"nrfcloud_mqtt_topic_prefix":"prod/xx/"}}
[00:00:16.635,559] <dbg> voqdr: cloud_event_handler: NRF_CLOUD_EVT_USER_ASSOCIATED
[00:00:17.173,706] [1;33m<wrn> nrf_cloud_codec: Unhandled data received from nRF Cloud.
[00:00:17.181,854] <inf> nrf_cloud_codec: Ensure device firmware is up to date.
[00:00:17.189,605] <inf> nrf_cloud_codec: Delete and re-add device to nRF Cloud if problem persists.
[00:00:17.199,279] [1;31m<err> nrf_cloud_fsm: nrf_cloud_decode_requested_state Failed -2
[00:00:17.207,489] [1;31m<err> nrf_cloud_fsm: Handler failed! state: 8, type: 3
[00:00:17.214,996] [1;31m<err> nrf_cloud_transport: nct_input: failed -2
[00:00:17.293,792] <dbg> voqdr: cloud_event_handler: NRF_CLOUD_EVT_READY
[00:00:17.301,574] <inf> voqdr: Connected to nRF Cloud
[00:00:17.308,624] <inf> voqdr: Shadow updated
[00:00:17.347,229] [1;31m<err> nrf_cloud_agps:  nrf_cloud_agps_request finished
[00:00:17.822,723] [1;33m<wrn> nrf_cloud_codec: Unhandled data received from nRF Cloud.
[00:00:17.830,871] <inf> nrf_cloud_codec: Ensure device firmware is up to date.
[00:00:17.838,623] <inf> nrf_cloud_codec: Delete and re-add device to nRF Cloud if problem persists.
[00:00:17.848,297] [1;31m<err> nrf_cloud_fsm: nrf_cloud_decode_requested_state Failed -2
[00:00:17.856,536] [1;31m<err> nrf_cloud_fsm: Handler failed! state: 9, type: 3
[00:00:17.864,013] [1;31m<err> nrf_cloud_transport: nct_input: failed -2

I get cloud association as I should, and I receive the agps data as expected (verified only by how quickly it found several sats. As a digression, I allow myself to request some sort of verification of it through your libraries. After 2.2.0, this became a lot more "black box".)

The first part of the message stems from nrf_cloud_decode_requested_state() in nrf_cloud_codec.c, the last is from the handler in nrf_cloud_fsm.

I cant see any actual problems associated with these messages. Can anyone help in getting rid of these?

Please let me know what other information I can supply to help figuring this out.

Thanks!

Kind regards,

Torje

[justin]

What data (and data format) is written to the shadow here:
00:00:17.223,083] [0m<dbg> nrf_cloud_transport: nct_cc_send: mqtt_publish: id = 1000 opcode = 1 len = 91
00:00:17.233,947] [0m<inf> voqdr: Shadow updated

I tried to look for your device in AWS, but it appears to be gone.


It is possible that the codec needs to be updated to be less strict about shadow updates.

[Torje]

Hello Justin,

I'm updating the shadow as such:

void update_shadow(void)
{
	int err;
	struct nrf_cloud_svc_info_fota fota_info = {
		.application = IS_ENABLED(CONFIG_NRF_CLOUD_FOTA) && IS_ENABLED(CONFIG_BOOTLOADER_MCUBOOT),
		.bootloader = IS_ENABLED(CONFIG_NRF_CLOUD_FOTA) && IS_ENABLED(CONFIG_BOOTLOADER_MCUBOOT) && IS_ENABLED(CONFIG_BUILD_S1_VARIANT) && IS_ENABLED(CONFIG_SECURE_BOOT),
		.modem = IS_ENABLED(CONFIG_NRF_CLOUD_FOTA) && IS_ENABLED(CONFIG_BOOTLOADER_MCUBOOT)};
	struct nrf_cloud_svc_info_ui ui_info = {
		.gnss = true,		  
		.temperature = false, 
	};
	struct nrf_cloud_svc_info service_info = {
		.fota = &fota_info,
		.ui = &ui_info};
	struct nrf_cloud_device_status device_status = {
		.modem = NULL,
		.svc = &service_info};

	err = nrf_cloud_shadow_device_status_update(&device_status);
	if (err)
	{
		LOG_ERR("Failed to update device shadow, error: %d", err);
	}
}

This is plucked from a sample. The shadow is updated only once, on the first connection

I'm not sure how you would find the device, as I've hidden device ID and other info in the logs? The particular ID is Voqdr-352656101081837. Its location data is stored in nRFCloud, as expected.

[justin]

ah, i didn't realize you modified the device id in your logs... thanks for the real device id.
the desired section has a "desiredConnections" json object which is producing a shadow delta event.
that should not be a problem, but it seems the codec does not like it.

if you don't need this object, i can remove it for you and that should get rid of your error.

regardless, it looks like the codec needs updated to handle such things.

[Torje]

Thank you for looking into this, Justin.

We're planning to make loads of devices like this. Can you share any insight as to why this object is there? Is it something I've done?

I can share how I'm using it: I update the shadow in the cloud when I want to change the interval of fix. My app looks through the shadow it receives when it connects to the cloud, and saves the new interval if there is one. I'm doing this through this endpoint, by sending something like this:

{
  "state": {
    "desired": {
      "config": {
        "gnssInterval": 24
    }
  }
}

This has seemingly worked fine. If you have any comments regarding my usage, feel free to share!

One more question:
When you say that the codec needs to be updated, do you mean that there is a newer version of this library I can use which would solve it, or that I should modify it?

Thanks for your help!

[justin]

Can you share any insight as to why this object is there? Is it something I've done?
I don't see anything in the SDK that would write a "desiredConnections" object to the shadow. So perhaps it was accidentally written with the UpdateDeviceState endpoint during testing?

Yes, using the "config" object is the expected method.

I think we (nordic) will need to make an update to the codec to prevent the error messages you were seeing.
But I've removed the "desiredConnections" object, so you shouldn't have to do anything at this time.

[Torje]

Hey again,

Thanks alot for your help.You guys are the best.

Kind regards,
Torje