provisioning fails with token expiry error

[benbrown]

Describe the bug

Sometimes, when I provision an environment with all of the optional resources turned on, it will fail with an error about token expiry during the Cosmos DB step:

CREATE_COSMOSDB_ERROR - Error - The access token expiry UTC time '12/9/2020 8:46:47 PM' is earlier than current UTC time '12/9/2020 8:46:49 PM'. detail message can see provision.benbro-12-09-07.log in your bot folder

Version

wenyluo/provision branch

Browser

• Electron distribution

OS

• macOS

To Reproduce

This happens intermittently when creating provisioning profiles that include ALL of the resources.

Here is the log output:

{
  "profileName": "benbro-test-12-09-04",
  "jobId": "534a2903-cb3a-42fc-b401-08b8737cd5bf",
  "projectId": "86000.80110136497",
  "time": "2020-12-09T19:41:29.065Z",
  "log": [
    "Creating Azure resources...",
    "Checking the Existence of the Resource Group ...",
    "Creating Resource Group ...",
    "> Creating App Registration ...",
    "Start to add password for App, Id : x",
    "> Create App Registration Success! ID: x",
    "Deploying Web App Resource ...",
    "Deploying Bot Resource ...",
    "Deploying Cosmos DB Resource ...",
    "{\"stack\":\"Error: The access token expiry UTC time '12/9/2020 7:50:32 PM' is earlier than current UTC time '12/9/2020 7:50:51 PM'.\\n    at new t (/private/var/folders/kr/5kx0x26x19l2kv9fk18kqk280000gn/T/AppTranslocation/E9EEA2E0-0E30-4533-837B-3AFDA19373F0/d/Bot Framework Composer -- provisioning.app/Contents/Resources/app.asar.unpacked/extensions/azurePublish/lib/node/index.js:659:1580420)\\n    at /private/var/folders/kr/5kx0x26x19l2kv9fk18kqk280000gn/T/AppTranslocation/E9EEA2E0-0E30-4533-837B-3AFDA19373F0/d/Bot Framework Composer -- provisioning.app/Contents/Resources/app.asar.unpacked/extensions/azurePublish/lib/node/index.js:659:1606448\",\"message\":\"The access token expiry UTC time '12/9/2020 7:50:32 PM' is earlier than current UTC time '12/9/2020 7:50:51 PM'.\",\"code\":\"ExpiredAuthenticationToken\",\"statusCode\":401,\"request\":{},\"response\":{\"body\":\"{\\\"error\\\":{\\\"code\\\":\\\"ExpiredAuthenticationToken\\\",\\\"message\\\":\\\"The access token expiry UTC time '12/9/2020 7:50:32 PM' is earlier than current UTC time '12/9/2020 7:50:51 PM'.\\\"}}\"},\"body\":{\"message\":\"The access token expiry UTC time '12/9/2020 7:50:32 PM' is earlier than current UTC time '12/9/2020 7:50:51 PM'.\",\"code\":\"ExpiredAuthenticationToken\"}}",
    "{\"name\":\"CREATE_COSMOSDB_ERROR\",\"message\":\"Error - The access token expiry UTC time '12/9/2020 7:50:32 PM' is earlier than current UTC time '12/9/2020 7:50:51 PM'.\",\"stack\":\"Error\\n    at new n (/private/var/folders/kr/5kx0x26x19l2kv9fk18kqk280000gn/T/AppTranslocation/E9EEA2E0-0E30-4533-837B-3AFDA19373F0/d/Bot Framework Composer -- provisioning.app/Contents/Resources/app.asar.unpacked/extensions/azurePublish/lib/node/index.js:18:96745)\\n    at Object.t.createCustomizeError (/private/var/folders/kr/5kx0x26x19l2kv9fk18kqk280000gn/T/AppTranslocation/E9EEA2E0-0E30-4533-837B-3AFDA19373F0/d/Bot Framework Composer -- provisioning.app/Contents/Resources/app.asar.unpacked/extensions/azurePublish/lib/node/index.js:18:97075)\\n    at e.<anonymous> (/private/var/folders/kr/5kx0x26x19l2kv9fk18kqk280000gn/T/AppTranslocation/E9EEA2E0-0E30-4533-837B-3AFDA19373F0/d/Bot Framework Composer -- provisioning.app/Contents/Resources/app.asar.unpacked/extensions/azurePublish/lib/node/index.js:629:27747)\\n    at /private/var/folders/kr/5kx0x26x19l2kv9fk18kqk280000gn/T/AppTranslocation/E9EEA2E0-0E30-4533-837B-3AFDA19373F0/d/Bot Framework Composer -- provisioning.app/Contents/Resources/app.asar.unpacked/extensions/azurePublish/lib/node/index.js:629:12347\\n    at Object.throw (/private/var/folders/kr/5kx0x26x19l2kv9fk18kqk280000gn/T/AppTranslocation/E9EEA2E0-0E30-4533-837B-3AFDA19373F0/d/Bot Framework Composer -- provisioning.app/Contents/Resources/app.asar.unpacked/extensions/azurePublish/lib/node/index.js:629:12452)\\n    at s (/private/var/folders/kr/5kx0x26x19l2kv9fk18kqk280000gn/T/AppTranslocation/E9EEA2E0-0E30-4533-837B-3AFDA19373F0/d/Bot Framework Composer -- provisioning.app/Contents/Resources/app.asar.unpacked/extensions/azurePublish/lib/node/index.js:629:11217)\"}",
    "CREATE_COSMOSDB_ERROR - Error - The access token expiry UTC time '12/9/2020 7:50:32 PM' is earlier than current UTC time '12/9/2020 7:50:51 PM'.\n        detail message can see provision.benbro-test-12-09-04.log in your bot folder"
  ]
}

[benbrown]

I wonder if this is caused by the token expiring mid-way through the provision process. Can we refresh the token more regularly?

[boydc2014]

supposed to be fixed, according to @luhan2017