Azure IoT Hub DPS library seems to always reprovision our device

I am working with SDK: 2.5.0 and toolchain 2.5.0.
I am using the new nRF7002DK.

I created an application from the azure_iot_hub sample.

I am using the DPS for my provisioning.
It is important to note that we haven't modified the code other than adding log to help us.

I am experiencing the following issues:

During azure_iot_hub_dps_init(), we are correctly enabling the setting module, and the load is a success:

[00:00:07.963,104] <wrn> azure_iot_hub_dps: azure_iot_hub_dps_init
[00:00:07.963,134] <inf> azure_iot_hub_dps: No registration ID provided, using ID from Kconfig: device-01
[00:00:07.963,165] <inf> azure_iot_hub_dps: Setting DPS registration ID: device-01
[00:00:07.963,226] <inf> azure_iot_hub_dps: No ID scope provided, using ID scope from Kconfig: ********
[00:00:07.963,256] <inf> azure_iot_hub_dps: Setting DPS ID scope: ********
[00:00:07.963,378] <inf> azure_iot_hub_dps: Assigned device ID found:
[00:00:07.963,531] <inf> azure_iot_hub_dps: Assigned device ID length found: 9
[00:00:07.963,714] <inf> azure_iot_hub_dps: Azure IoT Hub hostname found:
[00:00:07.963,928] <inf> azure_iot_hub_dps: Azure IoT Hub hostname length found: 29
[00:00:07.963,958] <inf> azure_iot_hub_dps: Settings fully loaded
[00:00:07.963,989] <inf> azure_iot_hub_dps: State transition: DPS_STATE_UNINIT --> DPS_STATE_DISCONNECTED
[00:00:07.964,019] <inf> azure_iot_hub_sample: DPS registration status: AZURE_IOT_HUB_DPS_REG_STATUS_NOT_STARTED

During the azure_iot_hub_dps_start phase. The global dps_reg_ctx was not updated with the value. I am new, but could it be some thread caching problem?

[00:00:07.964,019] <wrn> azure_iot_hub_dps: azure_iot_hub_dps_start
[00:00:07.964,050] <wrn> azure_iot_hub_dps: Settings not found

Here's the code I added to get that output:

	if ((az_span_size(dps_reg_ctx.assigned_hub) > 0) &&
	    (az_span_size(dps_reg_ctx.assigned_device_id) > 0)) {
		LOG_WRN("Settings found");
		LOG_INF("Device \"%.*s\" is assigned to IoT hub: %.*s",
			az_span_size(dps_reg_ctx.assigned_device_id),
			(char *)az_span_ptr(dps_reg_ctx.assigned_device_id),
			az_span_size(dps_reg_ctx.assigned_hub),
			(char *)az_span_ptr(dps_reg_ctx.assigned_hub));

		LOG_INF("To re-register, call azure_iot_hub_dps_reset() first");

		dps_reg_ctx.status = AZURE_IOT_HUB_DPS_REG_STATUS_ASSIGNED;

		return -EALREADY;
	} else {
		LOG_WRN("Settings not found");
		LOG_INF("Device \"%.*s\" is assigned to IoT hub: %.*s",
			az_span_size(dps_reg_ctx.assigned_device_id),
			(char *)az_span_ptr(dps_reg_ctx.assigned_device_id),
			az_span_size(dps_reg_ctx.assigned_hub),
			(char *)az_span_ptr(dps_reg_ctx.assigned_hub));
	}


After that, we end up straight into the provisioning process:

[00:00:07.964,233] <inf> azure_iot_hub_dps: User name (size: 58): ******/registrations/device-01/api-version=2019-03-31
[00:00:07.964,263] <inf> mqtt_helper: State transition: MQTT_STATE_UNINIT --> MQTT_STATE_DISCONNECTED
[00:00:07.964,324] <inf> mqtt_helper: Resolving IP address for global.azure-devices-provisioning.net
[00:00:08.548,095] <inf> mqtt_helper: IPv4 Address found 52.228.85.227 (AF_INET)


Has anyone here already experienced the same issues?
Am I doing something wrong?

We have already experienced much trouble using this example on our nRF7002DK.
Has this example been thoroughly tested before releasing it to us?

Thanks for any advice regarding this issue. I am a beginner here, and any shared knowledge will be helpful.

Cheers!

