Search code examples
c#dependency-injectionserilog.net-6.0

Serilog .ForContext not available via in service(/worker) class


How do I fix the dependency injection so that I can access .ForContext(...) within my worker/service class?

[.Net Core 6 for a hybrid console/WindowsService App]

In my main program class and worker/service classes, I have Serilog working correctly for basic logging...

Program.cs

Log.Information($"Application Directory: {baseDir}");

Worker.cs

_logger.LogInformation("Service Starting");

ServiceA.cs

_logger.LogInformation("In Service A");

However, the issue I'm having is that I need .ForContext to be able to work everywhere as well... and it does in my main program class:

Program.cs

Log
   .ForContext("EventID", 42)
   .Information("Log This with EventID === 42");

... however, when I try to do the same in either of the worker/service classes ...

Worker.cs

_logger
   .ForContext("EventID", 42)
   .Information("Log This with EventID === 42");

... it does not work, and I get the following error:

Error CS1061

'ILogger<Worker>' does not contain a definition for 'ForContext' and no accessible extension method 'ForContext' accepting a first argument of type 'ILogger<Worker>' could be found

... so I looked into that, and came upon the following SO questions (neither of which was I able to apply, see comments in code below) which were close:

... (as well as some other places) but I was unable to integrate the answers into the codebase:

Program.cs

    public static IHostBuilder CreateHostBuilder(string[] args) =>
        Host.CreateDefaultBuilder(args)
            .UseWindowsService()
            .ConfigureAppConfiguration((context, config) =>
            {
                // Configure the app here.
            })
            .ConfigureServices((hostContext, services) =>
            {
                services.AddHostedService<Worker>();
                services.Configure<AppSettings>(hostContext.Configuration.GetSection("AppSettings"));
                services.AddScoped<IServiceA, ServiceA>();
                services.AddScoped<IServiceB, ServiceB>();
                
                //?? I'm not sure if this .AddLogging(...) is needed ??
                services.AddLogging(x =>     
                {
                    x.ClearProviders();
                    x.AddSerilog(dispose: true);
                });
                //?? ... having/not having it doesn't seem to affect execution 
            })
            .UseSerilog();

Worker.cs

public class Worker : BackgroundService
{
    private readonly ILogger<Worker> _logger;
    //private readonly Serilog.ILogger<Worker> _logger;
    //?? ... wrt this attempt, Serilog.ILogger won't allow <Worker> ...

    //??    private readonly ILogger _log = Log.ForContext<SomeService>();
    //private readonly ILogger _logger = Log.ForContext<Worker>();
    //?? ... wrt this attempt, Log isn't available ...
    
    private FileSystemWatcher _folderWatcher;
    private readonly string _inputFolder;
    private readonly IServiceProvider _services;

    public Worker(ILogger<Worker> logger, IOptions<AppSettings> settings, IServiceProvider services)
    {
        _logger = logger;
        _services = services;
        _inputFolder = settings.Value.InputFolder;
    }

    protected override async Task ExecuteAsync(CancellationToken stoppingToken)
    {
        await Task.CompletedTask;
    }

