Bot Stops Working After Organization-Wide Deployment of Microsoft Teams App

[lgtm-ed]

Steps to reproduce

Description:
When the Microsoft Teams App package is deployed by distributing it to the organization, the bot ceases to function after some time. The Azure server logs indicate a 500 Internal Server Error.

Steps to Reproduce:
Deploy the Microsoft Teams App package to the organization via the admin center.
Use the bot functionality for some time.
Observe that the bot eventually stops responding.
Check Azure server logs, which show a 500 Internal Server Error.

Expected Behavior:
The bot should continue functioning without interruptions post-organization-wide deployment.

Actual Behavior:
The bot stops working, and Azure logs show a 500 Internal Server Error.

Expected behavior

These are the application logs from the Log Stream for the App Service.

2025-01-16 14:36:44 ~1NOTIFICATIOND88135 GET / - 80 - 10.0.32.18 AlwaysOn - - notificationd88135.azurewebsites.net 200 0 0 3392 475 22927
2025-01-16 14:36:44 ~1NOTIFICATIOND88135 GET / - 80 - 10.0.32.18 AlwaysOn - - notificationd88135.azurewebsites.net 200 0 0 3392 475 12783
2025-01-16 14:36:44 NOTIFICATIOND88135 POST /api/messages X-ARR-LOG-ID=285b14b1-09db-4e2f-879e-a8f2575d3290 443 - 52.112.76.0 Microsoft-SkypeBotApi+(Microsoft-BotFramework/3.0) - - notificationd88135.azurewebsites.net 200 0 0 358 3613 3846
2025-01-16 14:36:51 ~1NOTIFICATIOND88135 GET / - 80 - 10.0.32.18 AlwaysOn - - notificationd88135.azurewebsites.net 200 0 64 0 475 18
2025-01-16 14:36:51 NOTIFICATIOND88135 GET / X-ARR-LOG-ID=fd9702b3-e5ae-4533-baa2-103c90f19b1f 443 - 127.0.0.1 AlwaysOn ARRAffinity=013a31477018208d1d9a6a5265db9b280dcea0fe6b36fa395321a7acf41f0bfc - notificationd88135.azurewebsites.net 404 0 0 466 896 42
2025-01-16 14:37:01 ~1NOTIFICATIOND88135 GET / - 80 - 10.0.32.18 AlwaysOn - - notificationd88135.azurewebsites.net 200 0 64 0 475 110
2025-01-16 14:37:01 NOTIFICATIOND88135 GET / X-ARR-LOG-ID=913e800d-6d57-4fd0-b6ca-b908b5c4b17a 443 - 127.0.0.1 AlwaysOn ARRAffinity=013a31477018208d1d9a6a5265db9b280dcea0fe6b36fa395321a7acf41f0bfc - notificationd88135.azurewebsites.net 404 0 0 466 896 51
2025-01-16 14:37:18 NOTIFICATIOND88135 POST /api/messages X-ARR-LOG-ID=3f09952b-c60b-45aa-9105-26a94e7d8236 443 - 52.112.106.2 Microsoft-SkypeBotApi+(Microsoft-BotFramework/3.0) - - notificationd88135.azurewebsites.net 200 0 0 358 3631 7449

Actual behavior

These are the application logs from the Log Stream for the App Service.

2025-01-16 14:28:20 ~1NOTIFICATIOND88135 GET / - 80 - 10.0.32.18 AlwaysOn - - notificationd88135.azurewebsites.net 200 0 0 3382 475 21
2025-01-16 14:28:36 NOTIFICATIOND88135 GET / X-ARR-LOG-ID=6ac6e752-af68-4084-a855-6dd7021424e3 443 - 127.0.0.1 AlwaysOn ARRAffinity=013a31477018208d1d9a6a5265db9b280dcea0fe6b36fa395321a7acf41f0bfc - notificationd88135.azurewebsites.net 500 1001 64 0 894 54495
2025-01-16 14:28:45 NOTIFICATIOND88135 OPTIONS /api/messages X-ARR-LOG-ID=939611b6-0639-4183-a5a4-ba0f8d21660a 443 - 71.167.33.30 Mozilla/5.0+(Macintosh;+Intel+Mac+OS+X+10_15_7)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/131.0.0.0+Safari/537.36 - - notificationd88135.azurewebsites.net 500 1001 2 352 1330 55189
2025-01-16 14:29:04 NOTIFICATIOND88135 GET / X-ARR-LOG-ID=f5c62fa6-67c7-4688-a1bc-3ac7462ca299 443 - 127.0.0.1 AlwaysOn ARRAffinity=013a31477018208d1d9a6a5265db9b280dcea0fe6b36fa395321a7acf41f0bfc - notificationd88135.azurewebsites.net 500 1001 64 0 894 54081
2025-01-16 14:29:12 NOTIFICATIOND88135 GET / X-ARR-LOG-ID=1fd868d7-7a8e-4dec-8760-b5f7e991868b 443 - 127.0.0.1 AlwaysOn ARRAffinity=013a31477018208d1d9a6a5265db9b280dcea0fe6b36fa395321a7acf41f0bfc - notificationd88135.azurewebsites.net 500 1001 64 0 894 52053

