Как получить выходные данные журнала от JwtSecurityTokenHandler?

Question

У меня есть проект веб-приложения ASP.NET Core 2.1, использующий токены JWT для аутентификации встроенного в проект веб-API.Он работает нормально, когда я запускаю его локально на своем компьютере, но при развертывании его в Azure (с идентичной средой и настройками приложения) он просто возвращает пустые ответы HTTP 401 на запросы от моих аутентифицированных клиентов, и мне нужно выяснить, почему так ямогу это исправить.

Я включил ведение журнала каждой детали в ASP.NET Core, однако я не получил никакого полезного вывода.

Сначала я добавил Serilog.AspNetCore и приемник консоли в проектчерез NuGet, затем настроил ведение журнала на уровне Verbose в Program.cs:

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 (с консолью 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 не делает много собственной регистрации, но он вызывает не 101-открытый исходный код System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler, который обычно делает много регистрации, включая подробные причины (например, (с IDX10209-тыpe коды ошибок в строках), но я не знаю, почему он не выводит ничего, что я могу перехватить.

Как мне регистрировать сообщения с JwtSecurityTokenHandler?

Answer 1

Я обнаружил проблему:

• Мой HttpClient (который отправлял маркер носителя заголовка HTTP Authorization) был непреднамеренно отправив его на http:// URIтот сразу получил 301 перенаправление на https:// URI.Перенаправление было выполнено IIS без участия конвейера ядра ASP.NET.
• Класс HttpClient не пересылает заголовок Authorization после перенаправления (это by-design ).
  • Я никогда не замечал этого, потому что мои HttpClient полученные HttpResponseMessage имели ссылку на оригинальный запрос с заголовком Authorization, а не на запрос после перенаправления, в котором отсутствовалзаголовокМне пришлось использовать Fiddler с HTTPS-прокси, чтобы увидеть, что во втором запросе отсутствует заголовок Authorization.

• Когда IdentityServerAuthenticationHandler или собственное ядро ​​ASP.NET * JwtBearerHandlerполучает запрос без заголовка Authorization, который вообще не вызывает JwtSecurityTokenHandler.Чтобы увидеть это, откройте файл JwtBearerHandler.cs в репозитории ASP.NET Core Security Git и посмотрите на 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: Bearer не был аутентифицирован".должно было быть что-то вроде «AuthenticationScheme: в запросе не присутствовал токен Bearer».вместо.
  • и «Авторизация не удалась».должен был быть «Авторизация пропущена, потому что токен не присутствовал в запросе».

• Таким образом, в конечном итоге исправление должно было изменить схему URI исходного запроса с http://до https://.