search

Azure / azure-iot-sdk-c

A C99 SDK for connecting devices to Microsoft Azure IoT services
https://azure.github.io/azure-iot-sdk-c
Other
587 stars 739 forks source link

How to do multithreading IoT SDK C? #2320

Closed SatriaPriambada closed 2 years ago

SatriaPriambada commented 2 years ago

Hi I'm interested to run iot-sdk-c on one processing node gateway with multiple device twins instance on separate thread

The reason for this is I want to make another edge node that's very lightweight, have the lightweight node to connect to processing node gateway, then have this processing node connect to Azure IoT Central

I can run the device twin instance for a single thread without problem However as soon as I use pthread to handle start the twin instances I start to have problem with initalizing device 

Info: Locks already initialized
Info: Failed to install static locks in OpenSSL!
Error: Time:Thu Jun 16 14:34:13 2022 File:/home/project/iothub_client/src/iothub.c Func:IoTHub_Init Line:16 Platform initialization failed
Error: Time:Thu Jun 16 14:34:13 2022 File:/home/project/iothub_client/iotcentral/common/pnp_device_client_ll.c Func:PnP_CreateDeviceClientLLHandle Line:65 Failure to initialize client, error=17
Error: Time:Thu Jun 16 14:34:13 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/deviceCategoryId/SENSE.c Func:CreateDeviceClientAndAllocateComponents Line:437 Failure creating IotHub device client
Error: Time:Thu Jun 16 14:34:13 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/deviceCategoryId/SENSE.c Func:startSENSE Line:491 Failure creating IotHub device client
operationSENSE D8:71:4D:55:FF:FF 
Error: Time:Thu Jun 16 14:34:13 2022 File:/home/project/iothub_client/src/iothub_client_core_ll.c Func:IoTHubClientCore_LL_SendEventAsync Line:1745 result = IOTHUB_CLIENT_INVALID_ARG

Not only that I can't seem to send telemetry from already started thread

Info: Locks already initialized
Info: Failed to install static locks in OpenSSL!
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/src/iothub.c Func:IoTHub_Init Line:16 Platform initialization failed
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/common/pnp_device_client_ll.c Func:PnP_CreateDeviceClientLLHandle Line:65 Failure to initialize client, error=17
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/deviceCategoryId/SENSE.c Func:CreateDeviceClientAndAllocateComponents Line:437 Failure creating IotHub device client
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/deviceCategoryId/SENSE.c Func:startSENSE Line:491 Failure creating IotHub device client
operationSENSE D8:71:4D:55:FF:FF 
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/src/iothub_client_core_ll.c Func:IoTHubClientCore_LL_SendEventAsync Line:1745 result = IOTHUB_CLIENT_INVALID_ARG
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/deviceCategoryId/SENSE.c Func:PnP_SENSEComponent_SendWorkingSet Line:334 Unable to send telemetry message, error=1
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/src/iothub_message.c Func:IoTHubMessage_SetProperty Line:545 Failure validating property as ASCII
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/common/pnp_protocol.c Func:PnP_CreateTelemetryMessageHandle Line:117 IoTHubMessage_SetProperty=$.sub failed, error=2
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/component/thermometer/thermometer.c Func:PnP_thermometerComponent_SendTelemetry Line:332 Unable to create telemetry message
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/src/iothub_client_core_ll.c Func:IoTHubClientCore_LL_SendEventAsync Line:1745 result = IOTHUB_CLIENT_INVALID_ARG
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/component/thermometer/thermometer.c Func:PnP_thermometerComponent_SendTelemetry Line:336 Unable to send telemetry message, error=1
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/src/iothub_message.c Func:IoTHubMessage_SetProperty Line:545 Failure validating property as ASCII
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/common/pnp_protocol.c Func:PnP_CreateTelemetryMessageHandle Line:117 IoTHubMessage_SetProperty=$.sub failed, error=2
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/component/voltmeter/voltmeter.c Func:PnP_voltmeterComponent_SendTelemetry Line:342 Unable to create telemetry message
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/src/iothub_message.c Func:IoTHubMessage_SetProperty Line:545 Failure validating property as ASCII
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/common/pnp_protocol.c Func:PnP_CreateTelemetryMessageHandle Line:117 IoTHubMessage_SetProperty=$.sub failed, error=2
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/component/powermeter/powermeter.c Func:PnP_powermeterComponent_SendTelemetry Line:336 Unable to create telemetry message
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/src/iothub_message.c Func:IoTHubMessage_SetProperty Line:545 Failure validating property as ASCII
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/common/pnp_protocol.c Func:PnP_CreateTelemetryMessageHandle Line:117 IoTHubMessage_SetProperty=$.sub failed, error=2
Error: Time:Thu Jun 16 13:51:41 2022 File:/home/project/iothub_client/iotcentral/pnp_kernelplus/data/component/powermeter/powermeter.c Func:PnP_powermeterComponent_SendTelemetry Line:336 Unable to create telemetry message

