nRF9160DK: MQTT Connection Error - Azure IoT Hub

[Sam]

Hi, 

I have been using the nRF9160-DK sample code to connect my dk to my hosted Azure IoT Hub. I have followed the documentation for creating the certificates for both the CA Cert to put on my IoT Hub and as well the client-side certificate. I used the AT Client to turn off the modem before updating the certificates as told to do so in the documentation and as well testing the certificates using the sample verification and data from that simulation was able to send. However, when trying to do so from the device failed. I am not sure whether this is a certificate issue or a code issue. Please advise. I am not using DPS fyi

I have been troubleshooting for a couple of days now and I can't seem to understand where this issue is coming from. Below is the logging information for what is happening to my device. 

Thanks in advance! 

/resized-image/__size/640x480/__key/communityserver-discussions-components-files/4/Logging.jpg_2D00_640x480.jpg. 

*** Booting Zephyr OS build v3.2.99-ncs2 ***
[00:00:00.531,005] <inf> azure_iot_hub_sample: Azure IoT Hub sample started
[00:00:00.531,127] <inf> azure_iot_hub_sample: Connecting to LTE network
+CEREG: 2,"3BC5","03090216",7
+CSCON: 1
[00:00:16.855,957] <inf> azure_iot_hub_sample: LTE cell changed: Cell ID: 50922006, Tracking area: 15301
[00:00:17.616,760] <inf> azure_iot_hub_sample: RRC mode: Connected
+CEREG: 5,"3BC5","03090216",7,,,"00001010","11000001"
[00:00:20.076,843] <inf> azure_iot_hub_sample: Network registration status: Connected - roaming
[00:00:20.076,995] <inf> azure_iot_hub_sample: Connected to LTE network
[00:00:20.077,056] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_UNINIT --> STATE_DISCONNECTED
[00:00:20.077,056] <inf> azure_iot_hub_sample: Azure IoT Hub library initialized
[00:00:20.077,117] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_DISCONNECTED --> STATE_CONNECTING
[00:00:20.077,148] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_CONNECTING
[00:00:20.077,239] <dbg> azure_iot_hub: azure_iot_hub_connect: User name: HubIoTSZGP.azure-devices.net/iotdemodevice/?api-version=2020-09-30&DeviceClientType=azsdk-c%2F1.4.0-beta.2
[00:00:20.077,270] <dbg> azure_iot_hub: azure_iot_hub_connect: User name buffer size is 128, actual user name size is: 106
[00:00:20.078,521] <inf> azure_iot_hub_sample: PSM parameter update: TAU: 1152000, Active time: 20
[00:00:20.577,545] <err> mqtt_helper: mqtt_connect, error: -111
[00:00:20.577,545] <err> azure_iot_hub: mqtt_helper_connect failed, error: -111
[00:00:20.577,606] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_CONNECTING --> STATE_DISCONNECTED
[00:00:20.577,636] <err> azure_iot_hub_sample: azure_iot_hub_connect failed: -111
+CSCON: 0
[00:00:27.182,922] <inf> azure_iot_hub_sample: RRC mode: Idle

[Sam]

**Update It seems like I have fixed the certificate issue. I am now getting this in my logs however and I still don't see the data in my Azure IoT Hub. 

