Search code examples
c#azureasp.net-corebotframeworkmicrosoft-teams

Working Bot Framework Bot as an Azure Web App suddenly with no configuration changes hitting SecurityTokenSignatureKeyNotFoundException: IDX10501


I've been training myself to build a bot as integration with MS Teams.

I've followed the tutorials for building a simple echo bot, and have further used the Visual Studio 2019 add in for the Bot Framework version 4 on top of .Net Core 3.1.

Over a week ago, I had two working bots using the framework and doing very simple tasks.

Bot bots were deployed as Azure Web Apps - I could type something into the Teams Chat and the bot would respond with something. All good.

Today, after about 24 hours away from my project, the same chat attempt in the same teams instance using the same web app and passing the same credentials (App ID and App Password) they have just ceased working. From logs, I can see that the category named Microsoft.AspNetCore.Server.IIS.Core.IISHttpServer has detected an unhandled exception with the event ID ApplicationError and the log message Connection ID "15924728283992716557", Request ID "8000750e-0000-dd00-b63f-84710c7967bb": An unhandled exception was thrown by the application.

The exception itself follows:

Microsoft.IdentityModel.Tokens.SecurityTokenSignatureKeyNotFoundException: IDX10501: Signature validation failed. Unable to match key: 
kid: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
Exceptions caught:
 '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'. 