Given this error is there any help that I can get on how to run multithread twin instances in one processor? If iot-sdk-c is not the best fit for my use case I'm also open to suggestion on how can I create transparent gateway to connect data to Azure IoT Central

Thanks and have a great day!

ericwolz commented 2 years ago

The LL are non-multi threaded APIs as they do not implement thread locks.

Single threaded: IoTHubDeviceClient_LL_SendEventAsync Multi threaded: IoTHubDeviceClient_SendEventAsync

Please see this documentation: https://github.com/Azure/azure-iot-sdk-c/blob/c894993e8cb4fc5171f54b0ed4ab9122824bd6dd/doc/threading_notes.md

SatriaPriambada commented 2 years ago

Hi thanks for the answer and pointing out about the threading documentation!

So is it correct that if I don't use the low level LL functions I can implement a multithreaded clients? I'll definitely try and look into this

While I try to change my function calls, Is there any example code in using azure-iot-sdk-c that doesn't use LL functions? The reason I'm using LL function is because the example in this sdk all uses LL so I thought that it's the way to send data

ericwolz commented 2 years ago

We have both in the sample directory.

https://github.com/Azure/azure-iot-sdk-c/tree/main/iothub_client/samples

Only the iothub_ll_XXXX_sample samples use the LL apis.

SatriaPriambada commented 2 years ago

Thanks! I'll definitely look more into this

SatriaPriambada commented 2 years ago

Hi Eric, Thanks for your suggestion!

I have managed to try not using LL libraries as suggested and successfully create 2 threads for 2 distinct device. Now I can provision different devices (shown in DPS successfully registered), but I still can't send data to the IoT Central. It seems that only the first thread connection can send data and the second thread is always not authorized (error seen below)

Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized

Both of the thread uses SAS Authentication type with distinct value for each device. When I try to run just 1 thread with 1 device there's no problem in connecting and sending and receiving data (this shows that the SAS deviceId, scope, and primary key is indeed valid way to connect to IoT Central and not a typo)

But as soon as I try multithread, only the provision can went through, Data and "Connection" status can only work with the first thread connection and Not Authorized for the other thread

Is there any specific way to authorize for multithreading connection? Or can you help point on where in my IoT Central can I see more logs and reason for MQTT with SAS Authentication gets rejected?

This is more details on my multithreading experiment with Azure IoT SDK C Development Machine Ubuntu 20.04 Linux

SDK Version (1.9.0)

Protocol: MQTT

Full log 

