I’m trying to add some additional properties to the log messages produced when a exception is logged by Serilog.
I’ve tried adding a middleware and use the same approach as the core request logging middleware (push in new enrichers using `LogContext.Push`). It works great for things “inside” the request, like controllers etc. But, it seems like this scope is disposed before the unhandled exception logging kicks in, so these enrichers are not called when the exception is logged.
I’ve looked around for ways to define additional enrichers, but it seems like they are all hardcoded in an extension method.
Anyone who successfully managed to add custom enrichers for exceptions?
Thanks for trying @mistyn8, I’m quite happy with the way that exceptions are logged, my problem was that I needed to use my own custom enricher(s).
As far as I understand. Umbraco calls .Enrich.FromLogContext() during Serilog setup as a way to allow for adding custom enrichers. The problem is that these are scoped to the current LogContext, and when an unhandled exception happens, this scope is disposed. This means that any “per-request”-registered enrichers will not run. E.g. the built-in ones in Umbraco like SessionIdEnricher, RequestNumberEnricher, and RequestIdEnricher will not run for unhandled exceptions.
The only way (that I’ve found) to get around this without updating the source of Umbraco is to use appsettings.jsonto register the enricher in the Serilog-section.
Then have an extension method in MyProject.Webnamespace like so:
public static LoggerEnrichmentConfiguration WithMyCustomEnrichers(
this LoggerEnrichmentConfiguration enrichmentConfiguration)
{
if (enrichmentConfiguration == null)
throw new ArgumentNullException(nameof(enrichmentConfiguration));
// Notice: No idea trying to use StaticServiceProvider.Instance as it will be null.
// because this method is called before the service provider is built.
enrichmentConfiguration.With<RequestUserAgentEnricher>();
return enrichmentConfiguration;
}
The enrichers need to have a parameterless constructor. If you need access to DI you’d have to use StaticServiceProvider.Instance to get access to “stuff” from DI. A good option is to use Lazy properties for this.
and perplexity gave this with a little prompting.. to add your enricher in code, rather than appsettings.. ???
public class SerilogEnricherComposer : IComposer
{
public void Compose(IUmbracoBuilder builder)
{
// Extend the existing Serilog logger by adding the custom enricher
Log.Logger = new LoggerConfiguration()
.ReadFrom.Logger(Log.Logger) // inherit existing configuration
.Enrich.With<WithMyCustomEnricher>() // add your custom enricher
.CreateLogger();
}
}
and another thought
// note umbraco logViewer expects string not json so won't show destructured.. but seq should
var scopeProps = new Dictionary<string, object> {
{ "@Model", model },
};
using (_logger.BeginScope(scopeProps))
{
_logger.LogInformation("Account register: {Email} registering for a new account", model.ContactDetails.Email);
}
to use the MSLogger abstraction rather than serilog specific?
Also there is the IDiagnosticContext, to make things less chatty and squash a request down to a single log entry…
not sure if that combines scopes and would perists your log context for exceptions though
Also found this I was messing around with.. can’t remember if it worked or not for DI…
using Microsoft.AspNetCore.Http;
using Serilog.Core;
using Serilog.Events;
namespace www.Code.Extensions.Logging
{
public class LovellEnricher : ILogEventEnricher
{
private readonly IHttpContextAccessor _contextAccessor;
public LovellEnricher()
: this(new HttpContextAccessor())
{
}
internal LovellEnricher(IHttpContextAccessor contextAccessor)
{
_contextAccessor = contextAccessor;
}
public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
{
var httpContext = _contextAccessor.HttpContext;
if (httpContext == null)
{
return;
}
// do we have httpContext?
}
}
}
Looking at it prob not.. think this was the source for the experiment…
I did spend about 4 hours trying to get something to work for unhandled exception.
About your examples:
.Enrich.FromGlobalLogContext()
Not an option as it would require me to reconfigure the logger that Umbraco uses, which feels “overkill” just to be able to add an enricher.
If I were to replace the logging initialization, it would be easy to just add my enrichers like so
.Enrich.With<MyCustomEnricher>()
using (_logger.BeginScope(scopeProps))
{
_logger.LogInformation("Account register: {Email} registering for a new account", model.ContactDetails.Email);
}
Since I do not control the code that performs the logging (it’s part of Serilog) I cannot create a new scope when unhandled exceptions are logged.
LovellEnricher : ILogEventEnricher
Yes, this is what I’m doing. The problem was never to implement the enricher but to get it to fire for unhandled exceptions.
If you have a working sample on how to add a custom enricher that runs on unhandled exceptions without replacing the default i logger declaration, it would be cool to see
I’ve got a workaround that works, so I’m quite happy. But it would be nice if there were a hook to register enrichers during the setup.
So I don’t think that you do have to reinitialise the logger…
From the last article link…
Spot the difference? CreateBootstrapLogger() returns a new, mutable logger type, ReloadableLogger, that can be reconfigured on-the-fly.
The callback overload of UseSerilog() is aware of this: if Log.Logger is a ReloadableLogger, it will be reconfigured through the callback, and then “frozen” into the efficient, immutable logging pipeline that the application will use for the remainder of its execution time.
So that to me looks like, if you create a reloadable logger earlier than umbraco with createBootstrapLogger, then Umbraco will add it’s config to it.. or if you alter the config via the UseSerilog() callback after umbraco then it too will add to the configuration..
Also the original example though not sure required now with the newer boostrapping.. had .ReadFrom.Logger(Log.Logger) // inherit existing configuration
so even though reinitialising it should bring all the existing configuration??
I’ll try to see if it’s possible to append to GlobalLogContext during startup, it would be nice to avoid having to fiddle with appSettings to get the enrichers configured.
I’ll share any progress if I find a better approach than the one I posted initially.
To make serilog less chatty and squash logs related to a single request down to one log event..
this series is wonderful!
Maybe something like..
using Microsoft.AspNetCore.Mvc.Filters;
using Serilog;
using Umbraco.Cms.Core.Composing;
using Umbraco.Cms.Core.Sync;
using Umbraco.Cms.Web.Common.ApplicationBuilder;
namespace www.Code.Extensions.Logging
{
public static class WwwRequestLoggingOptions
{
public static void EnrichFromRequest(IDiagnosticContext diagnosticContext, HttpContext httpContext)
{
var request = httpContext.Request;
// Set all the common properties available for every request
diagnosticContext.Set("RequestHost", request.Host);
// Only set it if available. You're not sending sensitive data in a querystring right?!
if (request.QueryString.HasValue)
{
diagnosticContext.Set("RequestQueryString", request.QueryString.Value);
}
// Set the content-type of the Response at this point
diagnosticContext.Set("RequestContentType", httpContext?.Response?.ContentType ?? "n/a");
// Retrieve the IEndpointFeature selected for the request
var endpoint = httpContext.GetEndpoint();
if (endpoint is object) // endpoint != null
{
diagnosticContext.Set("RequestEndpointName", endpoint.DisplayName ?? "n/a");
}
}
}
public class SerilogExceptionEnricherMvcFilter : IExceptionFilter
{
public void OnException(ExceptionContext context)
{
var dc = context.HttpContext.RequestServices.GetRequiredService<IDiagnosticContext>();
dc.SetException(context.Exception);
}
}
public class SerilogLoggingActionFilter : IActionFilter
{
private readonly IDiagnosticContext _diagnosticContext;
private readonly IServerRoleAccessor _serverRoleAccessor;
public SerilogLoggingActionFilter(IDiagnosticContext diagnosticContext, IServerRoleAccessor serverRoleAccessor)
{
_diagnosticContext = diagnosticContext;
_serverRoleAccessor = serverRoleAccessor;
}
public void OnActionExecuting(ActionExecutingContext context)
{
_diagnosticContext.Set("RouteData", context.ActionDescriptor.RouteValues);
_diagnosticContext.Set("ActionName", context.ActionDescriptor.DisplayName ?? "n/a");
_diagnosticContext.Set("ActionId", context.ActionDescriptor.Id);
_diagnosticContext.Set("ValidationState", context.ModelState.IsValid);
_diagnosticContext.Set("UmbracoServerRole", _serverRoleAccessor.CurrentServerRole);
}
// Required by the interface
public void OnActionExecuted(ActionExecutedContext context) { }
public class SerilogRequestLoggingComposer : IComposer
{
// can move to prePipeline if we want to log static files.
// in 13.1.1 can move to preRouting for just after static files
public void Compose(IUmbracoBuilder builder)
{
builder.Services.Configure<Microsoft.AspNetCore.Mvc.MvcOptions>(options =>
{
options.Filters.Add<SerilogExceptionEnricherMvcFilter>();
});
builder.Services.AddControllers(opts => opts.Filters.Add<SerilogLoggingActionFilter>());
builder.Services.Configure<UmbracoPipelineOptions>(options =>
{
options.AddFilter(
new UmbracoPipelineFilter("SerilogRequestLogging",
prePipeline: null,
preRouting: null,
postRouting: null,
postPipeline: app => app.UseSerilogRequestLogging(opt => opt.EnrichDiagnosticContext = LovellRequestLoggingOptions.EnrichFromRequest),
endpoints: null
)
);
});
}
}
}
}
