Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MQTT client reporting IOTHUB_CLIENT_CONNECTION_NO_NETWORK error even when network connection is fine when handling credential issues #2650

Open
felipe-clay opened this issue Oct 1, 2024 · 0 comments

Comments

@felipe-clay
Copy link

Using latest SDK release LTS_08_2024 and MQTT over websockets protocol

When authenticating using x509 certificate in the MQTT over websockets protocol we use certificates with a limited duration that expire and need to be rotated every once in a while.

However, if the device is still using the old certificate after the current certificate expires it is expected that the SDK client will disconnect and report relevant credential/authentication errors.

What I have observed is that instead the device client will call the connection state callbacks with multiple different error reasons:

<- 01:02:55 PINGRESP
-> 01:03:55 PINGREQ
<- 01:03:55 PINGRESP
-> 01:04:55 PINGREQ
<- 01:04:55 PINGRESP
Error: Time:Mon Sep 30 01:05:36 2024 File:src/iothubtransport_mqtt_common.c Func:processErrorCallback Line:2305 Disconnecting MQTT connection because of an MQTT protocol error (MQTT_CLIENT_PARSE_ERROR).
Error: Time:Mon Sep 30 01:05:36 2024 File:src/uws_client.c Func:uws_client_close_async Line:1809 close has been called when already CLOSED
Error: Time:Mon Sep 30 01:05:36 2024 File:adapters/tlsio_openssl.c Func:decode_ssl_received_bytes Line:896 SSL channel closed in decode_ssl_received_bytes.
Error: Time:Mon Sep 30 01:05:36 2024 File:adapters/tlsio_openssl.c Func:on_underlying_io_bytes_received Line:945 Error in decode_ssl_received_bytes.
20240930T010536.0970Z [�[33mWarning�[39m]:IoTHubLib DeviceClient The device client has been disconnected due to reason IOTHUB_CLIENT_CONNECTION_NO_NETWORK
20240930T010536.0971Z [�[31mError�[39m]:IoTHubLib DeviceClient No connection_state_changed_callback
-> 01:05:37 CONNECT | VER: 4 | KEEPALIVE: 60 | FLAGS: 128 | USERNAME: iq-shared-0-38d07.azure-devices.net/52c1852c-14a0-11ed-98a3-000d3a46ad5a/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.13.0%20(native%3b%20Linux%3b%20armv7l) | CLEAN: 0
<- 01:05:37 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Error: Time:Mon Sep 30 01:05:37 2024 File:src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2142 Connection Not Accepted: 0x5: Not Authorized
Error: Time:Mon Sep 30 01:05:37 2024 File:src/uws_client.c Func:uws_client_close_async Line:1809 close has been called when already CLOSED
Error: Time:Mon Sep 30 01:05:37 2024 File:adapters/tlsio_openssl.c Func:decode_ssl_received_bytes Line:896 SSL channel closed in decode_ssl_received_bytes.
Error: Time:Mon Sep 30 01:05:37 2024 File:adapters/tlsio_openssl.c Func:on_underlying_io_bytes_received Line:945 Error in decode_ssl_received_bytes.
20240930T010537.0491Z [�[33mWarning�[39m]:IoTHubLib DeviceClient The device client has been disconnected due to reason IOTHUB_CLIENT_CONNECTION_BAD_CREDENTIAL
20240930T010537.0492Z [�[31mError�[39m]:IoTHubLib DeviceClient No connection_state_changed_callback
20240930T010537.0492Z [�[33mWarning�[39m]:IoTHubLib DeviceClient The device client has been disconnected due to reason IOTHUB_CLIENT_CONNECTION_NO_NETWORK
20240930T010537.0493Z [�[31mError�[39m]:IoTHubLib DeviceClient No connection_state_changed_callback
Error: Time:Mon Sep 30 01:05:37 2024 File:src/mqtt_client.c Func:sendPacketItem Line:393 Failure sending control packet data
Error: Time:Mon Sep 30 01:05:37 2024 File:src/mqtt_client.c Func:mqtt_client_disconnect Line:1350 Error: mqtt_client_disconnect send failed
-> 01:05:37 CONNECT | VER: 4 | KEEPALIVE: 60 | FLAGS: 128 | USERNAME: iq-shared-0-38d07.azure-devices.net/52c1852c-14a0-11ed-98a3-000d3a46ad5a/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.13.0%20(native%3b%20Linux%3b%20armv7l) | CLEAN: 0
<- 01:05:38 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Error: Time:Mon Sep 30 01:05:38 2024 File:src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2142 Connection Not Accepted: 0x5: Not Authorized
Error: Time:Mon Sep 30 01:05:38 2024 File:src/uws_client.c Func:uws_client_close_async Line:1809 close has been called when already CLOSED
Error: Time:Mon Sep 30 01:05:38 2024 File:adapters/tlsio_openssl.c Func:decode_ssl_received_bytes Line:896 SSL channel closed in decode_ssl_received_bytes.
Error: Time:Mon Sep 30 01:05:38 2024 File:adapters/tlsio_openssl.c Func:on_underlying_io_bytes_received Line:945 Error in decode_ssl_received_bytes.
20240930T010538.0027Z [�[33mWarning�[39m]:IoTHubLib DeviceClient The device client has been disconnected due to reason IOTHUB_CLIENT_CONNECTION_BAD_CREDENTIAL
20240930T010538.0028Z [�[31mError�[39m]:IoTHubLib DeviceClient No connection_state_changed_callback
20240930T010538.0029Z [�[33mWarning�[39m]:IoTHubLib DeviceClient The device client has been disconnected due to reason IOTHUB_CLIENT_CONNECTION_NO_NETWORK
20240930T010538.0029Z [�[31mError�[39m]:IoTHubLib DeviceClient No connection_state_changed_callback
udhcpc: broadcasting discover
Error: Time:Mon Sep 30 01:05:38 2024 File:src/mqtt_client.c Func:sendPacketItem Line:393 Failure sending control packet data
Error: Time:Mon Sep 30 01:05:38 2024 File:src/mqtt_client.c Func:mqtt_client_disconnect Line:1350 Error: mqtt_client_disconnect send failed
-> 01:05:39 CONNECT | VER: 4 | KEEPALIVE: 60 | FLAGS: 128 | USERNAME: iq-shared-0-38d07.azure-devices.net/52c1852c-14a0-11ed-98a3-000d3a46ad5a/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.13.0%20(native%3b%20Linux%3b%20armv7l) | CLEAN: 0
<- 01:05:39 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Error: Time:Mon Sep 30 01:05:39 2024 File:src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2142 Connection Not Accepted: 0x5: Not Authorized
Error: Time:Mon Sep 30 01:05:39 2024 File:src/uws_client.c Func:uws_client_close_async Line:1809 close has been called when already CLOSED
Error: Time:Mon Sep 30 01:05:39 2024 File:adapters/tlsio_openssl.c Func:decode_ssl_received_bytes Line:896 SSL channel closed in decode_ssl_received_bytes.
Error: Time:Mon Sep 30 01:05:39 2024 File:adapters/tlsio_openssl.c Func:on_underlying_io_bytes_received Line:945 Error in decode_ssl_received_bytes.
20240930T010539.0885Z [�[33mWarning�[39m]:IoTHubLib DeviceClient The device client has been disconnected due to reason IOTHUB_CLIENT_CONNECTION_BAD_CREDENTIAL
20240930T010539.0885Z [�[31mError�[39m]:IoTHubLib DeviceClient No connection_state_changed_callback
20240930T010539.0887Z [�[33mWarning�[39m]:IoTHubLib DeviceClient The device client has been disconnected due to reason IOTHUB_CLIENT_CONNECTION_NO_NETWORK
20240930T010539.0887Z [�[31mError�[39m]:IoTHubLib DeviceClient No connection_state_changed_callback

I would expect to get the IOTHUB_CLIENT_CONNECTION_BAD_CREDENTIAL error, however it is always followed by another IOTHUB_CLIENT_CONNECTION_NO_NETWORK a couple of milliseconds after, even if the device internet connection is fine, which makes it really hard to do any error handling over the state. Is this the expected behavior from the SDK or is there something wrong with it?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant