nblumhardt / autofac-serilog-integration

Contextual logger injection for Autofac using Serilog
Apache License 2.0
70 stars 25 forks source link

Dev logger lambda #38

Closed antonKrouglov closed 7 months ago

antonKrouglov commented 4 years ago

I am writing a net.core worker service project. There is no Startup class there. Updating Log after host has been built does not work as expected as only child scopes are affected. I am configuring serilog in code using custom config file which stores things connection strings for SQL Server sink. The only option I have found is to hide initialization inside lamba. This is a real autofac-style,

Sample usage:

using Autofac;
using AutofacSerilogIntegration;
using Microsoft.Extensions.Options;
using Serilog.Core;

public class SerilogConfiguratorFromSettings : IStartable {

    private readonly IOptionsMonitor<MyLoggingSettingsFromConfig> _MyLoggingSettingsFromConfigLive;
    public Logger logger { get; private set; }

    public SerilogConfiguratorFromSettings(IOptionsMonitor<MyLoggingSettingsFromConfig> MyLoggingSettingsFromConfigLive)
        => _MyLoggingSettingsFromConfigLive = MyLoggingSettingsFromConfigLive;

    public void Start()
        => logger = SerilogConfigurator.GetLoggerFromSettings(_MyLoggingSettingsFromConfigLive.CurrentValue);

}

public class LoggingModule : Module {

    protected override void Load(ContainerBuilder builder) {
        builder
            .RegisterType<SerilogConfiguratorFromSettings>()
            .As<IStartable>()
            .SingleInstance() //config is read once
            //.InstancePerLifetimeScope() //this allows to reread config for each new lifetime scope
            ;

        builder.RegisterLogger(
            loggerLambda: c => c.Resolve<SerilogConfiguratorFromSettings>().logger
            , autowireProperties: true);
    }
}
srogovtsev commented 4 years ago

Can you give an example of the intended usage?

In my experience, as you still have a place where you configure the container, you can configure the logger there.

antonKrouglov commented 4 years ago

@srogovtsev - example added above. I need to compose Logger before autofac container is build. Logger depends on IOptions<MyLoggingSettingsFromConfig> which are not available directly. In the absence of Startup adding Logger-lambda is the only way to solve this chicken-egg problem

srogovtsev commented 4 years ago

I'd say this is quite a strange scenario. If I remember properly, MS recommends having IConfiguration available during service configuration. Worker services seem to follow the usual pattern with the IHostBuilder, so you'll have access to IConfiguration in the container build stage. Why does it have to be in the module?

(frankly, from my experience, registering logger in the module can have strange effects on the system)

antonKrouglov commented 4 years ago

MS recommends having IConfiguration available during service configuration

This would be a bit oversimplified scenario. In my case it would be a bad design to access IConfiguration directly. Options should be accessed by special configurator helper classes and abstracted properly for the purposes of unit testing. In may case parts of the configuration are being pulled from external sources. Helper classes may throw. Configurators should log to special basic bootstrap logger.

srogovtsev commented 4 years ago

MS recommends having IConfiguration available during service configuration

This would a bit oversimplified scenario.

That's the one that works for asp.net Core.

In my case it would a bad design to access IConfiguration directly. IConfiguration should be accessed by special helper classes and abstracted properly for the purposes of uni testing.

You can easily do that during service configuration. On the other hand, though, there is problem in unit-testing code relying on IConfiguration, because you can always inject in-memory configuration.

In may case parts of the configuration are being pulled from external sources.

This is what IConfigurationSource is for.

But all of this is a bit outside of the scope, I agree. The problem is, having Startup class wouldn't help you either: the startup cannot affect the container, it is already built. So if you depend on something from the container to build your logger, the only option would be resolving it, and that will in turn lead to interesting lifetime management issues.

srogovtsev commented 4 years ago

Actually, I would agree that mixing dynamically provided loggers with provided instances leads to confusion. I suggest we forget about the current changes for a moment. What syntax and behavior, especially regarding lifetime management, would you use for dynamically provided loggers?

antonKrouglov commented 4 years ago

The problem is, having Startup class wouldn't help you either

As per this question - it does help. I have tried to emulate this approach by using autofac with auto-start component - no luck. Making any changes to Serilog.Log.Logger affect child scopes only. I have even tried this - no luck. This may be related to how Serilog integrates with IHostBuilder and IWebHostBuilder.

