Azure-iot-sdk-c: IOTHUB_CLIENT_CONNECTION_STATUS_REASON is IOTHUB_CLIENT_CONNECTION_OK but IOTHUB_CLIENT_CONNECTION_STATUS being '1'

[suhuruli]

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

Azure Sphere 20.10 OS

SDK Version (Please Give Commit SHA if Manually Compiling)

July LTS

Protocol

MQTT

Describe the Bug
We are noticing that in our callback code, the result and the reason are inconsistent in an environment where are we having frequent disconnect and reconnects. We are seeing the result show up as '1' but the reason being IOTHUB_CLIENT_CONNECTION_OK. We would like to know the proper reason why the connection failed (assuming NO_NETWORK).

Here is a small snippet.

/// <summary>
///     Converts the IoT Hub connection status reason to a string.
/// </summary>
static const char* ErrorToString(IOTHUB_CLIENT_CONNECTION_STATUS_REASON reason)
{
    static char* reasonString = "No reason provided.";
    switch (reason) {
    case IOTHUB_CLIENT_CONNECTION_EXPIRED_SAS_TOKEN:
        reasonString = "IOTHUB_CLIENT_CONNECTION_EXPIRED_SAS_TOKEN";
        break;
    case IOTHUB_CLIENT_CONNECTION_DEVICE_DISABLED:
        reasonString = "IOTHUB_CLIENT_CONNECTION_DEVICE_DISABLED";
        break;
    case IOTHUB_CLIENT_CONNECTION_BAD_CREDENTIAL:
        reasonString = "IOTHUB_CLIENT_CONNECTION_BAD_CREDENTIAL";
        break;
    case IOTHUB_CLIENT_CONNECTION_RETRY_EXPIRED:
        reasonString = "IOTHUB_CLIENT_CONNECTION_RETRY_EXPIRED";
        break;
    case IOTHUB_CLIENT_CONNECTION_NO_NETWORK:
        reasonString = "IOTHUB_CLIENT_CONNECTION_NO_NETWORK";
        break;
    case IOTHUB_CLIENT_CONNECTION_COMMUNICATION_ERROR:
        reasonString = "IOTHUB_CLIENT_CONNECTION_COMMUNICATION_ERROR";
        break;
    case IOTHUB_CLIENT_CONNECTION_OK:
        reasonString = "IOTHUB_CLIENT_CONNECTION_OK";
        break;
    }
    return reasonString;
}

/// <summary>
///     Sets the IoT Hub authentication state for the app
/// </summary>
static void ConnCallback(IOTHUB_CLIENT_CONNECTION_STATUS result,
    IOTHUB_CLIENT_CONNECTION_STATUS_REASON reason,
    void* userContextCallback)
{
    LogDebug("[%s]->info: IoT Hub Authenticated result: %d, reason: %s\n", TAG, result, ErrorToString(reason));
    //...
}

//set connection callback
IoTHubDeviceClient_LL_SetConnectionStatusCallback(iothubClientHandle,ConnCallback, NULL);

Console Logs
"IoTHubClient->info: IoT Hub Authenticated result: 1, reason: IOTHUB_CLIENT_CONNECTION_OK"

[danewalton]

Hi @suhuruli are you able to give more context when this is getting invoked and what you believe is wrong with that scenario?

[suhuruli]

Hi @danewalton , sure!

The reason that is being reported back is IOTHUB_CLIENT_CONNECTION_OK but the result is 1 which indicates the connection is in fact not OK.

This is getting invoked when we are setting up the connection to IoT Hub directly from an Azure Sphere device. Check out this line: https://github.com/Azure/azure-sphere-samples/blob/master/Samples/AzureIoT/main.c#L611.

[danewalton]