Update Thread List
creating thread for mac D8:71:4D:55:7F:42 to prevConMac
thread id: 0, mac: D8:71:4D:55:7F:42
creating thread for mac D8:71:4D:55:FF:FF to prevConMac
thread id: 1, mac: D8:71:4D:55:FF:FF
D8:71:4D:55:7F:42 
D8:71:4D:55:FF:FF 
getDevUri
getDevScope
getDevId
getDevKey
Info: FINISH DEVICE 1muap6gx74
Info: Initiating DPS client to retrieve IoT Hub connection information
-> 13:37:37 CONNECT | VER: 4 | KEEPALIVE: 0 | FLAGS: 194 | USERNAME: 0ne00490ECC/registrations/1muap6gx74/api-version=2019-03-31&ClientVersion=1.9.0 | PWD: XXXX | CLEAN: 1
<- 13:37:37 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x0
-> 13:37:37 SUBSCRIBE | PACKET_ID: 1 | TOPIC_NAME: $dps/registrations/res/# | QOS: 1
<- 13:37:37 SUBACK | PACKET_ID: 1 | RETURN_CODE: 1
-> 13:37:37 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $dps/registrations/PUT/iotdps-register/?$rid=1 | PAYLOAD_LEN: 86
<- 13:37:37 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_LEAST_ONCE | TOPIC_NAME: $dps/registrations/res/202/?$rid=1&retry-after=3 | PACKET_ID: 2 | PAYLOAD_LEN: 94
-> 13:37:37 PUBACK | PACKET_ID: 2
-> 13:37:40 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $dps/registrations/GET/iotdps-get-operationstatus/?$rid=2&operationId=4.42056a5bc089ef0f.f9eaa0b2-23b2-465a-bc32-cbc8c6ecc544 | PAYLOAD_LEN: 86
<- 13:37:40 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_LEAST_ONCE | TOPIC_NAME: $dps/registrations/res/200/?$rid=2 | PACKET_ID: 2 | PAYLOAD_LEN: 465
-> 13:37:40 PUBACK | PACKET_ID: 2
Info: Provisioning callback indicates success.  iothubUri=iotc-28106cd0-0b05-4d33-885a-14db6a5a5fe9.azure-devices.net, deviceId=1muap6gx74
-> 13:37:40 DISCONNECT
Info: DPS successfully registered.  Continuing on to creation of IoTHub device client handle.
Info: Device Client Init Successfully
Info: Sending serialNumber property to IoTHub
Info: Sending device information property to IoTHub.  propertyName=swVersion, propertyValue="1.0.0.0"
Info: Sending device information property to IoTHub.  propertyName=manufacturer, propertyValue="Sample-Manufacturer"
Info: Sending device information property to IoTHub.  propertyName=model, propertyValue="SENSOR"
Info: Sending device information property to IoTHub.  propertyName=osName, propertyValue="sample-OperatingSystem-name"
Info: Sending device information property to IoTHub.  propertyName=processorArchitecture, propertyValue="Contoso-Arch-64bit"
Info: Sending device information property to IoTHub.  propertyName=processorManufacturer, propertyValue="Processor Manufacturer(TM)"
Info: Sending device information property to IoTHub.  propertyName=totalStorage, propertyValue=10000
Info: Sending device information property to IoTHub.  propertyName=totalMemory, propertyValue=200
Info: Sending maximumTemperatureSinceLastReboot property to IoTHub for component=ambientTemperature
Info: Sending maximumTemperatureSinceLastReboot property to IoTHub for component=caseTemperature
Info: Sending maximumVoltageSinceLastReboot property to IoTHub for component=voltmeter
Info: Sending maximumPowerSinceLastReboot property to IoTHub for component=activeEnergyA
Info: Sending maximumPowerSinceLastReboot property to IoTHub for component=activeEnergyB
operationSENSE D8:71:4D:55:7F:42 
getDevScope
getDevId
getDevKey
Info: DEVICE dj5d9cpzoc
Info: Initiating DPS client to retrieve IoT Hub connection information
-> 13:37:41 CONNECT | VER: 4 | KEEPALIVE: 0 | FLAGS: 194 | USERNAME: 0ne00490ECC/registrations/dj5d9cpzoc/api-version=2019-03-31&ClientVersion=1.9.0 | PWD: XXXX | CLEAN: 1
total length -1 <- 13:37:41 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x0
-> 13:37:41 SUBSCRIBE | PACKET_ID: 1 | TOPIC_NAME: $dps/registrations/res/# | QOS: 1
<- 13:37:41 SUBACK | PACKET_ID: 1 | RETURN_CODE: 1
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $dps/registrations/PUT/iotdps-register/?$rid=1 | PAYLOAD_LEN: 86
-> 13:37:41 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: iotc-28106cd0-0b05-4d33-885a-14db6a5a5fe9.azure-devices.net/1muap6gx74/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20x86_64)&model-id=dtmi%3aenciotDev%3aGAMMASENSE_5d%3b1 | PWD: XXXX | CLEAN: 0
<- 13:37:41 CONNACK | SESSION_PRESENT: true | RETURN_CODE: 0x0
-> 13:37:41 SUBSCRIBE | PACKET_ID: 2 | TOPIC_NAME: $iothub/twin/res/# | QOS: 0 | TOPIC_NAME: $iothub/methods/POST/# | QOS: 0
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_LEAST_ONCE | TOPIC_NAME: devices/1muap6gx74/messages/events/ | PACKET_ID: 3 | PAYLOAD_LEN: 19
total length -1 <- 13:37:41 SUBACK | PACKET_ID: 2 | RETURN_CODE: 0 | RETURN_CODE: 0
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/GET/?$rid=4
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=5 | PAYLOAD_LEN: 36
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=6 | PAYLOAD_LEN: 55
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=7 | PAYLOAD_LEN: 70
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=8 | PAYLOAD_LEN: 55
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=9 | PAYLOAD_LEN: 72
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=10 | PAYLOAD_LEN: 78
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=11 | PAYLOAD_LEN: 86
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=12 | PAYLOAD_LEN: 54
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=13 | PAYLOAD_LEN: 51
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=14 | PAYLOAD_LEN: 65
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=15 | PAYLOAD_LEN: 62
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=16 | PAYLOAD_LEN: 57
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=17 | PAYLOAD_LEN: 61
-> 13:37:41 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=18 | PAYLOAD_LEN: 61
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/200/?$rid=4 | PAYLOAD_LEN: 957
-> 13:37:42 SUBSCRIBE | PACKET_ID: 19 | TOPIC_NAME: $iothub/twin/PATCH/properties/desired/# | QOS: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_LEAST_ONCE | TOPIC_NAME: $dps/registrations/res/202/?$rid=1&retry-after=3 | PACKET_ID: 2 | PAYLOAD_LEN: 94
-> 13:37:42 PUBACK | PACKET_ID: 2
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=5&$version=604 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=7&$version=606 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=6&$version=605 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=8&$version=607 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=10&$version=609 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=9&$version=608 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=11&$version=610 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=13&$version=612 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=14&$version=613 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=12&$version=611 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=16&$version=614 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=15&$version=615 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=17&$version=616 | PAYLOAD_LEN: 0
<- 13:37:42 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=18&$version=617 | PAYLOAD_LEN: 0
<- 13:37:42 SUBACK | PACKET_ID: 19 | RETURN_CODE: 0
<- 13:37:42 PUBACK | PACKET_ID: 3
-> 13:37:44 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $dps/registrations/GET/iotdps-get-operationstatus/?$rid=2&operationId=4.b328e5bf2363c6f2.38843757-3fba-4ab9-a07c-08d87d93b61e | PAYLOAD_LEN: 86
<- 13:37:45 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_LEAST_ONCE | TOPIC_NAME: $dps/registrations/res/200/?$rid=2 | PACKET_ID: 2 | PAYLOAD_LEN: 467
-> 13:37:45 PUBACK | PACKET_ID: 2
Info: Provisioning callback indicates success.  iothubUri=iotc-179638c4-c997-449d-89e7-8a808a116f0b.azure-devices.net, deviceId=dj5d9cpzoc
-> 13:37:45 DISCONNECT
Info: DPS successfully registered.  Continuing on to creation of IoTHub device client handle.
Info: Device Client Init Successfully
Info: Sending serialNumber property to IoTHub
Info: Sending device information property to IoTHub.  propertyName=swVersion, propertyValue="1.0.0.0"
Info: Sending device information property to IoTHub.  propertyName=manufacturer, propertyValue="Sample-Manufacturer"
Info: Sending device information property to IoTHub.  propertyName=model, propertyValue="GAMMA SENSE"
Info: Sending device information property to IoTHub.  propertyName=osName, propertyValue="sample-OperatingSystem-name"
Info: Sending device information property to IoTHub.  propertyName=processorArchitecture, propertyValue="Contoso-Arch-64bit"
Info: Sending device information property to IoTHub.  propertyName=processorManufacturer, propertyValue="Processor Manufacturer(TM)"
Info: Sending device information property to IoTHub.  propertyName=totalStorage, propertyValue=10000
Info: Sending device information property to IoTHub.  propertyName=totalMemory, propertyValue=200
Info: Sending maximumTemperatureSinceLastReboot property to IoTHub for component=ambientTemperature
Info: Sending maximumTemperatureSinceLastReboot property to IoTHub for component=caseTemperature
Info: Sending maximumVoltageSinceLastReboot property to IoTHub for component=voltmeter
Info: Sending maximumPowerSinceLastReboot property to IoTHub for component=activeEnergyA
Info: Sending maximumPowerSinceLastReboot property to IoTHub for component=activeEnergyB
operationSENSE D8:71:4D:55:FF:FF 
-> 13:37:45 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: iotc-179638c4-c997-449d-89e7-8a808a116f0b.azure-devices.net/dj5d9cpzoc/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20x86_64)&model-id=dtmi%3aenciotDev%3aGAMMASENSE_5d%3b1 | PWD: XXXX | CLEAN: 0
<- 13:37:46 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Error: Time:Mon Jun 27 13:37:46 2022 File:/home/satria/Endeavour/KernelPlus_BBB_Application/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
-> 13:37:46 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: iotc-179638c4-c997-449d-89e7-8a808a116f0b.azure-devices.net/dj5d9cpzoc/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20x86_64)&model-id=dtmi%3aenciotDev%3aGAMMASENSE_5d%3b1 | PWD: XXXX | CLEAN: 0
<- 13:37:46 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Error: Time:Mon Jun 27 13:37:46 2022 File:/home/satria/Endeavour/KernelPlus_BBB_Application/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
-> 13:37:47 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: iotc-179638c4-c997-449d-89e7-8a808a116f0b.azure-devices.net/dj5d9cpzoc/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20x86_64)&model-id=dtmi%3aenciotDev%3aGAMMASENSE_5d%3b1 | PWD: XXXX | CLEAN: 0
<- 13:37:47 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Error: Time:Mon Jun 27 13:37:47 2022 File:/home/satria/Endeavour/KernelPlus_BBB_Application/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
-> 13:37:49 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: iotc-179638c4-c997-449d-89e7-8a808a116f0b.azure-devices.net/dj5d9cpzoc/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20x86_64)&model-id=dtmi%3aenciotDev%3aGAMMASENSE_5d%3b1 | PWD: XXXX | CLEAN: 0
<- 13:37:49 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Error: Time:Mon Jun 27 13:37:49 2022 File:/home/satria/Endeavour/KernelPlus_BBB_Application/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
-> 13:37:53 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: iotc-179638c4-c997-449d-89e7-8a808a116f0b.azure-devices.net/dj5d9cpzoc/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20x86_64)&model-id=dtmi%3aenciotDev%3aGAMMASENSE_5d%3b1 | PWD: XXXX | CLEAN: 0
<- 13:37:53 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Error: Time:Mon Jun 27 13:37:53 2022 File:/home/satria/Endeavour/KernelPlus_BBB_Application/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
danewalton commented 2 years ago