*** Booting Zephyr OS build v3.2.99-ncs2 ***
[00:00:00.522,186] <inf> azure_iot_hub_sample: Azure IoT Hub sample started
[00:00:00.522,308] <inf> azure_iot_hub_sample: Connecting to LTE network
+CEREG: 2,"3BEB","01610D04",7
+CSCON: 1
+CEREG: 2,"3BEB","01610D04",7,0,11
[00:00:20.043,518] <inf> azure_iot_hub_sample: LTE cell changed: Cell ID: 23137540, Tracking area: 15339
[00:00:20.311,553] <inf> azure_iot_hub_sample: RRC mode: Connected
+CSCON: 0
+CEREG: 2,"874A","0B78580F",7
[00:00:21.653,564] <inf> azure_iot_hub_sample: RRC mode: Idle
[00:00:22.121,490] <inf> azure_iot_hub_sample: LTE cell changed: Cell ID: 192436239, Tracking area: 34634
+CSCON: 1
+CEREG: 2,"874A","0B78580F",7,0,11
[00:00:22.696,289] <inf> azure_iot_hub_sample: RRC mode: Connected
+CSCON: 0
+CEREG: 2,"874A","0B78580F",7
+CSCON: 1
[00:00:24.092,559] <inf> azure_iot_hub_sample: RRC mode: Idle
[00:00:24.284,332] <inf> azure_iot_hub_sample: RRC mode: Connected
+CEREG: 5,"874A","0B78580F",7,,,"00001010","11000001"
[00:00:28.785,552] <inf> azure_iot_hub_sample: Network registration status: Connected - roaming
[00:00:28.785,736] <inf> azure_iot_hub_sample: Connected to LTE network
[00:00:28.785,766] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_UNINIT --> STATE_DISCONNECTED
[00:00:28.785,797] <inf> azure_iot_hub_sample: Azure IoT Hub library initialized
[00:00:28.785,858] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_DISCONNECTED --> STATE_CONNECTING
[00:00:28.785,858] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_CONNECTING
[00:00:28.786,071] <dbg> azure_iot_hub: azure_iot_hub_connect: User name: HubIoTSZGP.azure-devices.net/iotdemodevice/?api-version=2020-09-30&DeviceClientType=azsdk-c%2F1.4.0-beta.2
[00:00:28.786,071] <dbg> azure_iot_hub: azure_iot_hub_connect: User name buffer size is 128, actual user name size is: 106
[00:00:28.787,170] <inf> azure_iot_hub_sample: PSM parameter update: TAU: 1152000, Active time: 20
[00:00:32.657,501] <inf> azure_iot_hub_sample: Connection request sent to IoT Hub
[00:00:32.897,613] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_CONNECTING --> STATE_CONNECTED
[00:00:32.897,613] <dbg> azure_iot_hub: on_connack: MQTT mqtt_client connected
[00:00:32.898,712] <dbg> azure_iot_hub: topic_subscribe: Successfully subscribed to default topics
[00:00:32.898,712] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_CONNECTED
[00:00:33.050,872] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_READY
[00:00:33.050,994] <dbg> azure_iot_hub: request_id_create_and_get: Request ID not specified, using "330"
[00:00:33.051,269] <inf> azure_iot_hub_sample: Sending event:{"temperature":25.1,"timestamp":33051}
[00:00:33.051,757] <dbg> azure_iot_hub: device_twin_request: Device twin requested
[00:00:33.052,307] <inf> azure_iot_hub_sample: Event was successfully sent
[00:00:33.052,337] <inf> azure_iot_hub_sample: Next event will be sent in 20 seconds
[00:00:33.187,774] <wrn> azure_iot_hub: DISCONNECT, result: -128
[00:00:33.187,835] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_CONNECTED --> STATE_DISCONNECTED
[00:00:33.187,866] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_DISCONNECTED
[00:00:33.187,896] <err> mqtt_helper: Cloud MQTT input error: -128
+CSCON: 0
[00:00:38.900,634] <inf> azure_iot_hub_sample: RRC mode: Idle

[Reimer]

Hey Sam,

I am currently experiencing the same problem you encountered.

Therefore I am curious to know how you solved your error: -128. Cant seem to get beyond this issue so it would be a huge help if you could share some information as to how you have resolved the issue.

Kind regards

Reimer    

[Reimer]

Hey Sam,

Thank you for taking the time to respond. Haven't been able to solve it in the meantime so it is greatly appreciated.

I have currently configured the sample to match the deviceID and IDScope with my iot hub and enabled DPS. Used the same security tag 10 and 11, where i have with Baltimore Root ca 10 and Digicert global Root Ca 2 with 11 both as CA certificate. Both have the same Client certificate which at the moment is the Device ca and have previously attempted with combining the client- and intermediate CA. The Private key is the device's private key also for both security tags.

I feel like I should have the correct certificates but it just continues to show the error -128

Sam said:

I had to flash the device with the certificate that nRF provides.

What exactly does this involve? I have made my own RootCa, IntermediateCa, DeviceCa and private keys, do you know if they are unusable?

Are you aware of a specific security tag or something that is preferred or should be avoided.

I am using DPS but it doesn't seem to be a problem to establish that connection.