2025-01-16 14:31:49 NOTIFICATIOND88135 POST /api/messages X-ARR-LOG-ID=ae96c575-c3fc-4263-a2cd-82a1c1db8a0f 443 - 52.112.76.0 Microsoft-SkypeBotApi+(Microsoft-BotFramework/3.0) - - notificationd88135.azurewebsites.net 500 1001 64 0 3039 51775
2025-01-16 14:31:49 NOTIFICATIOND88135 POST /api/messages X-ARR-LOG-ID=17fb96f4-2f71-466a-9ba5-c19f36ff4fd4 443 - 52.112.76.0 Microsoft-SkypeBotApi+(Microsoft-BotFramework/3.0) - - notificationd88135.azurewebsites.net 500 1001 64 0 3135 51781
2025-01-16 14:31:56 NOTIFICATIOND88135 POST /api/messages X-ARR-LOG-ID=7a22765b-fab4-476b-8853-a594008056e0 443 - 52.112.76.0 Microsoft-SkypeBotApi+(Microsoft-BotFramework/3.0) - - notificationd88135.azurewebsites.net 500 1001 64 0 3618 51567

Error details

For some reason the server is erroring out with a 500 error. Is there any explanation for this behavior?

Note: We noticed that we were able to deploy our application to the Teams App Store without review.

[Prasad-MSFT]

Hi @lgtm-ed, thanks for raising your issue. When a bot stops working after an organization-wide deployment of a Microsoft Teams app and you encounter a 500 Internal Server Error in the Azure server logs, it indicates that there might be an issue with the bot's backend or configuration.

• Ensure that the bot's Azure Bot Service configuration is correct, including the messaging endpoint URL.
• Verify that the bot's App ID and password are correctly configured in the Azure Bot Service and in your bot's code.
• Check if there are any issues with the authentication tokens or if they are expiring unexpectedly.

Test the bot in isolation (e.g., in a development environment) to ensure that it works correctly outside of the organization-wide deployment. This can help identify if the issue is specific to the deployment process or configuration.

[lgtm-ed]

Why is it that it works for a few hours after deployment to the organization and then stops working? There are no changes to the configuration during that time.

[Prasad-MSFT]

Hi @lgtm-ed, could you please ensure that your App Service is not hitting any resource limits such as CPU, memory, or disk space? You can monitor these metrics in the Azure portal. Sometimes, simply restarting the App Service or redeploying the application can resolve transient issues. Try these steps to see if they help.

If not, please do share bot-id, timestamp along with logs, so that we can investigate further.

[lgtm-ed]

There are no issues with CPU, memory, or disk space.

Here is the bot_id: 4b0e45c3-f82d-4ed0-8306-c9f774f22077

Here are the error logs:

Tue Jan 07 2025 05:31:10 GMT+0000 (Coordinated Universal Time): Disabling Azure Drive logging after 43200000ms since it was enabled
Wed Jan 08 2025 18:34:03 GMT+0000 (Coordinated Universal Time): Disabling Azure Drive logging after 43200000ms since it was enabled
Thu Jan 09 2025 07:17:38 GMT+0000 (Coordinated Universal Time): Application has thrown an uncaught exception and is terminated:
TypeError: Cannot perform 'set' on a proxy that has been revoked
at Proxy. (C:\home\site\wwwroot\node_modules\botbuilder-core\lib\turnContext.js:392:36)
at Generator.next ()
at fulfilled (C:\home\site\wwwroot\node_modules\botbuilder-core\lib\turnContext.js:9:58)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Fri Jan 10 2025 17:14:44 GMT+0000 (Coordinated Universal Time): Disabling Azure Drive logging after 43200000ms since it was enabled
Mon Jan 13 2025 04:44:02 GMT+0000 (Coordinated Universal Time): Application has thrown an uncaught exception and is terminated:
TypeError: Cannot perform 'set' on a proxy that has been revoked
at Proxy. (C:\home\site\wwwroot\node_modules\botbuilder-core\lib\turnContext.js:392:36)
at Generator.next ()
at fulfilled (C:\home\site\wwwroot\node_modules\botbuilder-core\lib\turnContext.js:9:58)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Fri Jan 17 2025 02:36:49 GMT+0000 (Coordinated Universal Time): Disabling Azure Drive logging after 43200000ms since it was enabled

[Prasad-MSFT]

Hi @lgtm-ed, thanks for providing these details. We have raised an ICM for this issue. Once we get any update from engineering team, we will update in this thread. Additionally, if you can provide tenant id, HAR files it would be helpful for us.

[lgtm-ed]

Here is the tenant id: f434e6e2-3197-4d35-9653-c4835fd6fbe3

Where can I get the HAR File?