antonKrouglov commented 4 years ago

What syntax and behavior, especially regarding lifetime management, would you use for dynamically provided loggers?

I would expect that provider (DI container or something similar to LoggerProvider) cares about lifetime of dynamically provided loggers. However I do not have any deep understanding what happens beneath the Serilog/MEF surface when ILogger<MyClass> are being instantiated and injected to each consumer.

Probably alternate approach would be: use LoggerConfiguration instance or lambda as it seems to be a lightweight object so GC can take care of it if needed so I would not care about its lifetime.

srogovtsev commented 4 years ago

The problem is, having Startup class wouldn't help you either

As per this question - it does help.

Erm.

public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory, IOptions<EmailLoggerSettings> emailLoggerSettings, IOptions<SqlLoggerSettings> sqlLoggerSettings)
{
  Log.Logger = new LoggerConfiguration()
    //...
    .CreateLogger();

  loggerFactory.AddSerilog(); //this is important
}

The place that I marked as important - this is Microsoft.Extensions.Logging.ILoggerFactory. You won't be able to resolve Serilog.ILogger from the service provider.

(nor will it affect the loggers for the services that are created by this time)

srogovtsev commented 4 years ago

I would expect that provider (DI container or something similar to LoggerProvider) cares about lifetime of dynamically provided loggers.

It can "care" only as much as you explain it to. There's no way the DI container can tell whether you want the the loggers to be alive for just one resolve or for a scope lifetime, or for container lifetime. Be that a regular service, that'd be easy - we have all those handy SingleInstance, InstancePerLifetimeScope and so forth, but how do you propose to do that with the lambda you have provided?

antonKrouglov commented 4 years ago

Well, lambda may cause troubles. How about just changing defaults? Say when Logger is not provided (1) try to resolve LoggerConfiguration from container (2) and only then default to static instance? That would solve my problem as well.

srogovtsev commented 4 years ago

try to resolve LoggerConfiguration from container

What should be the lifetime of the Logger created from this instance?

antonKrouglov commented 4 years ago

What should be the lifetime of the Logger created from this instance?

I would say .InstancePerLifetimeScope. This would force to reload settings on child scopes. If app extensively creates scopes this may lead to problems, Therefore there maybe makes sense to add a flag that switches between InstancePerLifetimeScope or SingleInstance. Ideally new logger should be re-created only when LoggerConfiguration change.

srogovtsev commented 4 years ago

What should be the lifetime of the Logger created from this instance?

I would say .InstancePerLifetimeScope.

And as soon as you have at least one SingleInstance consumer you effectively have a logger that never changes whatever you do.

Which is worse, as soon as you have to concurrent scopes (which is usual for a web application which creates a scope for every incoming request), you'll have two concurrent loggers. And let's say your logging configuration has a MS SQL sink, which is, for the purposes of this example, a periodic batching sink, which creates a timer for every instance of the sink. So, two concurrent scopes - two timers, which will not ever fire, because the usual lifetime of the request is shorter the default two seconds interval. But at least SQL handles concurrent writes decently. If you configure your logger to write to a file, you'll have to specify concurrent access even if your application is the only one that uses the file.

Ideally new logger should be re-created only when LoggerConfiguration change.

There's no easy way to do that in Autofac. Basically, you'll have to to it yourself, which is not an easy thing if you consider concurrency issues. And you'll still have the problem that the loggers that were created from previous configuration might be (and most probably are) still in use, because there's almost no way of affecting them.

What is funny, though, is that you can expand on the recipe from one of your links above, and create a proxying Logger which does nothing - no enrichment, no level filtering, nothing - and forwards every event to a custom sink which in turn sends them to an ILogger that you have wherever you want (probably in some static) and change in whichever way you want. The only downside of this solution is that the consumers will always assume that all logging levels are enabled.

antonKrouglov commented 4 years ago

OK, it makes sense in a broad context. In a narrow context, in my particular case I do not have any child scopes. If required, I may re-engeneer this Windows service to have them a few with a low concurrency. Log setting that may change during runtime in this narrow case is either a particular sink is on or off. Can this be achieved somehow?

srogovtsev commented 4 years ago

Can this be achieved somehow?

Yes, the easiest to do this would be to use a configure everything statically as usual, and then use LoggingLevelSwitch.

antonKrouglov commented 4 years ago

Thank you