I'll leave my terminal output, I have tried looking at the Serial terminal instead of LTE Link Monitor which returns some more information.

*** Booting Zephyr OS build v3.3.99-ncs1-1 ***
[00:00:00.508,880] <inf> nrf_modem_lib_trace: Trace thread ready
[00:00:00.510,498] <inf> nrf_modem_lib_trace: Trace level override: 2
[00:00:00.510,528] <inf> azure_iot_hub_sample: Azure IoT Hub sample started
[00:00:00.510,559] <inf> azure_iot_hub_sample: Device ID: testdevice-01
[00:00:00.510,650] <inf> azure_iot_hub_sample: Connecting to LTE network
+CEREG: 2,"36DA","0285B720",7
+CSCON: 1
[00:00:01.550,140] <inf> azure_iot_hub_sample: LTE cell changed: Cell ID: 42317600, Tracking area: 14042
[00:00:01.615,692] <inf> azure_iot_hub_sample: RRC mode: Connected
+CEREG: 5,"36DA","0285B720",7,,,"11100000","11100000"
[00:00:03.170,013] <inf> azure_iot_hub_sample: Network registration status: Connected - roaming
[00:00:03.170,166] <inf> azure_iot_hub_sample: Connected to LTE network
[00:00:03.170,196] <inf> azure_iot_hub_sample: Starting DPS
[00:00:03.170,227] <dbg> azure_iot_hub_dps: dps_reg_id_set: Setting DPS registration ID: testdevice-01
[00:00:03.170,288] <dbg> azure_iot_hub_dps: dps_id_scope_set: No ID scope provided, using ID scope from Kconfig: 0ne00AFEE24
[00:00:03.170,349] <dbg> azure_iot_hub_dps: dps_id_scope_set: Setting DPS ID scope: 0ne00AFEE24
[00:00:03.170,623] <dbg> azure_iot_hub_dps: dps_on_settings_loaded: Settings fully loaded
[00:00:03.170,684] <dbg> azure_iot_hub_dps: dps_state_set: State transition: DPS_STATE_UNINIT --> DPS_STATE_DISCONNECTED
[00:00:03.170,684] <inf> azure_iot_hub_sample: DPS registration status: AZURE_IOT_HUB_DPS_REG_STATUS_NOT_STARTED
[00:00:03.170,745] <dbg> azure_iot_hub_dps: provisioning_client_init: Client ID (size: 13): testdevice-01
[00:00:03.170,928] <inf> azure_iot_hub_sample: PSM parameter update: TAU: 3240, Active time: -1
[00:00:03.171,051] <dbg> azure_iot_hub_dps: provisioning_client_init: User name (size: 62): 0ne00AFEE24/registrations/testdevice-01/api-version=2019-03-31
[00:00:16.021,057] <dbg> azure_iot_hub_dps: dps_state_set: State transition: DPS_STATE_DISCONNECTED --> DPS_STATE_CONNECTING
[00:00:16.021,118] <dbg> azure_iot_hub_dps: timeout_work_restart_timer: Restarting timeout: 90 sec
[00:00:16.021,118] <inf> azure_iot_hub_sample: The DPS process has started, timeout is set to 90 seconds
[00:00:16.113,708] <dbg> azure_iot_hub_dps: dps_state_set: State transition: DPS_STATE_CONNECTING --> DPS_STATE_CONNECTED
[00:00:16.113,708] <dbg> azure_iot_hub_dps: on_connack: MQTT connected
[00:00:16.113,769] <dbg> azure_iot_hub_dps: topic_subscribe: Subscribing to: $dps/registrations/res/#
[00:00:16.114,715] <dbg> azure_iot_hub_dps: topic_subscribe: Successfully subscribed to DPS topics
[00:00:16.114,746] <dbg> azure_iot_hub_dps: timeout_work_restart_timer: Restarting timeout: 90 sec
[00:00:16.275,543] <dbg> azure_iot_hub_dps: dps_send_reg_request: Topic buffer size is 224, actual topic size is: 46
[00:00:16.275,604] <dbg> azure_iot_hub_dps: dps_send_reg_request: Publishing to DPS registration topic: $dps/registrations/PUT/iotdps-register/?$rid=1, no payload
[00:00:16.276,367] <inf> azure_iot_hub_sample: DPS registration status: AZURE_IOT_HUB_DPS_REG_STATUS_ASSIGNING
[00:00:16.276,397] <dbg> azure_iot_hub_dps: timeout_work_restart_timer: Restarting timeout: 90 sec
[00:00:16.421,478] <dbg> azure_iot_hub_dps: timeout_work_restart_timer: Restarting timeout: 90 sec
[00:00:16.600,219] <dbg> azure_iot_hub_dps: timeout_work_restart_timer: Restarting timeout: 90 sec
[00:00:16.600,372] <dbg> azure_iot_hub_dps: handle_reg_update: DPS registration request response received
[00:00:16.600,372] <dbg> azure_iot_hub_dps: handle_reg_update: Status code is 202
[00:00:16.600,402] <dbg> azure_iot_hub_dps: handle_reg_update: Received retry value: 3
[00:00:16.600,433] <dbg> azure_iot_hub_dps: handle_reg_update: Operation ID: 5.4fd4ce520c89aa14.6f403c5b-55bd-4a17-9bdf-a0f3026468f9
[00:00:16.600,463] <inf> azure_iot_hub_sample: DPS registration status: AZURE_IOT_HUB_DPS_REG_STATUS_ASSIGNING
[00:00:19.761,901] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_DISCONNECTED --> STATE_CONNECTING
--- 18 messages dropped ---
[00:00:19.761,932] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_CONNECTING
[00:00:19.761,932] <dbg> azure_iot_hub: azure_iot_hub_connect: Starting DPS, timeout is 90 seconds
[00:00:19.761,993] <dbg> azure_iot_hub_dps: dps_reg_id_set: Setting DPS registration ID: testdevice-01
[00:00:19.762,023] <dbg> azure_iot_hub_dps: dps_id_scope_set: Setting DPS ID scope: 0ne00AFEE24
[00:00:19.762,451] <dbg> azure_iot_hub_dps: dps_settings_handler: Azure IoT Hub hostname length found: 27
[00:00:19.762,847] <dbg> azure_iot_hub_dps: dps_settings_handler: Azure IoT Hub hostname found: SensOrigo.azure-devices.net
[00:00:19.763,122] <dbg> azure_iot_hub_dps: dps_settings_handler: Assigned device ID length found: 13
[00:00:19.763,336] <dbg> azure_iot_hub_dps: dps_settings_handler: Assigned device ID found: testdevice-01
[00:00:19.763,427] <dbg> azure_iot_hub_dps: dps_on_settings_loaded: Settings fully loaded
[00:00:19.763,458] <dbg> azure_iot_hub: dps_handler: AZURE_IOT_HUB_DPS_REG_STATUS_NOT_STARTED
[00:00:19.763,519] <dbg> azure_iot_hub_dps: azure_iot_hub_dps_start: Device "testdevice-01" is assigned to IoT hub: SensOrigo.azure-devices.net
[00:00:19.763,549] <dbg> azure_iot_hub_dps: azure_iot_hub_dps_start: To re-register, call azure_iot_hub_dps_reset() first
[00:00:19.763,549] <dbg> azure_iot_hub: azure_iot_hub_connect: Already assigned to an IoT hub, skipping DPS
[00:00:19.763,610] <dbg> azure_iot_hub_dps: azure_iot_hub_dps_hostname_get: hostname_ptr: 0x200125bf, hostname_len: 27
[00:00:19.763,641] <dbg> azure_iot_hub: azure_iot_hub_connect: Using the assigned hub (size: 27): SensOrigo.azure-devices.net
[00:00:19.763,671] <dbg> azure_iot_hub_dps: azure_iot_hub_dps_device_id_get: dev_id_ptr: 0x2001253f, dev_id_len: 13
[00:00:19.763,732] <dbg> azure_iot_hub: azure_iot_hub_connect: Using the assigned device ID: testdevice-01
[00:00:19.763,824] <dbg> azure_iot_hub: azure_iot_hub_connect: User name: SensOrigo.azure-devices.net/testdevice-01/?api-version=2020-09-30&DeviceClientType=azsdk-c%2F1.4.0-beta.2
[00:00:19.763,854] <dbg> azure_iot_hub: azure_iot_hub_connect: User name buffer size is 160, actual user name size is: 105
[00:00:31.811,279] <inf> azure_iot_hub_sample: Connection request sent to IoT Hub
[00:00:32.017,333] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_CONNECTING --> STATE_CONNECTED
[00:00:32.017,333] <dbg> azure_iot_hub: on_connack: MQTT mqtt_client connected
[00:00:32.018,463] <dbg> azure_iot_hub: topic_subscribe: Successfully subscribed to default topics
[00:00:32.018,463] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_CONNECTED
[00:00:32.106,628] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_READY
[00:00:32.106,842] <inf> azure_iot_hub_sample: Sending event:{"temperature":25.6,"timestamp":32106}
[00:00:32.107,055] <dbg> azure_iot_hub: request_id_create_and_get: Request ID not specified, using "321"
[00:00:32.108,123] <inf> azure_iot_hub_sample: Event was successfully sent
[00:00:32.108,123] <inf> azure_iot_hub_sample: Next event will be sent in 60 seconds
[00:00:32.109,344] <dbg> azure_iot_hub: device_twin_request: Device twin requested
[00:00:32.635,070] <wrn> azure_iot_hub: DISCONNECT, result: -128
[00:00:32.635,131] <dbg> azure_iot_hub: iot_hub_state_set: State transition: STATE_CONNECTED --> STATE_DISCONNECTED
[00:00:32.635,162] <inf> azure_iot_hub_sample: AZURE_IOT_HUB_EVT_DISCONNECTED
[00:00:32.635,162] <err> mqtt_helper: Cloud MQTT input error: -128
+CSCON: 0
[00:00:39.001,556] <inf> azure_iot_hub_sample: RRC mode: Idle
[00:01:32.108,306] <inf> azure_iot_hub_sample: Sending event:{"temperature":25.8,"timestamp":92108}
[00:01:32.108,367] <wrn> azure_iot_hub: Azure IoT Hub is not connected
[00:01:32.108,367] <err> azure_iot_hub_sample: Failed to send event
[00:01:32.108,367] <inf> azure_iot_hub_sample: Next event will be sent in 60 seconds

