Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Can you add a log line for this exception? #6577

Closed
sandrock opened this issue Jan 17, 2023 · 1 comment · Fixed by #6587
Closed

Can you add a log line for this exception? #6577

sandrock opened this issue Jan 17, 2023 · 1 comment · Fixed by #6587
Assignees
Labels
Bot Services Required for internal Azure reporting. Do not delete. Do not change color. customer-reported Issue is created by anyone that is not a collaborator in the repository. feature-request A request for new functionality or an enhancement to an existing one.

Comments

@sandrock
Copy link

My bot does not work for an obscure authentication reason. I believe the runtime goes into this line of code.

Can someone add a logger.LogWarning call with detailled info so I can know what is happening?

catch (UnauthorizedAccessException)
{
    // handle unauthorized here as this layer creates the http response
    httpResponse.StatusCode = (int)HttpStatusCode.Unauthorized;
    // TODO: can you log info here?
}

My log file is like that:

info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
Request starting HTTP/1.1 POST http://somewhere/api/messages application/json;+charset=utf-8 475
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
Executing endpoint 'TeamsBot.Controllers.BotController.PostAsync (TeamsBot)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
Route matched with {action = "Post", controller = "Bot"}. Executing controller action with signature System.Threading.Tasks.Task PostAsync() on controller TeamsBot.Controllers.BotController (TeamsBot).
info: Microsoft.Bot.Builder.Integration.AspNet.Core.IBotFrameworkHttpAdapter[0]
ProcessActivityAsync
dbug: BotController[0]
Adapter=TeamsBot.CloudAdapterWithErrorHandler Bot=TeamsBot.Bots.EchoBot ProcessAsync done. Microsoft.AspNetCore.Http.DefaultHttpRequest -> Microsoft.AspNetCore.Http.DefaultHttpResponse
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
Executed action TeamsBot.Controllers.BotController.PostAsync (TeamsBot) in 991.5981ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
Executed endpoint 'TeamsBot.Controllers.BotController.PostAsync (TeamsBot)'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
Request finished HTTP/1.1 POST http://somewhere/api/messages application/json;+charset=utf-8 475 - 401 0 - 1078.8221ms

As you can see, the last line indicates my controller returns a HTTP 401 code. The controller action is calling await this.adapter.ProcessAsync(this.Request, this.Response, this.bot); (this.adapter is of type IBotFrameworkHttpAdapter, the instance of this.adapter is CloudAdapterWithErrorHandler, which inherits Microsoft.Bot.Builder.Integration.AspNet.Core.CloudAdapter.


Referencing BotBuilder 4.18.1.

Log config:

  "Logging": {
    "LogLevel": {
      "Default": "Debug",
      "EchoBot": "Trace",
      "BotController": "Debug",
      "Microsoft": "Information",
      "TeamsBot.Bots.EchoBot": "Trace",
      "Microsoft.Hosting.Lifetime": "Information",
      "BotFrameworkHttpAdapter": "Trace",
      "Microsoft.Bot.Builder.Integration.AspNet.Core.BotFrameworkHttpAdapter": "Trace",
      "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker": "Warning",
      "Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor": "Warning"
    },
    "File":{
      "Path": "logs/teamsbot.DATE.log"
    }
  }
@LeeParrishMSFT LeeParrishMSFT added customer-reported Issue is created by anyone that is not a collaborator in the repository. Bot Services Required for internal Azure reporting. Do not delete. Do not change color. needs-triage The issue has just been created and it has not been reviewed by the team. labels Jan 17, 2023
@ramfattah ramfattah added the feature-request A request for new functionality or an enhancement to an existing one. label Jan 18, 2023
@ramfattah ramfattah removed the needs-triage The issue has just been created and it has not been reviewed by the team. label Jan 25, 2023
tracyboehrer pushed a commit that referenced this issue Feb 10, 2023
* Added log in ProcessAsync method. Updated CloudAdapter unit tests.

* Unit test updated

* Changed LogWarning to LogError

* Suggested changes applied

---------

Co-authored-by: Emiliano Quiroga <emiliano.quiroga@7-11.com>
tracyboehrer pushed a commit that referenced this issue Feb 13, 2023
* Added log in ProcessAsync method. Updated CloudAdapter unit tests.

* Unit test updated

* Changed LogWarning to LogError

* Suggested changes applied

---------

Co-authored-by: Emiliano Quiroga <emiliano.quiroga@7-11.com>
@sandrock
Copy link
Author

Thanks for the patch. My new log is:

info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
Request starting HTTP/1.1 POST http://somwhere/api/messages application/json;+charset=utf-8 1062
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
Executing endpoint 'TeamsBot.Controllers.BotController.PostAsync (TeamsBot)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
Route matched with {action = "Post", controller = "Bot"}. Executing controller action with signature System.Threading.Tasks.Task PostAsync() on controller TeamsBot.Controllers.BotController (TeamsBot).
info: Microsoft.Bot.Builder.Integration.AspNet.Core.IBotFrameworkHttpAdapter[0]
ProcessActivityAsync

fail: Microsoft.Bot.Builder.Integration.AspNet.Core.IBotFrameworkHttpAdapter[0]
System.UnauthorizedAccessException: Invalid AppId passed on token: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
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.Connector.Authentication.BuiltinBotFrameworkAuthentication.AuthenticateRequestAsync(Activity activity, String authHeader, CancellationToken cancellationToken)
at Microsoft.Bot.Builder.CloudAdapterBase.ProcessActivityAsync(String authHeader, Activity activity, BotCallbackHandler callback, CancellationToken cancellationToken)
at Microsoft.Bot.Builder.Integration.AspNet.Core.CloudAdapter.ProcessAsync(HttpRequest httpRequest, HttpResponse httpResponse, IBot bot, CancellationToken cancellationToken)

dbug: BotController[0]
Adapter=TeamsBot.CloudAdapterWithErrorHandler Bot=TeamsBot.Bots.EchoBot ProcessAsync done. Microsoft.AspNetCore.Http.DefaultHttpRequest -> Microsoft.AspNetCore.Http.DefaultHttpResponse
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
Executed action TeamsBot.Controllers.BotController.PostAsync (TeamsBot) in 1064.143ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
Executed endpoint 'TeamsBot.Controllers.BotController.PostAsync (TeamsBot)'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
Request finished HTTP/1.1 POST http://somwhere/api/messages application/json;+charset=utf-8 1062 - 401 0 - 1074.1526ms

I can now investigate my problem.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bot Services Required for internal Azure reporting. Do not delete. Do not change color. customer-reported Issue is created by anyone that is not a collaborator in the repository. feature-request A request for new functionality or an enhancement to an existing one.
Projects
None yet
4 participants