Hi @SatriaPriambada On the service side I'm seeing two kinds of logs:

The first is "key not found"

AuthenticationFailed | Details: Key  was not found

The second is "connection closed because a new connection was formed".

[DeviceSession] ClientSessionId:2edd0c34c6f14a72a8ea6ed527465e39, ServiceSessionId:7e9ff25939474298a1a09f211a4829bf, State: ClosedByServerReason: ErrorCode: ConnectionForcefullyClosedOnNewConnection
Message: Backend initiated disconnection.

Are you either not passing the key to the IoT Hub connection or connecting a device with the same credentials twice?

SatriaPriambada commented 2 years ago

Hi Thanks for the response!

  1. I don't think there's a problem with the key When I try to run just 1 thread with 1 device there's no problem in connecting and sending and receiving data (this shows that the SAS deviceId, scope, and primary key is indeed valid way to connect to IoT Central and not a typo) If I do multiple process instead of multi thread I can still connect multiple instance of twins from the same device as well

  2. I can't even connect so I'm not really sure what do you mean by "connection closed because a new connection was formed" Hmm I don't close any connection, this logs even suggest that I can't even connect since the SESSION_PRESENT is false and the device client can't get authenticated

    -> 13:37:45 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: iotc-179638c4-c997-449d-89e7-8a808a116f0b.azure-devices.net/dj5d9cpzoc/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20x86_64)&model-id=dtmi%3aenciotDev%3aGAMMASENSE_5d%3b1 | PWD: XXXX | CLEAN: 0
<- 13:37:46 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5

    For the time being I'll just create multi process instead of multi thread

Thanks and have a great day!