Kind regards,

Reimer

[Sam]

I see, 

When I used my device, I did not enable DPS. I had DPS disabled. 

Also, at first, I thought I needed to flash the device with the CA root certificate I created. However, this did not work for me. Instead, I flashed the device with ONLY the Baltimore Certificate and uploaded the CA root Certificate to the Azure IoT Certificate upload and from there I verified the certificate from Azure Cloud. 

You may have the correct certificates but placed them in the wrong place. That was the same issue I faced. I am not certain of the advice I am giving you since it was once again 6 months ago, but I am almost certain that error -128 has something to do with the certificate. 

Some good news is that this was the last error I faced until I saw data coming into my Azure IoT Hub. You just need to somehow get the certificate to work from the device to Azure IoT Hub and that's all I remember to be frank with you. 

Sorry in advance if this did not help. 

[Reimer]

Hey Sam,

If possible could you tell/show how you have setup you certificates up if you still have access/can remember? 

I was wondering if I might have to use subordinate certificates from Microsoft: https://github.com/MicrosoftDocs/azure-docs/blob/main/articles/security/fundamentals/azure-CA-details.md#root-and-subordinate-certificate-authority-chains

Kind regards,

Reimer

[Sam]

On my nRF device I used the "Baltimore CyberTrust Root" certificate and then on my Azure IoT Hub, I uploaded myself generated CA root certificate. I verified that certificate on Azure IoT Hub and added the device to the device manager on Azure IoT Hub. 

When you add your device to Azure IoT Hub make sure you have it set for x.509 CA.

Make sure your device name on Azure IoT Hub matches your code, and as well the Azure IoT Hub host name matches. 

Try looking at the images I attached. 

From there the device started working. 

[Reimer]

Hey Sam

Though I already had set it up like that it made me look my IoT hub through again and found out i had a "basic" subscription and when i changed it to "standard" it just worked. 

Really appreciate you taking the time to help me!

Kind regards,

Reimer

[Sam]

Happy to hear that! Best of luck to you.