iothub Registry service client fromTokenCredential does not refresh token and it expire after days

[leoluKL]

I notice the registry service created from token credential (in this case the managed identity credential) does not renew token that cause SDK fail day after registry client being created. To reproduce, use node as example, -create a web app -turn on its managed identity -assign iot hub role "IoT Hub Registry Contributor" -add below code in web app index.js const iothub = require('azure-iothub'); const { DefaultAzureCredential} = require("@azure/identity"); const credential = new DefaultAzureCredential(); const iothubRegistry = new iothub.Registry.fromTokenCredential(process.env.IoTHubEndpoint,credential)

-use the iothubRegistry variable to invoke sdk such as creating device registry. It will work for a while, but day after it will pop out error such as "Token Expired. ValidTo: 7/7/2021 7:37:10 AM"

[vishnureddy17]

Hi @leolumicrosoft, DefaultAzureCredential tries to authenticate with different authentication mechanisms in a certain order until there is one that works. The section on DefaultAzureCredential in the @azure/identity README gives more information on this. Which mechanism is being used in your scenario?

Also you say that you are creating a web app. Just to confirm, you are running our SDK in the Node.js runtime, right? We do not support running in the browser.

[leoluKL]

In my case it is managed identity. I used sdk in an app service. What I did is to turn on system managed identity of my app service, then in the RBAC blade of iot hub, I assign "IoT Hub Registry Contributor" to the managed identity of my app service.

To clarify my question: I invoke iothub.Registry.fromTokenCredential only one time when the app service starts, then the generated iot hub registry client is used for responding subsequent http request to my app service. If my suspect is true that the generated iot hub registry client does not refresh its token after its creation, it will not able to access iot hub after the token expire.

[vishnureddy17]

I'm attempting to reproduce this. For your app service, what runtime stack and operating system are you using? @leolumicrosoft

EDIT: Also, when this error occurs, how does it get surfaced to you? i.e., does it return the error through the callback or promise rejection when you invoke the SDK client methods, does it get printed out directly, or something else?

[leoluKL]

My app service uses node 14 LTS. APP service plan(P1V2:1) OS is linux

When the error happens, app service invokes IoTHub sdk api is doing things such as registering a new device, updating device twin and so on. The operation will fail and output error message as ""Token Expired. ValidTo: .... This error message is captured when executing a promise function that uses SDK api such as registering a new device. "iothubRegistry.create({"deviceId":deviceID})"

[vishnureddy17]

@leolumicrosoft , what version of @azure/identity are you using? If you are using an older version, can you try seeing if version 1.5.0 resolves the issue?

If so, we will update our package dependency to the newer version of @azure/identity.

[leoluKL]

I confirm the defect is still there. I have used 1.5 azure identity library. Error is the same PS: the error message is the original error message coming from SDK registering device API iothubRegistry.create({"deviceId":deviceID})

[vishnureddy17]

Just an update, I have an app service instance running and I'm trying to repro the issue. So far, the token refreshed after a day without issue. I'll keep it running for another day to see if I can recreate the problem.

[leoluKL]

Hi, do you mind to use this sample folder as code base and deploy it to app service and test. I minimize my code to this folder that it can reproduce the issue. There is a iothubHelper class in it that will run only once after http server start. that means Registry.fromTokenCredential is also only executed for one time

https://github.com/leolumicrosoft/ADTUI/tree/master/iothubSDKIssue

[vishnureddy17]

Yep, the token refreshed after another day without issue in my example.

Thank you very much for providing that sample—I will go ahead and try it out.

[vishnureddy17]

Hi @leolumicrosoft , in your sample, the token seems to successfully refresh on my end. Here's what I did:

1. Create an app service web app (Linux, Node 14, P1V2)
2. Enable system assigned managed identity on the app service
3. Give the system assigned managed identity the "IoT Hub Registry Contributor Role"
4. Run NPM install on my local machine for your sample, which should use your package-lock.json file to install the exact versions of the dependencies that you are using
5. Deploy the sample to the app service via FTP

