Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Serilog output to hangfire context console

I would like to be able to use my Log to emit events through Hangfires context.console, so that I don't need to use context.writeline to output log events to my hangfire dashboard.

I have attempted to implement a specific serilog sink for this purpose. But as I need the PerformContext from hangfire (which is injected during runtime into the task method), I can't configure the log sink at application startup. I have attempted to create a new logger inside the task method, just to see if the sink actually works, and it does not - can anyone either see why it wouldn't work, or maybe suggest a different approach?

Here is the sink:

 class HangfireContextSink : ILogEventSink {
        private readonly IFormatProvider formatProvider;
        private readonly PerformContext context;
        public HangfireContextSink(IFormatProvider formatProvider, PerformContext context) {
            this.formatProvider = formatProvider;
            this.context = context;
        }
        public void Emit(LogEvent logEvent) {
            var message = logEvent.RenderMessage(formatProvider);
            context.WriteLine(ConsoleTextColor.Blue, DateTimeOffset.Now.ToString() + " " + message);
        }

The sink configuration:

 public static class SinkExtensions {
        public static LoggerConfiguration HangfireContextSink(this LoggerSinkConfiguration loggerSinkConfiguration, PerformContext context, IFormatProvider formatProvider = null) {
            return loggerSinkConfiguration.Sink(new HangfireContextSink(formatProvider, context));
        }
    }

The task method:

 public static bool TestJob(PerformContext context) {
            using (LogContext.PushProperty("Hangfirejob", "TestJob")) {
                try {
                    using (var hangfireLog = new LoggerConfiguration().WriteTo.HangfireContextSink(context).CreateLogger()) {
                        var progress = context.WriteProgressBar("Progress");
                        for (int i = 0; i < 10; i++) {
                            context.WriteLine("Working with {0}", i);
                            progress.SetValue((i + 1) * 10);
                            Log.Debug("Test serilog");
                            hangfireLog.Debug("Test from hangfirelog");
                            Thread.Sleep(5000);
                        }
                    }
                    Log.Debug("Done testjob");
                    return true;
                } catch (Exception ex) {
                    Log.Error(ex, "Error!");
                    return false;
                }
            }
        }
like image 999
Dynde Avatar asked Mar 06 '18 12:03

Dynde


1 Answers

Messages aren't logged to Hangfire console, because you log them with Debug log level, while default Serilog level is Information. You could change logging level with call to .MinimumLevel.Debug() on LoggerConfiguration. Also for logging messages via Serilog.Log static class, you should set its Logger property.

Here is a fixed code that will log to Hangfire console:

using (LogContext.PushProperty("Hangfirejob", "TestJob"))
{
    try
    {
        using (var hangfireLog = new LoggerConfiguration().MinimumLevel.Debug().WriteTo.HangfireContextSink(context).CreateLogger())
        {
            //  This is a dirty code that will be removed in final solution
            var prevLogger = Log.Logger;
            Log.Logger = hangfireLog;

            var progress = context.WriteProgressBar("Progress");
            for (int i = 0; i < 10; i++)
            {
                context.WriteLine("Working with {0}", i);
                progress.SetValue((i + 1) * 10);
                Log.Debug("Test serilog");
                hangfireLog.Debug("Test from hangfirelog");
                Thread.Sleep(5000);
            }
            Log.Debug("Done testjob");
            Log.Logger = prevLogger;
        }
        return true;
    }
    catch (Exception ex)
    {
        Log.Error(ex, "Error!");
        return false;
    }
}

This will work, however overall approach of creating new log for each job is pretty bad. You could avoid this by passing instance of PerformContext through property in LogEvent. You should define a custom property class that is derived from abstract LogEventPropertyValue and exposes instance of PerformContext.

Here is the final code:

PerformContextProperty.cs:

public class PerformContextProperty : LogEventPropertyValue
{
    public PerformContext PerformContext { get; }

    public PerformContextProperty(PerformContext performContext)
    {
        PerformContext = performContext;
    }

    public override void Render(TextWriter output, string format = null, IFormatProvider formatProvider = null)
    {
    }
}

PerformContextEnricher.cs:

public class PerformContextEnricher : ILogEventEnricher
{
    private readonly PerformContext performContext;

    public PerformContextEnricher(PerformContext performContext)
    {
        this.performContext = performContext;
    }

    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
    {
        logEvent.AddPropertyIfAbsent(new LogEventProperty(HangfireContextSink.PerformContextProperty, new PerformContextProperty(performContext)));
    }
}

TestJob.cs:

public class TestJob
{
    public static bool Execute(PerformContext context)
    {
        using (LogContext.PushProperty("Hangfirejob", "TestJob"))
        using (LogContext.Push(new PerformContextEnricher(context)))
        {
            try
            {
                var progress = context.WriteProgressBar("Progress");
                for (int i = 0; i < 10; i++)
                {
                    context.WriteLine("Working with {0}", i);
                    progress.SetValue((i + 1) * 10);
                    Log.Debug("Test serilog", context);
                    Log.Debug("Test from hangfirelog");
                    Thread.Sleep(5000);
                }
                Log.Debug("Done testjob");
                return true;
            }
            catch (Exception ex)
            {
                Log.Error(ex, "Error!");
                return false;
            }
        }
    }
}

HangfireContextSink.cs:

class HangfireContextSink : ILogEventSink
{
    public const string PerformContextProperty = "PerformContext";

    private readonly IFormatProvider formatProvider;

    public HangfireContextSink(IFormatProvider formatProvider)
    {
        this.formatProvider = formatProvider;
    }

    public void Emit(LogEvent logEvent)
    {
        var message = logEvent.RenderMessage(formatProvider);

        LogEventPropertyValue propertyValue;
        if (logEvent.Properties.TryGetValue(PerformContextProperty, out propertyValue))
        {
            var context = (propertyValue as PerformContextProperty)?.PerformContext;
            context?.WriteLine(ConsoleTextColor.Green, DateTimeOffset.Now + " " + message);
        }
    }
}

SinkExtensions.cs:

public static class SinkExtensions
{
    public static LoggerConfiguration HangfireContextSink(this LoggerSinkConfiguration loggerSinkConfiguration, IFormatProvider formatProvider = null)
    {
        return loggerSinkConfiguration.Sink(new HangfireContextSink(formatProvider));
    }
}

Serilog configuration:

Log.Logger = new LoggerConfiguration()
    .Enrich.FromLogContext()
    .MinimumLevel.Debug()
    .WriteTo.HangfireContextSink()
    .CreateLogger();

In Serilog configuration don't forget to call .Enrich.FromLogContext() so that log events are enriched with properties from LogContext.

Above code is pretty straightforward, that's why I don't comment it in detail. If you have some questions regarding the code, please ask and I'll try to explain unclear moments.

like image 188
CodeFuller Avatar answered Oct 26 '22 14:10

CodeFuller