3

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)
...    ...    ...
George 2.0 Hope
  • 583
  • 1
  • 6
  • 21
  • @Dai I first tried to use `BeginScope`, however, it does not function the same when using a custom `eventIdProvider: new SERCrawler.SerilogWinEvtID.EventIdProvider())` ... also, since I'm developing an app vs a library; I'm not sure why the preference for MS? – George 2.0 Hope Feb 23 '22 at 09:32
  • I deleted my original comment as I was wrong about Serilog's `ForContext`. The MEL equivalent of `ForContext` is to just specify the `TContext` as a generic type arg for `ILogger` in your constructor, as MEL's DI registration takes care of the rest. – Dai Feb 23 '22 at 09:34
  • Using Serilog directly doesn't really offer that many advantages over MEL (I use MEL as a frontend for Serilog myself), and if you use MEL then you make your life easier if you ever want to spin-off parts of your application as a reusable library. A huge reason to _not_ use Serilog's `static Log` property is because it makes it impossible (literally, yes) to factor-in your code's logging behaviour in your unit and integration tests. – Dai Feb 23 '22 at 09:36
  • @Dai can you provide the modified constructor in code as an answer pls? I've attempted this as well, but was unsuccessful. – George 2.0 Hope Feb 23 '22 at 09:37
  • `services.AddLogging` will add MEL, so you're already using MEL _and_ Serilog together. I think those `ILogger` errors are because you're inadvertently referencing `global::Serilog.ILogger` instead of MEL's `ILogger`. You should (for now) fully-qualify the `ILogger` type-names to avoid ambiguity (as both MEL and Serilog use the same type-names, which is unfortunate). – Dai Feb 23 '22 at 09:38
  • @Dai I may be using MEL & Serilog, but I still can't access `.ForContext` ... also, wrt MEL vs Serilog, this is why I thought it wouldn't matter (in my case) ... https://github.com/serilog/serilog-aspnetcore/issues/104 – George 2.0 Hope Feb 23 '22 at 09:41
  • Re: that Github link, that's me in there (same penguin avatar), so this amuses me – Dai Feb 23 '22 at 09:42
  • The `.ForContext` method is only available on `global::Serilog.ILogger`, _not_ MEL, so if you're getting errors then it means you're using MEL's `ILogger` instead of Serilog's `ILogger` - this is why I say you should fully-qualify your type-names (for now) to avoid this ambiguity and **don't** have `using:` statements for both namespaces in the same `.cs` file. – Dai Feb 23 '22 at 09:43
  • @Dai I thought the same, & I did try `public Worker(Serilog.ILogger logger` but I get the following error: CS0308 The non-generic type 'ILogger' cannot be used with type arguments – George 2.0 Hope Feb 23 '22 at 09:50
  • That's because Serilog's `ILogger` isn't generic. (As far as I know) Serilog doesn't _automagically_ set `ForContext` when a `Serilog.ILogger` is a constructor param, you need to do it yourself, and that's only if your DI framework supports it (e.g. [SimpleInjector does](https://stackoverflow.com/questions/37620823/serilogs-ilogger-injected-using-log-forcontextt-where-t-is-the-consumer), but MEDI does not) - that's why I recommend using MEL for ctor params instead, as MEL (with Serilog) _will_ call `ForContext` behind-the-scenes for you. – Dai Feb 23 '22 at 09:51
  • @Dai if I try to change it to non-generic, then I get multiple `CS0229 Ambiguity` errors for `'Worker._logger' and 'Worker._logger'`, etc, and I'm not sure how to resolve it. – George 2.0 Hope Feb 23 '22 at 10:06
  • Remove the `using:` statements then and fully-qualify the type-names. – Dai Feb 23 '22 at 10:08
  • @Dai I don't know how to: use MEL for ctor params instead, so that MEL (with Serilog) will call ForContext behind-the-scenes for you. – George 2.0 Hope Feb 23 '22 at 10:08
  • Let us [continue this discussion in chat](https://chat.stackoverflow.com/rooms/242305/discussion-between-george-2-0-hope-and-dai). – George 2.0 Hope Feb 23 '22 at 10:21

1 Answers1

5

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();
}
Dai
  • 141,631
  • 28
  • 261
  • 374
  • 2
    +1 good complete answer but have to take issue with a strawman: _you then cannot unit-test or integration-test your class, nor can you feasibly mock/stub/fake the static dependency you're using._ The/Nick's point is if you are not explicitly testing the logging, do it statically. Nothing prevents you* from surfacing the dependency explicitly as needed (and fulfilling it with `Log.Logger` in a prod composition root) if you need to control it in the context of a test, *but that is a very rare thing*. – Ruben Bartelink Feb 23 '22 at 11:24
  • @RubenBartelink You are correct. I should rephrase that. – Dai Feb 23 '22 at 11:27
  • @RubenBartelink I've rewritten my bullet-point about testing with statics. – Dai Feb 23 '22 at 11:35
  • its better now but I would recommend that instead of talking about it as a disagreement that you just talk about where this does not make sense. For me its important though to acknowledge that people hardly ever a) test or b) (arguably) test logging in code. The point I, Nick and others are making is "for app code where you are not testing the logging, don't add all the noise that you would add for testing until you are actually doing that". Will delete all my comments later... – Ruben Bartelink Feb 23 '22 at 11:40
  • @RubenBartelink But I _do_ actually test my application-code, so I wouldn't say "where it doesn't make sense", because to me, it _always_ makes sense :) – Dai Feb 23 '22 at 11:41
  • Note your observations and reasoning about the general aesthetics and tradeoffs aside from this are fine (even if I don't happen to agree with them and would tend to default to using static Serilog for simplicitly -- to some degree this choice is for me also influenced by the fact I default to Pure DI without a container) – Ruben Bartelink Feb 23 '22 at 11:42
  • _But I do actually test my application-code,_ I am not saying you or others dont or shouldnt do that. I am saying that one is not typically mocking and verifying the logging aspect, so in a test context its perfectly fine for the code to write to an unitialized static logger in the context of a test. – Ruben Bartelink Feb 23 '22 at 11:44
  • For integration tests, I'll often wire a logger to the `ITestOutputHelper` etc and feed log output out from fixtures and/or app logic via something like https://github.com/jet/dotnet-templates/blob/4344ab0b6f9c3a07de1bde3e8a9ec0efa20ccf38/equinox-shipping/Watchdog.Integration/SerilogLogFixture.fs#L3. However that should not be confused with this being a generally good pattern - Tests in general, but more importantly, Apps should not dump out mounds of junk and require a dev to come interpret it. – Ruben Bartelink Feb 23 '22 at 11:48
  • Good logging is succinct, and orthogonal to a good app. As such, arguably the logging tests should not be intermingled with the application logic even if you do test it. On the other hand, for libraries that are intended to produce specific logging, you sometimes want to know that they work and log correctly in failure paths and hence absolutely will test that aspect. Even then though, you want to do validation of log messages on a semantic basis as much as possible, rather than pinning specific messages based on regexes or string compares, which is a recipe for messy application monitoring. – Ruben Bartelink Feb 23 '22 at 11:55
  • @RubenBartelink Of course, that's just being sensible: when my tests do assert expected log output they look at the structured log entry, not flat/rendered strings. – Dai Feb 23 '22 at 11:57
  • Yes, but that subtlety is often lost on people that are starting to use Serilog etc and/or doing testing, so is worth calling out. I am not suggesting you don't understand any of the above and/or that your tests would not consider that factor. – Ruben Bartelink Feb 23 '22 at 12:13
  • @RubenBartelink I don't agree that using static `Serilog.Log` is "cleaner" though - let's just agree to disagree. – Dai Feb 23 '22 at 12:35
  • I'm not seeking to drain your or my day through an argument, and I accept that the 'cleaner' judgement is subjective. I think your post makes the case well, and I can see that viewpoint as being valid (and very useful for others that take the view that MEL and DI are ubiquitous and something to hence lean on). – Ruben Bartelink Feb 23 '22 at 13:44
  • My only quibble is that: _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._ is still a strawman argument as written. *If* you need to test logging, it obv makes no sense to leave it static. *But* the argument is that the noise reduction by using `static Log` is a win _until you *need*_ to do that, _and you can then change it just in time in the cases where you are doing it_ - that even makes that case stand out better. – Ruben Bartelink Feb 23 '22 at 13:51
  • I removed my original comment and reposted ^. When you remove your last "agree to disagree" comment and either a) repost it now or b) do an edit that removes my argument, I'll remove this and/or the comment too. – Ruben Bartelink Feb 23 '22 at 13:54
  • @RubenBartelink You're taking StackOverflow far too seriously. If you really care that much then just edit my post. – Dai Feb 23 '22 at 13:54
  • You may be very right indeed ;) but for me editing someone's post is crossing a line. I'm making the argument here as I believe you've taken the time to argue an important case well. As I say, my quibble is with you diluting the central counterpoint: nobody tests logging so that's a bad reason to follow the pattern/dogma. Happy to leave the thread as is, but even happier if we can follow through to make it a canonical post putting the argument for having logging follow [referential transparency rules](https://en.wikipedia.org/wiki/Referential_transparency) without a strawman testing argument. – Ruben Bartelink Feb 23 '22 at 14:07
  • @RubenBartelink C#/.NET does not support referential-transparency, that's kinda moot. – Dai Feb 23 '22 at 14:09
  • I appreciate that; neither does F# or .NET in general ;) My point is that part of the case for using statics is just that: passing loggers around even when you could pass them out of band via them being `static` is not really part of the C# idiom, especially when you consider the fact that logging is orthogonal to working code, conceptually does not have side effects, and is guaranteed not to throw. Are we giving up on the agreeing to disagree ;P – Ruben Bartelink Feb 23 '22 at 16:00
  • @RubenBartelink I'm going to bed – Dai Feb 23 '22 at 16:01