I made a minor change to the code to help with my debugging, which was including the token expiration timestamp in the response body for provisionDevice. This wouldn't affect the token refresh though:

routerControlPlane.prototype.provisionDevice =async function(req,res) {
    var deviceID=req.body.deviceID
    var tags=req.body.tags
    var desiredProperties= req.body.desiredProperties

    try{
        try{
            await iothubHelper.iothubRegistry.get(deviceID)
        }catch(e){ //if the device is not registered yet, really provision it
            await iothubHelper.iothubRegistry.create({"deviceId":deviceID})
            await iothubHelper.iothubRegistry.updateTwin(deviceID
            ,{
                "tags":tags,
                "properties":{
                    "desired":desiredProperties
                }
            }
            ,"*")
        }
        res.send(`Device created with ID ${deviceID}. Expiry: ${iothubHelper.iothubRegistry._restApiClient._accessToken.expiresOnTimestamp}`) //
    }catch(e){
        res.status(400)
        if (Date.now() > iothubHelper.iothubRegistry._restApiClient._accessToken.expiresOnTimestamp) {
            res.send(`USED EXPIRED TOKEN (${iothubHelper.iothubRegistry._restApiClient._accessToken.expiresOnTimestamp}): ${e}`)
        } else {
            res.send(`Device create failed (${iothubHelper.iothubRegistry._restApiClient._accessToken.expiresOnTimestamp}): ${e}`)
        }
    }
}

Then I make requests to the app service similar to your Postman screenshot earlier. Token refresh seems to work as expected. Is there anything else I could do to more faithfully recreate your scenario?

[leoluKL]

Thank you. I did not know those "underscore" hidden properties. Let me try again with your added log information in my environment and I will let you know. If it works in your side, my hypothesis is it might be a problem only happens when the involved IoTHub service has completely zero activity for more than one day, if it happens again. I recall i saw this issue at weekends and since this a development environment so the iot hub service is idle without any device connecting to it.

I will do two more tests and respond you my observation next week. Have a good week end.

[leoluKL]

My previous hypothesis is proven by the two new tests. The token update issue will happen if there is no activity before the initial token expires. If there is an API call happening around 6 hours before the token expire, it will be renewed, but if you wait really after the expiration time and then call API such as provisioning a deviceid, it will fail.

My test 1: The initial token was created on Sat and it would expired at Sunday, August 1, 2021 11:46:52 AM GMT+08:00 I tested calling API after the expiration time and I got error : USED EXPIRED TOKEN (1627789612000): UnauthorizedError: Token Expired. ValidTo: 8/1/2021 3:46:52 AM

My test 2: I repeated the test, but this time i did not wait till the token expire. I called the api about six hours before expiration. The initial token expiration is 1627901758000 this token was reused until about 6 hours before the expiration time, when i called api again, it is automatically extended to 1627964268000. This means from initial Aug 2, 7pm extending to Aug 3, 12pm.

So if you want to reproduce the issue, you need to never invoke any API call from about 6hours before till the token expiration time. After it expires, you try calling api and you will see this issue.

[vishnureddy17]

Thank you. I did not know those "underscore" hidden properties. Let me try again with your added log information in my environment and I will let you know.

Yeah, the properties with the underscore in front are for internal use only. In general, I would recommend not accessing these properties, but in this case it's useful for debugging.

Thanks for running those tests! That is very useful, and I will investigate more.

[vishnureddy17]

Just an update, I was able to repro this. We found the likely culprit of the bug, and I'm working on a fix for it. Our next release should have a fix for this bug.

[vishnureddy17]

@leolumicrosoft, the most recent versions of the Azure IoT SDK packages should no longer have this issue. Please let me know if this fixes the issue for you.

[leoluKL]

I confirm the issue has been resolved with release 1.14.3. Thank you.

[vishnureddy17]

Great, thank you for helping me investigate this! Closing the issue now.