    public override Task StartAsync(CancellationToken cancellationToken)
    {
        _logger
            .ForContext("EventID", 1001)
            .LogInformation("Service Starting - need to assign EventID === 1001");
        //?? here is where .ForContext is needed (but doesn't work)
...    ...    ...

Solution

  • Preface:

    • This answer uses "MEL" as an abbreviation for Microsoft.Extensions.Logging.
    • Because the type-name ILogger is used by both MEL and Serilog for completely different types, this answer always disambiguates occurrences of the name ILogger as either MEL.ILogger or Serilog.ILogger.
      • Though note that only MEL's ILogger<T> is generic. There is no Serilog.ILogger<T>, only Serilog.ILogger.

    TL;DR (for .ForContext):

    • Serilog.ILogger.ForContext(String propertyName, Object? value, Boolean destructureObjects = false) creates a "child" Serilog.ILogger instance with a single event-property added to all events logged by the child logger.

      • Whereas in MEL, you would typically use ILogger<T>'s BeginScope in a using( log.BeginScope(...) ) block and passing state: Dictionary<String,Object?> parameter), which has different semantics to ForContext. This is why you should never mix Serilog idioms with MEL idioms.
    • Serilog.ILogger.ForContext(Type) and Serilog.ILogger.ForContext<TSource> are both equivalent to calling ForContext(String).

      • (ForContext<TSource>() passes typeof(TSource) into ForContext(Type), and ForContext(Type) just passes Type.FullName into ForContext(String)).
    • The MEL equivalent of ForContext<TSource> is to either....

      • ...use constructor parameter dependency injection by injecting MEL's ILogger<TSource> as a TSource constructor parameter.
      • Inject (or otherwise obtain) a reference to MEL's ILoggerFactory and specify TSource as a generic type argument for the .CreateLogger<T> extension method.
      • Both of these approaches will make the MEL ILoggerFactory add a "SourceContext" (or "Category") event-property for typeof(TSource).FullName for you automatically during injection.
    • So if you are injecting MEL's ILogger<TService> into your class TService's constructor then...

      • ...you don't need to call ForContext yourself to set "SourceContext" (or "Category").
      • And you should be using MEL's ILogger.BeginScope() instead of Serilog.ILogger.ForContext for when you want to add more event-properties inside your service.
      • If you try to use ForContext with MEL's ILogger (both the generic and non-generic versions) you'll get a compiler error, ditto if you try to use BeginScope with Serilog.ILogger - simply because those are extension methods that are only defined for their intended types.

    Read on...

    There are 2 different ways to use MEL and Serilog together in an application using Microsoft.Extensions.DependencyInjection.

    1. Use Serilog only as a (host-specific) backend for MEL, while using MEL for the "frontend" MEL.ILogger<T> interfaces that are injected into your types' constructors.
    2. Use Serilog directly in your own code (either with the static members of global::Serilog.Log, or by injecting global::Serilog.ILogger) while still wiring-up MEL for Serilog so that other components (that you didn't write) that use MEL will still appear in Serilog output.

    Option 2 is the preference of Serilog's author...

    In application code, I use Serilog.ILogger and static global::Serilog.Log.* methods exclusively.

    I also dislike having to clutter every constructor with MEL.ILogger<T> parameters (constructor argument lists are highly-valuable real estate), and find there are usability issues once code steps out of DI and starts calling non-DI-instantiated classes that want to do some logging (more parameter passing).

    ...however I (respectfully) disagree with @nblumhardt's reasoning because:

    • Using any impure (i.e. non-side-effect-free) static APIs in general (not just Serilog's Serilog.Log) is a bad idea because managing static state in unit and integration-tests is very difficult, if not impossible, depending on the API you're using and how your test-runner works.
      • For example, if you want your unit-test or integration-test to make assertions about what was logged by your SUT then you cannot use concurrent test execution: they must be strictly sequential so that your test-environment can reset or reconfigure the Serilog.Log for each test case, otherwise all of the test output will be munged together.
    • The reasoning for avoiding "usability" and how "constructor argument lists are highly-valuable real-estate" are couched in ergonomics, or even mere aesthetics, however this is probably the worst reason for not doing something properly: "I'm going to cause engineering problems for myself because of aesthetics" is not a good case to present to your project's engineering manager.
    • While I appreciate that having ctor params makes it harder to reuse a class in situations where DI is unavailable, using the static Serilog.Log methods is no-better: it means it's now harder to reuse your class in situations where the static Serilog types are unavailable.
      • My preferred solution to that situation is to either define a static factory method for that type which supplies stock or NOOP implementations of MEL.ILogger<T> (e.g. NullLogger<T>) or define an alternative constructor that supplies its own defaults (and apply [ActivatorUtilitiesConstructor] to the DI constructor).
      • Also, Microsoft.Extensions.Logging is now established as the baseline logging library which is present in every .NET environment now - given any random .csproj project created in the past 5 years, it's far more likely that MEL.ILogger<T> will be available instead of (if not in addition to) the Serilog NuGet package.
        • It's only bare-bones console projects and older codebases, that aren't using IHost, that won't have MEL available. Also, every ASP.NET Core project has MEL anyway.

    Things are different if you're using a different DI system, such as Simple Injector, Autofac, Ninject, and others, so please don't follow this post's advice if you're not using Microsoft.Extensions.DependencyInjection directly.


    For option 1, this is how I do it in my projects:

    • If this is a multiple-project solution, with a single "entrypoint" .exe project that references your other projects...

      • Then the .exe project should reference the Microsoft.Extensions.Logging, Serilog, and Serilog.Extensions.Logging NuGet packages.
      • The other projects only need to reference Microsoft.Extensions.Logging.Abstractions (and not the main Microsoft.Extensions.Logging package).
    • If this is a single-project solution, then reference Microsoft.Extensions.Logging, Serilog, and Serilog.Extensions.Logging.

    • If you're using Host.CreateDefaultBuilder or WebHost.CreateDefaultBuilder then those methods already call .AddLogging for you already, you don't need to do it yourself, but you do need to call UseSerilog (Serilog.SerilogHostBuilderExtensions.UseSerilog) on the IHostBuilder before .Build() is called.

      • You also do not need to call .AddSerilog either.
    • Inside your service-types (i.e. your types that have service interfaces in their constructor params) use Microsoft.Extensions.Logging.ILogger<T> where T is the same type as the constructor's declaring type (yes, I agree this is redundant).

      • So you should not have using Serilog in any other .cs files besides your Program.cs file (and/or the file where your configureLogger method is).
    • Then, at runtime, when the Microsoft.Extensions.DependencyInjection container instantiates your types, it will call Microsoft.Extensions.Logging.ILoggerFactory.ILoggerFactory.CreateLogger(String categoryName) for you automatically.

      • (Where the categoryName is the type-name of T in the injected MEL.ILogger<T> type)
      • ...which is passed-along to Serilog's ForContext logger factory, and the returned Serilog.ILogger is wrapped by MEL's MEL.ILogger<T>.

    An actual example:

    Program.cs

    using System;
    using Microsoft.Extensions.Logging;
    
    // No `using Serilog` here.
    
    static async Task<Int32> Main( String[] args )
    {
        using( IHost host = CreateHost( args ) )
        {
            await host.RunAsync();
    
            return 0;
        }
    }
    
    static IHost CreateHost( String[] args )
    {
        IHostBuilder b = Host.CreateDefaultBuilder( args );
        // CreateDefaultBuilder calls `MEL.AddLogging` for you already.
        b = b.UseStartup<YourStartupClass>(); // or `b.ConfigureServices()`;
    
        // Explicit extension method call because there's no `using Serilog` to avoid ambiguity issues:
        b = global::Serilog.SerilogHostBuilderExtensions.UseSerilog(
            builder             : b,
            configureLogger     : ConfigureSerilog,
            preserveStaticLogger: true
        );
    
        return b.Build();
    }
    
    static void ConfigureSerilog( HostBuilderContext ctx, Serilog.LoggerConfiguration logCfg )
    {
         _ = logCfx
            .Enrich.WithExceptionDetails()
            .Enrich.FromLogContext()
            .MinimumLevel.Is( /* etc */ )
            .WriteTo.File( /* etc */ );
    }
    

    ExampleServiceType.cs

    using System;
    using Microsoft.Extensions.Logging;
    
    // No `using Serilog` here either.
    
    public MyService
    {
        private readonly ILogger log;
    
        public MyService( ILogger<MyService> log )
        {
            this.log = log ?? throw new ArgumentNullException(nameof(log));
        }
    
        public void Foo( String name )
        {
            this.log.LogInformation( "hello {Name}", name );
        }
    }
    

    If you see yourself reusing MyService in places where DI is unavailable, then you can define an alternative constructor, like so:

    using System;
    using Microsoft.Extensions.Logging;
    using Microsoft.Extensions.Logging.Abstractions;
    using Microsoft.Extensions.DependencyInjection;
    
    // No `using Serilog` here either.
    
    public MyService
    {
        private readonly ILogger log;
    
        [ActivatorUtilitiesConstructor]
        public MyService( ILogger<MyService> log )
        {
            this.log = log ?? throw new ArgumentNullException(nameof(log));
        }
    
        public MyService()
            : this( log: NullLogger<MyService>.Instance )
        {
        }
    
        public void Foo( String name )
        {
            this.log.LogInformation( "hello {Name}", name );
        }
    }
    

    So this will just-work (though when using NullLogger<T> specifically, nothing will be logged, so that may-or-may-not be desirable):

    void Bar()
    {
        MyService svc = new MyService();
        svc.Foo();
    }