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

SAS Token cannot be renewed MQTT #2511

Closed ariesgun closed 1 year ago

ariesgun commented 1 year ago

Development Machine, OS, Compiler (and Other Relevant Toolchain Info)

Raspberry Pi Cross Compiled on Debian 9 using GCC 6.3.0

SDK Version (Please Give Commit SHA if Manually Compiling)

Release LTS_07_2022

Protocol

MQTT

Describe the Bug

SAS Token renewal seems not working anymore after I updated the SDK to LTS_07_2022. Previously, when the SAS token expired, it would automatically renew it and as far as i know, this is handled by the SDK directly. With version "LTS_07_2022", it does not work anymore.

To reproduce the issue, I changed the default sas token expiry time from 3600 to 60.

Console Logs

-> 11:05:01 CONNECT | VER: 4 | KEEPALIVE: 90 | FLAGS: 192 | USERNAME: xxx.azure-devices.net/123456789123456/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.1%20(native%3b%20Linux%3b%20armv7l) | PWD: XXXX | CLEAN: 0
<- 11:05:01 CONNACK | SESSION_PRESENT: true | RETURN_CODE: 0x0
>>[2023-07-26 11:05:01.485909] [info] The device client is connected to IoTHub. Result: IOTHUB_CLIENT_CONNECTION_AUTHENTICATED
-> 11:05:01 SUBSCRIBE | PACKET_ID: 2 | TOPIC_NAME: $iothub/twin/res/# | QOS: 0
<- 11:05:19 SUBACK | PACKET_ID: 2 | RETURN_CODE: 0
-> 11:05:20 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/GET/?$rid=3
-> 11:05:39 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_LEAST_ONCE | TOPIC_NAME: devices/123456789123456/messages/events/ | PACKET_ID: 4 | PAYLOAD_LEN: 554
-> 11:05:39 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_LEAST_ONCE | TOPIC_NAME: devices/123456789123456/messages/events/ | PACKET_ID: 5 | PAYLOAD_LEN: 1447
-> 11:05:39 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_LEAST_ONCE | TOPIC_NAME: devices/123456789123456/messages/events/ | PACKET_ID: 6 | PAYLOAD_LEN: 1843
-> 11:05:39 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_LEAST_ONCE | TOPIC_NAME: devices/123456789123456/messages/events/ | PACKET_ID: 7 | PAYLOAD_LEN: 1443
<- 11:05:39 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/200/?$rid=3 | PAYLOAD_LEN: 68
>>[2023-07-26 11:05:39.532717] [info] Device twin update DEVICE_TWIN_UPDATE_COMPLETE: {"desired":{"$version":2,"hello":"world"},"reported":{"$version":1}}
-> 11:05:40 SUBSCRIBE | PACKET_ID: 8 | TOPIC_NAME: $iothub/twin/PATCH/properties/desired/# | QOS: 0
<- 11:05:40 PUBACK | PACKET_ID: 4
<- 11:05:40 PUBACK | PACKET_ID: 5
<- 11:05:40 PUBACK | PACKET_ID: 6
<- 11:05:40 PUBACK | PACKET_ID: 7
-> 11:05:59 DISCONNECT
>>[2023-07-26 11:05:59.580318] [info] The device client has been disconnected. Result: IOTHUB_CLIENT_CONNECTION_UNAUTHENTICATED. Reason: IOTHUB_CLIENT_CONNECTION_EXPIRED_SAS_TOKEN
MQTT_CLIENT_STATUS_NOT_CONNECTED
SendMqttConnectMsg
Token SAS: SharedAccessSignature sr=xxx.azure-devices.net/devices/123456789123456&sig=amtZc0ed%2btGEd2gS6BS4346SBKr33ZBX6JamD%2bVl9xI%3d&se=1690369620
-> 11:06:20 CONNECT | VER: 4 | KEEPALIVE: 90 | FLAGS: 192 | USERNAME: xxx.azure-devices.net/123456789123456/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.1%20(native%3b%20Linux%3b%20armv7l) | PWD: XXXX | CLEAN: 0
Error: Time:Wed Jul 26 11:06:39 2023 File:../../extern/azure-iot-sdk-c/iothub_client/src/iothubtransport_mqtt_common.c Func:UpdateMqttConnectionStateIfNeeded Line:2850 mqtt_client timed out waiting for CONNACK: disconnecting MQTT connection
MQTT_CLIENT_STATUS_NOT_CONNECTED
SendMqttConnectMsg
Token SAS: SharedAccessSignature sr=xxx.azure-devices.net/devices/123456789123456&sig=srNGdX%2b0LTjP2WecwE5TFzsNeERqZHBl%2f6SkRnHkNT8%3d&se=1690369660
Error: Time:Wed Jul 26 11:07:00 2023 File:../../extern/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:onOpenComplete Line:452 Error: failure opening connection to endpoint
Error: Time:Wed Jul 26 11:07:19 2023 File:../../extern/azure-iot-sdk-c/iothub_client/src/iothubtransport_mqtt_common.c Func:UpdateMqttConnectionStateIfNeeded Line:2850 mqtt_client timed out waiting for CONNACK: disconnecting MQTT connection
MQTT_CLIENT_STATUS_NOT_CONNECTED
SendMqttConnectMsg
Token SAS: SharedAccessSignature sr=xxx.azure-devices.net/devices/123456789123456&sig=bS1BBqsd1QaTl8eWEnMezs3Nw15IA97GRxHBprrnYYM%3d&se=1690369700
-> 11:07:40 CONNECT | VER: 4 | KEEPALIVE: 90 | FLAGS: 192 | USERNAME: xxx.azure-devices.net/123456789123456/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.1%20(native%3b%20Linux%3b%20armv7l) | PWD: XXXX | CLEAN: 0
Error: Time:Wed Jul 26 11:07:59 2023 File:../../extern/azure-iot-sdk-c/iothub_client/src/iothubtransport_mqtt_common.c Func:UpdateMqttConnectionStateIfNeeded Line:2850 mqtt_client timed out waiting for CONNACK: disconnecting MQTT connection
MQTT_CLIENT_STATUS_NOT_CONNECTED
SendMqttConnectMsg
Token SAS: SharedAccessSignature sr=xxx.azure-devices.net/devices/123456789123456&sig=nzJUFut4MDM23JK%2bzpH5BQFbEsZw5oXFC743mTQZLhQ%3d&se=1690369740
Error: Time:Wed Jul 26 11:08:20 2023 File:../../extern/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:onOpenComplete Line:452 Error: failure opening connection to endpoint
Error: Time:Wed Jul 26 11:08:39 2023 File:../../extern/azure-iot-sdk-c/iothub_client/src/iothubtransport_mqtt_common.c Func:UpdateMqttConnectionStateIfNeeded Line:2850 mqtt_client timed out waiting for CONNACK: disconnecting MQTT connection
MQTT_CLIENT_STATUS_NOT_CONNECTED
SendMqttConnectMsg
Token SAS: SharedAccessSignature sr=xxx.azure-devices.net/devices/123456789123456&sig=gdfAJZN0DUIaPFZz1sXLlbm2QyfnUtW%2b%2fyhlEXapiiQ%3d&se=1690369780
Info: Closing tlsio from a state other than TLSIO_STATE_EXT_OPEN or TLSIO_STATE_EXT_ERROR
Error: Time:Wed Jul 26 11:08:40 2023 File:../../extern/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:onOpenComplete Line:452 Error: failure opening connection to endpoint
Error: Time:Wed Jul 26 11:09:19 2023 File:../../extern/azure-iot-sdk-c/iothub_client/src/iothubtransport_mqtt_common.c Func:UpdateMqttConnectionStateIfNeeded Line:2850 mqtt_client timed out waiting for CONNACK: disconnecting MQTT connection
MQTT_CLIENT_STATUS_NOT_CONNECTED
SendMqttConnectMsg
Token SAS: SharedAccessSignature sr=xxx.azure-devices.net/devices/123456789123456&sig=z6KP2nhilxaNhy6%2ffxejGkst5WH%2bm2oB1I%2fBiADsR%2bg%3d&se=1690369820
Error: Time:Wed Jul 26 11:09:20 2023 File:../../extern/azure-iot-sdk-c/c-utility/adapters/tlsio_openssl.c Func:tlsio_openssl_send Line:1530 Invalid tlsio_state. Expected state is TLSIO_STATE_OPEN.
Error: Time:Wed Jul 26 11:09:20 2023 File:../../extern/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:sendPacketItem Line:387 Failure sending control packet data
-> 11:09:20 PINGREQ
Error: Time:Wed Jul 26 11:09:39 2023 File:../../extern/azure-iot-sdk-c/c-utility/adapters/tlsio_openssl.c Func:tlsio_openssl_send Line:1530 Invalid tlsio_state. Expected state is TLSIO_STATE_OPEN.
Error: Time:Wed Jul 26 11:09:39 2023 File:../../extern/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:sendPacketItem Line:387 Failure sending control packet data
-> 11:09:39 PINGREQ
Error: Time:Wed Jul 26 11:09:40 2023 File:../../extern/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:onOpenComplete Line:452 Error: failure opening connection to endpoint
-> 11:09:40 PINGREQ