token: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateSignature(String token, TokenValidationParameters validationParameters)
   at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateToken(String token, TokenValidationParameters validationParameters, SecurityToken& validatedToken)
   at Microsoft.Bot.Connector.Authentication.JwtTokenExtractor.ValidateTokenAsync(String jwtToken, String channelId, String[] requiredEndorsements)
   at Microsoft.Bot.Connector.Authentication.JwtTokenExtractor.GetIdentityAsync(String scheme, String parameter, String channelId, String[] requiredEndorsements)
   at Microsoft.Bot.Connector.Authentication.JwtTokenExtractor.GetIdentityAsync(String authorizationHeader, String channelId, String[] requiredEndorsements)
   at Microsoft.Bot.Connector.Authentication.ChannelValidation.AuthenticateChannelToken(String authHeader, ICredentialProvider credentials, HttpClient httpClient, String channelId, AuthenticationConfiguration authConfig)
   at Microsoft.Bot.Connector.Authentication.ChannelValidation.AuthenticateChannelToken(String authHeader, ICredentialProvider credentials, String serviceUrl, HttpClient httpClient, String channelId, AuthenticationConfiguration authConfig)
   at Microsoft.Bot.Connector.Authentication.JwtTokenValidation.AuthenticateTokenAsync(String authHeader, ICredentialProvider credentials, IChannelProvider channelProvider, String channelId, AuthenticationConfiguration authConfig, String serviceUrl, HttpClient httpClient)
   at Microsoft.Bot.Connector.Authentication.JwtTokenValidation.ValidateAuthHeader(String authHeader, ICredentialProvider credentials, IChannelProvider channelProvider, String channelId, AuthenticationConfiguration authConfig, String serviceUrl, HttpClient httpClient)
   at Microsoft.Bot.Connector.Authentication.JwtTokenValidation.AuthenticateRequest(IActivity activity, String authHeader, ICredentialProvider credentials, IChannelProvider provider, AuthenticationConfiguration authConfig, HttpClient httpClient)
   at Microsoft.Bot.Builder.BotFrameworkAdapter.ProcessActivityAsync(String authHeader, Activity activity, BotCallbackHandler callback, CancellationToken cancellationToken)
   at Microsoft.Bot.Builder.Integration.AspNet.Core.BotFrameworkHttpAdapter.ProcessAsync(HttpRequest httpRequest, HttpResponse httpResponse, IBot bot, CancellationToken cancellationToken)
   at EchoBot1.Controllers.BotController.PostAsync() in C:\Ops\Development\Users\Stephan\EchoBot1\EchoBot1\Controllers\BotController.cs:line 34
   at lambda_method(Closure , Object )
   at Microsoft.Extensions.Internal.ObjectMethodExecutorAwaitable.Awaiter.GetResult()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Awaited|12_0(ControllerActionInvoker invoker, ValueTask`1 actionResultValueTask)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|19_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT`1.ProcessRequestAsync()

Every entry in that stack trace is part of either Asp .Net Core framework OR the Bot Framework. The only exception is the entry:

at EchoBot1.Controllers.BotController.PostAsync() in C:\Ops\Development\Users\Stephan\EchoBot1\EchoBot1\Controllers\BotController.cs:line 34

Unsurprisingly the code at line 34 in my controller is:

    [HttpPost, HttpGet]
    public async Task PostAsync()
    {
        // Delegate the processing of the HTTP POST to the adapter.
        // The adapter will invoke the bot.
        await Adapter.ProcessAsync(Request, Response, Bot);  // LINE 34 - EXCEPTION HERE
    }

This code is exactly as scaffolded by Visual Studio when using the Bot Framework v4.

This is a bit disappointing because my understanding is that one of the main benefits to the Bot Framework is that it provides the necessary security handshake, but when it doesn't work I'm completely in the dark about how to even start debugging this.

I would appreciate any insights about process to find the problem or any experience of others who have encountered this. Thanks.

============ EDIT- ADDING ADDITIONAL INFO INITALLY OBSCURED =============

In the exception I quoted in the initial question, various elements were obscured as per Microsoft's GDPR policy. I followed the following instructions to "unobscure" them: https://aka.ms/IdentityModel/PII

With that, I got this additional information that would suggest no exceptions in the processing beyond inability to match the security key to the hash. (Which I have confirmed is correct).

Here is the additional information, just obscured a little bit by me manually:

Microsoft.IdentityModel.Tokens.SecurityTokenSignatureKeyNotFoundException: IDX10501: Signature validation failed. Unable to match key: 
kid: 'KeyIHaveObsuredPresumablyFailsToMatchHash'.
Exceptions caught:
 ''. 
token: '{"alg":"RS256","kid":"KeyIHaveObsuredPresumablyFailsToMatchHash","typ":"JWT","x5t":"KeyIHaveObsuredPresumablyFailsToMatchHash"}.{"serviceurl":"https://smba.trafficmanager.net/amer/","nbf":1628123535,"exp":1628127135,"iss":"https://api.botframework.com","aud":"CorrectAppIdGuid"}'.

.... And Stack Trace as before ....

Solution

  • ADDITIONAL UPDATE FROM MICROSOFT Aug 20, 2021 Not a very satisfying answer, but I suspect it is all I am going to get:

    The issue occurred because of a configuration change which was made internally pertaining to the endpoints which has the public keys. This caused the keys to be missing from the well-known keys storage. But this has been fixed now and proper steps have been taken to ensure that the existing keys remain un-impacted.

    Additionally...

    Normally outage information regarding azure resources are published in the status link I have shared earlier. So in future, if in general some major issue happens owing to which resources are down we can expect it to be updated there.

    Finally w.r.t. Defensive Programming:

    Pertaining to this specific error, any exception handling might not solve the issue , max it can identify the issue. Reason is this was for some configuration change in the storage.

    UPDATE FROM MICROSOFT Aug 9, 2021: Microsoft has acknowledged that this was an infrastructural error on their end where the security key was absent. They are still working on a Root Cause Analysis. I have asked for a copy and have also asked some additional questions about frequency, expectation, status, and defensive programming. I'll post more of note if and when I get it.

    ORIGINAL ANSWER Aug 5, 2021: As per previous answer and a kind comment to the initial post, today the problem went away on its own. This had been affecting two of my apps/bots - one of them cleared itself up entirely, and the other cleared up after I (again) restarted the app service. To be clear, I had restarted the app service a couple of times (and even redeployed) before posting this question in the first place some 14 hours ago. But now everything is working again.