如何从 JwtSecurityTokenHandler 获取日志输出？

Question

我有一个 ASP.NET Core 2.1 Web 应用程序项目，它使用 JWT 令牌对项目内置的 Web API 进行身份验证。当我在我的机器上本地运行它时它工作正常，但是当我将它部署到 Azure（具有相同的环境和应用程序设置）时，它只是返回空的 HTTP 401 响应来自我经过身份验证的客户端的请求，我需要找出原因所以我可以修。

我在 ASP.NET Core 中启用了每个细节的日志记录，但是我从未收到任何有用的输出。

首先，我通过 NuGet 将Serilog.AspNetCore 和 Console sink 添加到项目中，然后在Program.cs 中配置Verbose 级别的日志记录：

public class Program
{
    public static void Main(string[] args)
    {
        Log.Logger = new LoggerConfiguration()
            .MinimumLevel.Verbose()
            .MinimumLevel.Override("Microsoft", LogEventLevel.Verbose)
            .MinimumLevel.Override("System", LogEventLevel.Verbose)
            .MinimumLevel.Override("Microsoft.AspNetCore.Authentication", LogEventLevel.Verbose)
            .Enrich.FromLogContext()
            .WriteTo.Console(outputTemplate: "[{Timestamp:HH:mm:ss} {Level}] {SourceContext}{NewLine}{Message:lj}{NewLine}{Exception}{NewLine}", theme: AnsiConsoleTheme.Literate)
            .CreateLogger();

        CreateWebHostBuilder( args ).Build().Run();
    }

    public static IWebHostBuilder CreateWebHostBuilder(String[] args)
    {
        return WebHost.CreateDefaultBuilder( args )
            .ConfigureLogging( (ctx, cfg ) =>
            {
                cfg.ClearProviders();
            } )
            .UseStartup<Startup>()
            .UseSerilog();
    }
}

但是当我在 Azure 上运行我的 Web 应用程序（使用控制台 stdout 记录到文件）时，我得到了以下输出：

[04:13:10 Verbose] Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker
Authorization Filter: Before executing OnAuthorizationAsync on filter 
Microsoft.AspNetCore.Mvc.Authorization.AuthorizeFilter.

[04:13:10 Verbose] 
IdentityServer4.AccessTokenValidation.IdentityServerAuthenticationHandler
HandleAuthenticateAsync called

[04:13:10 Debug] 
IdentityServer4.AccessTokenValidation.IdentityServerAuthenticationHandler
AuthenticationScheme: Bearer was not authenticated.

[04:13:10 Information] 
Microsoft.AspNetCore.Authorization.DefaultAuthorizationService
Authorization failed.

[04:13:10 Verbose] Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker
Authorization Filter: After executing OnAuthorizationAsync on filter 
Microsoft.AspNetCore.Mvc.Authorization.AuthorizeFilter.

[04:13:10 Information] 
Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker
Authorization failed for the request at filter 'Microsoft.AspNetCore.Mvc.Authorization.AuthorizeFilter'.

[04:13:10 Verbose] Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker
Before executing action result Microsoft.AspNetCore.Mvc.ChallengeResult.

[04:13:10 Information] Microsoft.AspNetCore.Mvc.ChallengeResult
Executing ChallengeResult with authentication schemes (["Bearer"]).

[04:13:10 Verbose] 
IdentityServer4.AccessTokenValidation.IdentityServerAuthenticationHandler
Forwarding challenge to scheme: BearerIdentityServerAuthenticationJwt

请注意，尽管有详细的日志记录，但错误消息（在下面重复）并没有给我任何解释：

AuthenticationScheme: Bearer was not authenticated.
Authorization failed.

我挖掘了 ASP.NET Core Security 源代码，发现 JwtBearerHandler.HandleAuthenticateAsync 本身并没有做太多的日志记录，但它确实调用了非开源的 System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler，它通常会做一个很多日志记录，包括详细原因（例如（在字符串中带有IDX10209-type 错误代码），但我不知道为什么它没有输出我可以捕获的任何内容。

如何记录来自JwtSecurityTokenHandler 的消息？

Answer 1

我发现了问题：

• 我的 HttpClient（发送 HTTP Authorization 标头 Bearer 令牌）无意将其发送到 http:// URI，该 URI 立即收到 301 重定向到 https:// URI。重定向由 IIS 执行，没有涉及 ASP.NET Core 管道。
• HttpClient 类不会在重定向后重新发送Authorization 标头（这是by-design）。
  • 我从未注意到这一点，因为我的HttpClient 收到的HttpResponseMessage 引用了具有Authorization 标头的原始 请求，而不是缺少标头的重定向后请求.我不得不将 Fiddler 与 HTTPS 代理一起使用，才能看到第二个请求缺少 Authorization 标头。

• 当IdentityServerAuthenticationHandler 或 ASP.NET Core 自己的JwtBearerHandler 收到一个没有Authorization 标头的请求时，它根本不会调用JwtSecurityTokenHandler。要查看此内容，请打开 ASP.NET Core Security Git 存储库中的 JwtBearerHandler.cs 文件并查看 HandleAuthenticateAsync：它具有以下逻辑：

  if (string.IsNullOrEmpty(token))
  {
      string authorization = Request.Headers["Authorization"];
  
      // If no authorization header found, nothing to process further
      if (string.IsNullOrEmpty(authorization))
      {
          return AuthenticateResult.NoResult();
      }
  

• 所以在我的例子中，它根本没有真正调用过JwtSecurityTokenHandler，因此缺少关于 JWT 验证的输出消息。

• 但是我收到的输出消息没有帮助。它们都具有误导性：

  • “AuthenticationScheme：承载未通过身份验证。”应该类似于“AuthenticationScheme：请求中不存在承载令牌”。而是。
  • “授权失败”。应该是“已跳过授权，因为请求中不存在令牌。”

• 所以最后，解决方法是将原始请求 URI 的方案从 http:// 更改为 https://。