Serilog Context Issues with Endpoints mapped in Static Class

Question

This issue is driving me bonkers.

I'm not having an issue getting Serilog to output to a file. I am having issues with Serilog enrichment when the endpoint is mapped within a static class and also in my Mediatr handlers.

This is the configuration for the WebApplicationBuilder:

        builder.Host
            .UseServiceProviderFactory(new AutofacServiceProviderFactory())
            .ConfigureAutofac()
            .UseSerilog((_, serviceProvider, configuration) => {
                var applicationConfiguration = serviceProvider.GetService<IOptions<MyConfigurationClass>>();
                var emailSettings = serviceProvider.GetService<IOptions<EmailSettingsOptions>>();

                var usernameEnricher = serviceProvider.GetAutofacRoot().Resolve(typeof(UserNameEnricher)) as ILogEventEnricher;

                configuration
                    .MinimumLevel.Information()
                    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
                    .Enrich.FromLogContext()
                    .Enrich.WithCorrelationId()
                    .Enrich.WithClientIp()
                    .Enrich.WithMachineName()
                    .Enrich.WithEnvironmentUserName()
                    .Enrich.WithEnvironmentName()
                    .Enrich.WithExceptionDetails()
                    .Enrich.WithExceptionData()
                    .Enrich.WithEventType()
                    .Enrich.With(usernameEnricher!)
                    .WriteTo.Logger(logger => {
                        logger.Filter.ByIncludingOnly(logEvent => logEvent.Level == LogEventLevel.Error).WriteTo.Email(
                            new EmailConnectionInfo() {
                                EmailSubject = applicationConfiguration?.Value.EmailSubjectLine,
                                FromEmail = applicationConfiguration?.Value.WebmasterEmail.EmailAddress,
                                MailServer = emailSettings?.Value.Host,
                                Port = Convert.ToInt32(emailSettings?.Value.Port),
                                ToEmail = string.Join(",", (applicationConfiguration?.Value.DeveloperEmails ?? Array.Empty<DeveloperEmailOptions>()).Select(x => x.EmailAddress))
                            });
                    })
                    .Destructure.UsingAttributes()
                    .WriteTo.File(path: applicationConfiguration?.Value.LogPath.Path ?? string.Empty, outputTemplate: applicationConfiguration?.Value.MessageTemplate.TemplateString ?? string.Empty, shared: true, rollingInterval: RollingInterval.Day)
                    .WriteTo.Console(theme: AnsiConsoleTheme.Code);
            });

Here is some of the configuration in the Program.cs:

app.UseSerilogRequestLogging(options => {
    options.EnrichDiagnosticContext = (context, httpContext) => {
        context.Set("Username", httpContext.User?.Identity?.Name);
        context.Set("RequestScheme", httpContext.Request.Scheme);
        context.Set("HttpRequestClientHostIP", httpContext.Connection.RemoteIpAddress);
        context.Set("HttpRequestUserAgent", httpContext.Request.Headers["User-Agent"].ToString());
    };
});

Here is my endpoint:

