Как обогатить запись в журнале Serilog при разматывании исключения промежуточного программного обеспечения ASP.NET Core?

Question

Я хочу регистрировать детали из запросов HTTP с любыми необработанными исключениями, используя Serilog (например, полный путь запроса, все заголовки HTTP, любые поля формы и т. Д.).Поэтому я следовал этому руководству, чтобы добавить информацию из текущего HttpContext.Request в зарегистрированный журнал Serilog: https://blog.getseq.net/smart-logging-middleware-for-asp-net-core/

Вот моя версия SerilogMiddleware;

/// <summary>This class logs Request Headers of any failed request.</summary>
public class SerilogMiddleware
{
    private static readonly ILogger _log = global::Serilog.Log.ForContext<SerilogMiddleware>();

    private readonly RequestDelegate next;

    public SerilogMiddleware( RequestDelegate next )
    {
        this.next = next ?? throw new ArgumentNullException( nameof( next ) );
    }

    public async Task Invoke( HttpContext httpContext )
    {
        if( httpContext == null ) throw new ArgumentNullException( nameof( httpContext ) );

        try
        {
            await this.next( httpContext );

            // TODO: Log certian HTTP 4xx responses?

            if( httpContext.Response?.StatusCode >= 500 )
            {
                GetLogForErrorContext( httpContext ).Warning( _MessageTemplateForHttp500 );
            }
        }
        catch( Exception ex ) when( LogException( httpContext, ex ) )
        {
            // LogException returns false, so this catch block will never be entered.
        }
    }

    const String _MessageTemplateForException = "Unhandled exception in {RequestResource}";
    const String _MessageTemplateForHttp500   = "Handled HTTP 500 in {RequestResource}";

    private static Boolean LogException( HttpContext httpContext, Exception ex )
    {
        GetLogForErrorContext( httpContext ).Error( ex, _MessageTemplateForException );

        return false; // return false so the exception is not caught and continues to propagate upwards. (I understand this is cheaper than `throw;` inside catch).
    }

    private static ILogger GetLogForErrorContext( HttpContext httpContext )
    {
        HttpRequest req = httpContext.Request;

        String resource = "{0} {1}{2} {3}".FormatInvariant( req.Method, req.Path, req.QueryString.ToString(), req.Protocol );

        // re: `ForContext`: https://nblumhardt.com/2016/08/context-and-correlation-structured-logging-concepts-in-net-5/

        ILogger result = _log
            .ForContext( "RequestHeaders" , req.Headers.ToDictionary( h => h.Key, h => h.Value.ToString() /* Returns all values, comma-separated */ ), destructureObjects: true )
            .ForContext( "RequestResource", resource )
            .ForContext( "ResponseStatus", httpContext.Response?.StatusCode )
        ;

        if( req.HasFormContentType )
            result = result.ForContext( "RequestForm", req.Form.ToDictionary( v => v.Key, v => v.Value.ToString() ) );

        return result;
    }
}

Однако ятакже есть Serilog в моем IWebHostBuilder коде:

IWebHostBuilder webHostBuilder = WebHost
    .CreateDefaultBuilder( args )
    .ConfigureLogging( (ctx, cfg ) =>
    {
        cfg.ClearProviders();
        cfg.AddSerilog(); // it's unclear if this is required or not
    } )
    .UseStartup<Startup>()
    .UseSerilog();

webHostBuilder.Build().Run();

Вкратце:

• Это промежуточный класс ASP.NET Core, который включает await next( context ) в try/catchкоторые получают ILogger, используя Log.ForContext( ... ) для добавления новых свойств в регистратор (например, путь запроса, код ответа и т. д.).
• Поскольку этот код фактически вызывает ILogger.Error, это вызывает немедленную регистрацию события.
• Но try/catch позволяет исключению продолжать распространение вверх по стеку вызовов (используя catch( Exception ex ) when ( LogExceptionThenReturnFalse( httpContext, ex ) ).
• ..., что означает, что Serilog регистрирует исключение и запрос HTTP снова, используяобогащение по умолчанию.

Я хочу, чтобы Serilog регистрировал исключение только один раз, с моим добавленным обогащением. Быстрым решением было бы полностью перехватить исключение в моем SerilogMiddleware, чтобы предотвратить дальнейшее распространение, но этоозначает, что он не попал в Serilog ILogger, настроенный в моемIWebHostBuilder.И если я разрешаю распространению исключения и не регистрирую его в своем промежуточном программном обеспечении, то я не могу записать данные из HttpContext.

Как мне «прикрепить» информацию к текущему «контексту» Serilog, чтобыкогда исключение в конечном итоге перехватывается и регистрируется регистратором IWebHostBuilder Serilog, оно включает дополнительные HttpContext данные?

Answer 1

Мы регистрируем наши запросы с HttpClientFactory

services.AddHttpClient("clientWithLogger")
    .AddHttpMessageHandler<HttpClientLoggingHandler>();

А наши HttpClientLoggingHandler

public class HttpClientLoggingHandler : DelegatingHandler
{
    private readonly ILogger<HttpClientLoggingHandler> _logger;

    public HttpClientLoggingHandler(ILogger<HttpClientLoggingHandler> logger)
    {
        _logger = logger;
    }

    protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request,
        CancellationToken cancellationToken)
    {
        var sw = Stopwatch.StartNew();
        _logger.LogInformation("Starting request to '{requestUri}'", request.RequestUri);
        var response = await base.SendAsync(request, cancellationToken);
        sw.Stop();
        _logger.LogInformation("Finished request to '{requestUri}' in {elapsedMilliseconds}ms, response: {response}",
            request.RequestUri, sw.ElapsedMilliseconds, await response.Content.ReadAsStringAsync());
        return response;
    }
}

Тогда мы можем просто использовать HttpClientFactory

public class DeviceDetector
{
    private readonly IHttpClientFactory _httpClientFactory;
    private const string LicenceKey = "XXX";
    private const string Domain = "https://xxx/api/v1/";

    public DeviceDetector(IHttpClientFactory httpClientFactory)
    {
        _httpClientFactory = httpClientFactory;
    }

    public async Task<Device> DetectDevice(string userAgent)
    {
        var url = $"{Domain}{LicenceKey}";
        var result = await _httpClientFactory.CreateClient("clientWithLogger").GetStringAsync(url);
        return Newtonsoft.Json.JsonConvert.DeserializeObject<Device>(result);
    }
}

Таким образом, мы используем обычный ILogger, который находится за кулисами Serilog, и имеем полный контроль над тем, что регистрирует и когда.

Редактировать

Если вы просто хотите регистрировать ошибки, тогда можно легко добавить логику

public class HttpClientLoggingHandler : DelegatingHandler
{
    private readonly ILogger<HttpClientLoggingHandler> _logger;

    public HttpClientLoggingHandler(ILogger<HttpClientLoggingHandler> logger)
    {
        _logger = logger;
    }

    protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request,
        CancellationToken cancellationToken)
    {
        // Log error requests
        try
        {
            var response = await base.SendAsync(request, cancellationToken);

            if(response.IsSuccessStatusCode)
            {
                // Success status code
            }
            else if( (int)response.StatusCode >= 500 )
            {
                // error 500
            }
        }
        catch( Exception ex ) when( LogException( httpContext, ex ) )
        {
            // LogException returns false, so this catch block will never be entered.
        }
    }
}