Enrich Serlilogs with unique value per hangfire job

Question

I'm using Hangfire for background jobs, and Serilog for logging. I'm trying to enrich my serilogs with a TrackingId so that all logs from a specific Hangfire job will have the same TrackingId that I can filter on.

I configure Serilog like this in Startup.cs:

Log.Logger = new LoggerConfiguration()
    .ReadFrom.Configuration(Configuration)
    .WriteTo.Seq(serverUrl: serverUrl, apiKey: apiKey)

    // Enrich the logs with a tracking id. Will be a new value per request
    .Enrich.WithProperty("TrackingId", Guid.NewGuid())

    .CreateLogger();

And I enqueue jobs like this:

BackgroundJob.Enqueue<MyService>(myService => myService.DoIt(someParameter));

But doing like this will not set a separate TrackingId per Hangfire job. Is there any way I can achieve that?

Emu

I've had a look at the Hangfire API and can't find a way to do this easily; adding a "server filter" seems like it might work. HTH. – Patmos

Answer 1

For what it's worth, I ended up pulling this off using the server/client filter and GlobalJobFilters registration shown below. One annoying issue I ran into is that the AutomaticRetryAttribute is added by default to the GlobalJobFilters collection, and that class will log errors for failed jobs without knowledge of the Serilog LogContext created in our custom JobLoggerAttribute. Personally, I know I will only allow manual retry, so I just removed that attribute and handled the error within the IServerFilter.OnPerformed method. Check the end of my post to see how to remove it if that works for you.

If you are going to allow automatic retry, then you will need to: 1) create a custom attribute that decorates the AutomaticRetryAttribute and makes it aware of a custom LogContext, 2) again remove the default AutomaticRetryAttribute from the GlobalJobFilters collection, and 3) add your decorator attribute to the collection.

public class JobLoggerAttribute : JobFilterAttribute, IClientFilter, IServerFilter
{
    private ILogger _log;

    public void OnCreating(CreatingContext filterContext)
    {
        _log = GetLogger();

        _log.Information("Job is being created for {JobType} with arguments {JobArguments}", filterContext.Job.Type.Name, filterContext.Job.Args);
    }

    public void OnCreated(CreatedContext filterContext)
    {
        _log.Information("Job {JobId} has been created.", filterContext.BackgroundJob.Id);
    }

    public void OnPerforming(PerformingContext filterContext)
    {
        if (_log == null)
            _log = GetLogger();

        _log.Information("Job {JobId} is performing.", filterContext.BackgroundJob.Id);
    }

    public void OnPerformed(PerformedContext filterContext)
    {
        _log.Information("Job {JobId} has performed.", filterContext.BackgroundJob.Id);

        if (filterContext.Exception != null)
        {
            _log.Error(
                filterContext.Exception,
                "Job {JobId} failed due to an exception.",
                filterContext.BackgroundJob.Id);
        }

        _log = null;
    }

    private ILogger GetLogger()
    {
        return Log.ForContext(GetType()).ForContext("HangfireRequestId", Guid.NewGuid());
    }
}

And the registration...

GlobalJobFilters.Filters.Add(new JobLoggerAttribute());

Removing the AutomaticRetryAttribute...

var automaticRetryFilter = GlobalJobFilters.Filters.Where(x => x.Instance is AutomaticRetryAttribute).Single();
GlobalJobFilters.Filters.Remove(automaticRetryFilter.Instance);

Dowsabel

How is this actually thread-safe? The _log field is shared across worker threads. – Parke