More specifically, are you able to find the place in the code where the callback is being invoked where you see this irregularity?
For example here:
https://github.com/Azure/azure-iot-sdk-c/blob/aa1d586546b061ac7451f5f358e50c27fbfa5308/iothub_client/src/iothubtransport_mqtt_common.c#L2470
The reason passed to the callback is IOTHUB_CLIENT_CONNECTION_EXPIRED_SAS_TOKEN. In your case, what macro value was passed to the callback?

[xiongyu0523]

When I get this disconnect callback, I need to know what is wrong and cause this interrupt. But it tells IOTHUB_CLIENT_CONNECTION_OK which is only valid when result is 0. (IOTHUB_CLIENT_CONNECTION_AUTHENTICATED)

From the log I can see the device will be reconnected few seconds after this disconnect callback

[danewalton]

What is the actual number of both result and reason from the code snippet above (copied below):

/// <summary>
///     Sets the IoT Hub authentication state for the app
/// </summary>
static void ConnCallback(IOTHUB_CLIENT_CONNECTION_STATUS result,
    IOTHUB_CLIENT_CONNECTION_STATUS_REASON reason,
    void* userContextCallback)
{
    LogDebug("[%s]->info: IoT Hub Authenticated result: %d, reason: %s\n", TAG, result, ErrorToString(reason));
    //...
}

I think you have said result is 1 but not reason.

[suhuruli]

The reason is IOTHUB_CLIENT_CONNECTION_OK which is an enum that is defined as part of the C SDK.

[danewalton]

I understand that. What I specifically mean is what numerical value is it? IOTHUB_CLIENT_CONNECTION_OK maps to a number. I wanted to confirm that debugged numerical value matches the expected numerical value. We have enum macro's that expand and possibly change the values (like inserting an _INVALID macro at value 0 so that we can double check we aren't setting return values to numbers instead of macro values). If header files get out of sync with source code, those values could be different depending on the header files.

[fanzhe98]

@danewalton
Let me rephrase the problem,
Most of the time the connection status value provide IOTHUB_CLIENT_CONNECTION_AUTHENTICATED (0) with reason IOTHUB_CLIENT_CONNECTION_OK(6) while in some occasion the status value provide IOTHUB_CLIENT_CONNECTION_UNAUTHENTICATED (1) with reason IOTHUB_CLIENT_CONNECTION_OK(6) which is abnormal.

cc. @suhuruli @xiongyu0523

[danewalton]

I see. I did a search through the whole code base and there is no where in the mqtt transport where that combination exists. There is, however, a case in the amqp as show below which we have documented:

In order to be a better help, I would need to see where in the SDK that callback is getting invoked. From this point of view above, there doesn't seem to be a combination which would execute and cause the behavior which you are seeing.

[xiongyu0523]

Yes.. I saw that condition may only happens when AMQP transport is used but in our case, the transport should be MQTT only.

[danewalton]

Are you guys not able to debug into the SDK at all to see where this is getting called? Without that it's difficult to help since from my perspective the SDK doesn't look like it would give that behavior.

[xiongyu0523]

Regarding the mapping, there is no break change in number against the macro.. So header file should always be compatible. The numeric number should be 6. Will try to log the actual number and see if we can capture this later.

@danewalton @fanzhe98 Azure IoT SDK on Sphere is library, I guess we can't trace back the call stack even breakpoint stop here?

[suhuruli]

@danewalton, it looks like we tracked this as an issue with the code snippet we put up there. The use of static for reasonString in combination with the switch statement not being exhaustive to check for all cases (and lacking a default) is attributed to this.

I will close this when we confirm with the customer.

[danewalton]

Hey @suhuruli any follow up here?

[suhuruli]

Hi @danewalton , we can close this since it was confirmed to be addressed based on the code snippet.

[az-iot-builder-01]

@danewalton, @suhuruli, @xiongyu0523, @fanzhe98, thank you for your contribution to our open-sourced project! Please help us improve by filling out this 2-minute customer satisfaction survey

[danewalton]

Awesome thanks @suhuruli !