search

Azure / azure-iot-sdk-node

A Node.js SDK for connecting devices to Microsoft Azure IoT services
https://docs.microsoft.com/en-us/azure/iot-hub/
Other
262 stars 227 forks source link

Device provisioning process terminated without any error #1155

Closed nochtap closed 1 year ago

nochtap commented 1 year ago

Context

Description of the issue

I tried to provision/connect device with X509 cert to Azure IOT Central. The provisioning process immediately terminated without any error message. My expectation would be to get an exception and be able to handle that exception on the client side.

Code sample exhibiting the issue

Repro step:

  1. Generate 3 root certificate (follow this docs: https://learn.microsoft.com/en-us/azure/iot-central/core/how-to-connect-devices-x509?pivots=programming-language-javascript)
  2. 1st-root-cert and 2nd-root-cert upload into the Group enrollment on Azure IOT Central
  3. Generate device certificate with the 3rd-root-cert
  4. Try to connect device with the generated device cert. (using azure-iot-sdk-node/device/samples/javascript/pnp_temperature_controller.js)

Console log of the issue

Here it is the end of the debug log

...
  mqttjs:client sendPacket :: writing to stream +0ms
  mqtt-packet:writeToStream generate called +163ms
  mqtt-packet:writeToStream generate: packet.cmd: puback +0ms
  mqtt-packet:writeToStream writeVarByteInt: writing to stream: <Buffer 02> +0ms
  mqtt-packet:writeToStream writeNumberCached: number: 2 +0ms
  mqtt-packet:writeToStream writeNumberCached: <Buffer 00 02> +0ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  azure-iot-provisioning-device-mqtt:Mqtt message received on $dps/registrations/res/401/?$rid=9bcfc893-8630-4856-96d7-b158fc5b68c2 +164ms
  azure-iot-provisioning-device-mqtt:Mqtt request payload is: {"errorCode":401002,"trackingId":"6567925b-2b8f-4a44-9c11-c1baf3ababdd","message":"CA certificate not found.","timestampUtc":"2022-11-04T06:52:37.6542649Z"} +0ms
  azure-iot-provisioning-device:PollingStateMachine completed transition from sendingRegistrationRequest to responseReceived +479ms
  azure-iot-provisioning-device:PollingStateMachine completed transition from responseReceived to responseError +0ms
  azure-iot-provisioning-device:PollingStateMachine:Errors Response error: UnauthorizedError: incoming message failure +0ms
  azure-iot-provisioning-device:PollingStateMachine completed transition from responseError to idle +0ms
  azure-iot-provisioning-device:PollingStateMachine disconnect called +1ms
  azure-iot-provisioning-device:PollingStateMachine completed transition from idle to disconnecting +0ms
  azure-iot-provisioning-device:PollingStateMachine cancelling query timer +0ms
  azure-iot-provisioning-device-mqtt:Mqtt MQTT State Machine: connected -> disconnecting (connected.disconnect) +2ms
  azure-iot-provisioning-device-mqtt:Mqtt unsubscribing on _disconnect +0ms
  mqttjs:client unsubscribe: call _sendPacket +2ms
  mqttjs:client _sendPacket :: (cert-device-01) ::  start +1ms
  mqttjs:client sendPacket :: packet: {
  mqttjs:client   cmd: 'unsubscribe',
  mqttjs:client   qos: 1,
  mqttjs:client   messageId: 54382,
  mqttjs:client   unsubscriptions: [ '$dps/registrations/res/#' ]
  mqttjs:client } +0ms
  mqttjs:client sendPacket :: emitting `packetsend` +0ms
  mqttjs:client sendPacket :: writing to stream +0ms
  mqtt-packet:writeToStream generate called +3ms
  mqtt-packet:writeToStream generate: packet.cmd: unsubscribe +0ms
  mqtt-packet:writeToStream writeVarByteInt: writing to stream: <Buffer 1c> +0ms
  mqtt-packet:writeToStream writeNumberCached: number: 54382 +0ms
  mqtt-packet:writeToStream writeNumberCached: <Buffer d4 6e> +0ms
  mqtt-packet:writeToStream writeNumberCached: number: 24 +0ms
  mqtt-packet:writeToStream writeNumberCached: <Buffer 00 18> +0ms
  mqtt-packet:writeToStream writeString: $dps/registrations/res/# +0ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  mqttjs:client nop :: undefined +0ms
  mqttjs:client (cert-device-01)stream :: on close +2ms
  mqttjs:client flushVolatile :: deleting volatile messages from the queue and setting their callbacks as error function +0ms
  azure-iot-provisioning-device-mqtt:Mqtt unsubscribed +3ms
  azure-iot-provisioning-device-mqtt:Mqtt:Errors error unsubscribing: Error: Connection closed +0ms
  azure-iot-provisioning-device-mqtt:Mqtt call disconnect on _mqttBase +0ms
  azure-iot-mqtt-base:MqttBase connected -> disconnecting (connected.disconnect) +203ms
  azure-iot-mqtt-base:MqttBase removing all listeners +0ms
  azure-iot-mqtt-base:MqttBase adding null error listener +0ms
  mqttjs:client end :: (cert-device-01) +0ms
  mqttjs:client end :: cb? true +1ms
  mqttjs:client _clearReconnect : clearing reconnect timer +0ms
  mqttjs:client end :: (cert-device-01) :: calling finish in 10ms once outgoing is empty +0ms
  mqttjs:client stream: emit close to MqttClient +0ms
  mqttjs:client close :: connected set to `false` +0ms
  mqttjs:client close :: clearing connackTimer +0ms
  mqttjs:client close :: clearing ping timer +0ms
  mqttjs:client close :: calling _setupReconnect +0ms
  mqttjs:client _setupReconnect :: doing nothing... +0ms

It looks like for me this callback is never called: https://github.com/Azure/azure-iot-sdk-node/blob/main/provisioning/device/src/x509_registration.ts#L77

vishnureddy17 commented 1 year ago

Hi @nochtap, sorry for the delayed response. Can you please check what version of azure-iot-mqtt-base you're using? After investigating, I have a feeling that if you're not already on version 1.13.1, updating would solve the issue. Thanks!

vishnureddy17 commented 1 year ago

Closing due to inactivity. @nochtap, feel free to leave a comment here if you're still experiencing this issue and I'll re-open it.