public static class MapExcelReportEndpointsExtensions {
    /// <summary>
    /// Maps the bae contract report endpoints.
    /// </summary>
    /// <param name="app">The application.</param>
    public static void MapExcelReports(this WebApplication app) {
        app.MapGet("/pdmsreportsapi", () => TypedResults.Ok()).RequireAuthorization(AuthorizationsConstants.AuthenticatedUser);

        app.MapGet("/myApi/myReport/reportId/{reportId:guid}/excel", async ([FromServices] ILogger logger, [FromServices] IHttpContextAccessorWrapper contextAccessor, [FromServices] IMediator mediator, [FromServices] IOptions<MyConfigurationClass> configuration, [FromRoute] Guid reportId, [FromQuery(Name = "Variable1")] string variable1, [FromQuery(Name = "Variable2")] string variable2, [FromQuery(Name = "OrderByValue")] int orderByValue) => {

            ...code elided...

            logger.Information("The Reports Excel endpoint");

            ...code elided...
    }

The issue is that when I am logging in the endpoint...contextual information provided by the enrichers do not output to the logs.

While experimenting, I discovered a really bizarre case where if I added the following:

 logger.Information("The Reports Excel endpoint {@Username}", contextAccess.httpContext?.User?.Identity?.Name);

The Username property that would normally be provided by the enricher now is added to the log entry as well as the text of the log output. Even more bizarre, if I did the following:

 logger.Information("The Reports Excel endpoint {@Username}", contextAccess.httpContext?.User?.Identity?.Name);
 logger.Information("The Reports Excel endpoint {@HttpRequestClientHostIP}", "1333.1333.1333.1333");

The HttpRequestClientHostIP would output, but the Username would not.

Can someone please illuminate what they think might be going on? Am I doing something wrong? Is this behavior normal and I'm just really understanding something correctly?

EDIT:

I resolved the issue with the Username property by moving the code to middleware like so:

public class SerilogUsernameMiddleware {
    /// <summary>
    /// The next
    /// </summary>
    private readonly RequestDelegate _next;

    /// <summary>
    /// Initializes a new instance of the <see cref="SerilogUsernameMiddleware"/> class.
    /// </summary>
    /// <param name="next">The next.</param>
    public SerilogUsernameMiddleware(RequestDelegate next) {
        Ensure.That(next, nameof(next)).IsNotNull();

        _next = next;
    }

    /// <summary>
    /// Invokes the specified HTTP context.
    /// </summary>
    /// <param name="httpContext">The HTTP context.</param>
    public async Task Invoke(HttpContext httpContext) {
        Ensure.That(httpContext, nameof(httpContext)).IsNotNull();

        var username = httpContext.User?.Identity?.Name;

        using (LogContext.PushProperty("Username", username)) {
            await _next(httpContext);
        }
    }
}

I believe that this code was based on a blog post by Nicholas Blumhardt awhile back. I'm still perplexed as to why some of the other properties that I'm defining in the UseSerilogRequestLogging is not persisting to logs generated in my Mediatr handlers and the endpoint definition.

score 0 · Answer 1 · answered Aug 29 '23 at 20:22

I pretty much resolved my issue. However, while I got the results I want, I'm not sure it's technically correct.

The first thing I did was to add another middleware:

/// <summary>
/// Class HttpMiddlewareExtensions.
/// </summary>
public static class HttpMiddlewareExtensions {
    /// <summary>
    /// Uses the serilog request information.
    /// </summary>
    /// <param name="app">The application.</param>
    /// <returns>IApplicationBuilder.</returns>
    public static IApplicationBuilder UseSerilogRequestInformation(this IApplicationBuilder app) {
        return app.UseMiddleware<SerilogRequestInformationMiddleware>();
    }
}

/// <summary>
/// Class SerilogRequestInformationMiddleware.
/// </summary>
public class SerilogRequestInformationMiddleware {
    /// <summary>
    /// The next
    /// </summary>
    private readonly RequestDelegate _next;

    /// <summary>
    /// Initializes a new instance of the <see cref="SerilogRequestInformationMiddleware"/> class.
    /// </summary>
    /// <param name="next">The next.</param>
    public SerilogRequestInformationMiddleware(RequestDelegate next) {
        Ensure.That(next, nameof(next)).IsNotNull();

        _next = next;
    }

    /// <summary>
    /// Invokes the specified context.
    /// </summary>
    /// <param name="context">The context.</param>
    public async Task Invoke(HttpContext context) {
        Ensure.That(context, nameof(context)).IsNotNull();

        var request = context.Request;

        using (LogContext.PushProperty("EndpointName", context.ContextHasEndpoint() ? context.GetEndpoint()?.DisplayName : string.Empty))
        using (LogContext.PushProperty("QueryString", request.QueryString.HasValue ? request.QueryString : string.Empty))
        using (LogContext.PushProperty("HttpRequestClientHostIP", context.GetHttpRequestClientHostIp()))
        using (LogContext.PushProperty("HttpRequestUserAgent", request.GetUserAgent()))
        using (LogContext.PushProperty("StatusCode", context.GetHttpStatusCode()))
        using (LogContext.PushProperty("RequestMethod", request.Method))
        using (LogContext.PushProperty("RequestScheme", request.Scheme)) {
            await _next(context);
        }
    }
}

I also added a helper class:

public static class LogHelper {
    public static void EnrichFromRequest(IDiagnosticContext diagnosticContext, HttpContext httpContext) {
        var request = httpContext.Request;

        diagnosticContext.Set("Username", httpContext.GetUsername());
        diagnosticContext.Set("Scheme", request.Scheme);
        diagnosticContext.Set("EndpointNAme", httpContext.ContextHasEndpoint() ? httpContext.GetEndpoint()?.DisplayName : string.Empty);
        diagnosticContext.Set("QueryString", request.QueryString.HasValue ? request.QueryString : string.Empty);
        diagnosticContext.Set("HttpRequestClientHostIP", httpContext.GetHttpRequestClientHostIp());
        diagnosticContext.Set("HttpRequestUserAgent", request.GetUserAgent());
        diagnosticContext.Set("StatusCode", httpContext.GetHttpStatusCode());
        diagnosticContext.Set("RequestMethod", request.Method);
        diagnosticContext.Set("RequestScheme", request.Scheme);
    }
}

Credit goes to Andrew Locke for this: Using Serilog.AspNetCore in ASP.NET Core 3.0

I updated Program.cs to the following:

var app = AppBuilder.GetApp(args);

app.UseSerilogRequestLogging(options => options.EnrichDiagnosticContext = LogHelper.EnrichFromRequest);

if (!app.Environment.IsDevelopment()) {
    app.UseExceptionHandler();
}

app.ConfigureExceptionHandler(Log.Logger);

app.UseStaticFiles();
app.UseSerilogRequestInformation();

app.UseAuthentication();
app.UseAuthorization();

app.UseSerilogUsername();
app.UseAdminSafelist(app.Configuration.GetSection("AdminSafeList").Value!);

app.MapExcelReports();
app.MapPdfReports();

Log.Logger.Information("Getting ready to run!");
app.Run();

But, wait! There's more!

I needed to update some of my code like my Requirement handlers for my endpoint authorizations to use LogContext.PushProperty to populate the Username property.

Once I made these changes, all of the properties in my logs populated as desired. I'm sure that the reason these properties were not populated had to do with the request pipeline and whether the handlers are considered part of that context or not. The LogContext probably adds values that Serilog keeps track of outside of the request. The reason why the values were empty in things like the Requirements handlers is because the HttpContext is not available in them. I had to supply the value for Username through other means depending on the, wait for it, context.

I hope that some of this helps someone and I am open to any suggestions.

Serilog Context Issues with Endpoints mapped in Static Class

1 Answers1