Parents Reply Children
  • Hi Simon,

    Thank you for pushing this ticket. One problem was resolved!
    After applying the fixes from that PR, the setting is read correctly on my side and not overwritten.

    Did you have feedback on the second point where we go twice inside the azure_iot_hub_dps_init function?


    [00:00:07.821,685] <wrn> azure_iot_hub_dps: azure_iot_hub_dps_init
    [00:00:07.821,746] <inf> azure_iot_hub_dps: No registration ID provided, using ID from Kconfig: device-01
    [00:00:07.821,777] <inf> azure_iot_hub_dps: Setting DPS registration ID: device-01
    [00:00:07.821,807] <inf> azure_iot_hub_dps: No ID scope provided, using ID scope from Kconfig: ********
    [00:00:07.821,838] <inf> azure_iot_hub_dps: Setting DPS ID scope: : ********
    [00:00:07.822,204] <inf> azure_iot_hub_dps: Azure IoT Hub hostname length found: 29
    [00:00:07.822,570] <inf> azure_iot_hub_dps: Azure IoT Hub hostname found: ********azure-devices.net
    [00:00:07.822,814] <inf> azure_iot_hub_dps: Assigned device ID length found: 9
    [00:00:07.822,967] <inf> azure_iot_hub_dps: Assigned device ID found: device-01
    [00:00:07.823,028] <inf> azure_iot_hub_dps: Settings fully loaded
    [00:00:07.823,089] <inf> azure_iot_hub_dps: State transition: DPS_STATE_UNINIT --> DPS_STATE_DISCONNECTED
    [00:00:07.823,089] <inf> azure_iot_hub_sample: DPS registration status: AZURE_IOT_HUB_DPS_REG_STATUS_NOT_STARTED
    [00:00:07.823,120] <wrn> azure_iot_hub_dps: azure_iot_hub_dps_start
    [00:00:07.823,120] <wrn> azure_iot_hub_dps: Settings found
    [00:00:07.823,181] <inf> azure_iot_hub_dps: Device "device-01" is assigned to IoT hub: ********azure-devices.net
    [00:00:07.823,211] <inf> azure_iot_hub_dps: To re-register, call azure_iot_hub_dps_reset() first
    [00:00:07.823,211] <inf> azure_iot_hub_sample: Already assigned to an IoT hub, skipping DPS
    [00:00:07.823,242] <inf> azure_iot_hub_dps: hostname_ptr: 0x200063e4, hostname_len: 29
    [00:00:07.823,242] <inf> azure_iot_hub_dps: dev_id_ptr: 0x20006364, dev_id_len: 9
    [00:00:07.823,303] <inf> azure_iot_hub_sample: Device ID "device-01" assigned to IoT hub with hostname "*****.azure-devices.net"
    [00:00:07.824,157] <inf> azure_fota: Current firmware version: 0.0.0-dev
    [00:00:07.824,188] <inf> azure_iot_hub_sample: Azure IoT Hub library initialized
    [00:00:07.824,218] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_CONNECTING
    [00:00:07.824,218] <wrn> azure_iot_hub_dps: azure_iot_hub_dps_init
    [00:00:07.824,249] <inf> azure_iot_hub_dps: Setting DPS registration ID: device-01
    [00:00:07.824,279] <inf> azure_iot_hub_dps: Setting DPS ID scope: *******
    [00:00:07.824,676] <inf> azure_iot_hub_dps: Azure IoT Hub hostname length found: 29
    [00:00:07.825,012] <inf> azure_iot_hub_dps: Azure IoT Hub hostname found: *******.azure-devices.net
    [00:00:07.825,256] <inf> azure_iot_hub_dps: Assigned device ID length found: 9
    [00:00:07.825,408] <inf> azure_iot_hub_dps: Assigned device ID found: device-01
    [00:00:07.825,469] <inf> azure_iot_hub_dps: Settings fully loaded
    [00:00:07.825,500] <wrn> azure_iot_hub_dps: azure_iot_hub_dps_start
    [00:00:07.825,531] <wrn> azure_iot_hub_dps: Settings found
    [00:00:07.825,592] <inf> azure_iot_hub_dps: Device "device-01" is assigned to IoT hub: *******..azure-devices.net
    [00:00:07.825,592] <inf> azure_iot_hub_dps: To re-register, call azure_iot_hub_dps_reset() first


    I also have some errors happening on my side that I would appreciate some support/explanation to assess if we can fix them. Could you explain to me what this error is really about and what is happening? Then, I will asses if I can live with it or I need to fix it.

    [00:00:08.765,472] <inf> mqtt_helper: State transition: MQTT_STATE_DISCONNECTED --> MQTT_STATE_TRANSPORT_CONNECTING
    [00:00:09.828,948] <err> net_pkt: Data buffer (68) allocation failed.
    [00:00:09.829,040] <err> net_tcp: TCP failed to allocate buffer in retransmission
    [00:00:10.385,528] <inf> net_mqtt: Connect completed
    [00:00:10.385,589] <inf> mqtt_helper: State transition: MQTT_STATE_TRANSPORT_CONNECTING --> MQTT_STATE_TRANSPORT_CONNECTED
    [00:00:10.385,620] <inf> mqtt_helper: State transition: MQTT_STATE_TRANSPORT_CONNECTED --> MQTT_STATE_CONNECTING

    Again, thank you and your team for the support.
    Vincent

  • Hi Vincent

    Does the azure_iot_hub_dps_init get called exactly twice before successfully connecting, or will it just keeps looping like this for X amount of tries before succeeding? If it's always two inits I would guess that the initialization itself is actually called twice, but it could also be that the application waits for X time before retrying to init and connect, and that it just needs more time to connect successfully.

    For the errors, I think you can simply try increasing some of the data buffer configurations in your .conf file to avoid this buffer allocation error.

    Best regards,

    Simon

  • The azure_iot_hub_dps_init gets called precisely twice. When I looked at the code, the azure_iot_hub_connect function in azure_iot_hub.c seems to unnecessarily redo the DPS provisioning process, which should be redundant in this context.

    I'm trying to understand the rationale behind its implementation. Could you clarify if the coding approach was intentional due to its minimal impact or if it might be an oversight? I want to ensure I’m not missing any critical aspects of our development strategy.

    Additionally, I find identifying the appropriate buffer or configuration parameters challenging. Any guidance or resources you could provide to help me navigate these settings would be precious.

    In the meantime, I will continue to explore the Zephyr networking layer in hopes of finding a solution. However, your expert support would expedite this process and enhance my understanding and learning.

    Thank you for your continuous support and exceptional work.

    Looking forward to your insights.

    Best regards,
    Vincent

  • Hi Simonr,

    Did your team finally understand the reason for this bug?

  • Hi again

    We concluded this is not a bug, as azure_iot_dps_init has to be run to initialize the library, and azure_iot_dps_start must be run to start the DPS process. Since there is no connection to the DPS server, the DPS library locates the host name and device ID in the flash memory as part of the DPS process and is in the DPS API, not the connection itself.

    Best regards,

    Simon

Related