Log file command setting and logging via DI

[duncansmart]

I have defined some Commands that take CommandSettings that specify a log file setting e.g. :

public class MyCommandSettings : CommandSettings
{
    public string LogFile { get; set; } = string.Empty;
}

And a command that just writes to an ILogger:

public class MyCommand : Command<MyCommandSettings> 
{
    readonly ILogger _logger;

    public MyCommand(ILogger logger) => _logger = logger;

    public override int Execute([NotNull] CommandContext context, [NotNull] MyCommandSettings settings)
    {
        _logger.LogInformation("Hello world");
        return 1;
    }
}

But the logging is configured in the main method by:

var serviceCollection = new ServiceCollection()
    .AddLogging(configure =>
        configure.AddSerilog(new LoggerConfiguration()
            .MinimumLevel.Debug()
            .WriteTo.File(????) // << HALP!
            .CreateLogger()
        )
    );

using var registrar = new DependencyInjectionRegistrar(serviceCollection);
var app = new CommandApp(registrar);

app.Configure(config =>
{
    config.AddCommand<MyCommand>("mycommand");
});

return app.Run(args);

How do i resolve the log file name in the ServiceCollection?

[phil-scott-78]

Bit of a chicken and egg problem here. Need to grab settings but those are only available once they are parsed, and we need to configure the logger before we parse.

One way I've solved this in the past is using Serilog.Sinks.Map along with an enricher to pull the file name, but I've always used something like a config file. Here we need access to the parsed settings. For this I think we could use an ICommandInterceptor to look for that value.

Taking the example from the Serilog.Sinks.Map readme, we could adjust it to just take the filename as a static property

internal class LogFileNameEnricher : ILogEventEnricher
{
    private string? _cachedLogFilePath;
    private LogEventProperty? _cachedLogFilePathProperty;

    public static string Path = string.Empty;

    public const string LogFilePathPropertyName = "LogFilePath";

    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
    {
        var logFilePath = string.IsNullOrWhiteSpace(Path) ? "output.log" : Path;
        LogEventProperty logFilePathProperty;

        if (_cachedLogFilePathProperty != null && logFilePath.Equals(_cachedLogFilePath))
        {
            // Path hasn't changed, so let's use the cached property
            logFilePathProperty = _cachedLogFilePathProperty;
        }
        else
        {
            // We've got a new path for the log. Let's create a new property
            // and cache it for future log events to use
            _cachedLogFilePath = logFilePath;

            _cachedLogFilePathProperty = logFilePathProperty =
                propertyFactory.CreateProperty(LogFilePathPropertyName, logFilePath);
        }

        logEvent.AddPropertyIfAbsent(logFilePathProperty);
    }
}

Then we'd create a command interceptor that looks for this setting and sets the static log file name

public class LogInterceptor : ICommandInterceptor
    {
        public void Intercept(CommandContext context, CommandSettings settings)
        {
            if (settings is LogCommandSettings logSettings)
            {
                LogFileNameEnricher.Path = logSettings.LogFile;
            }
        }
    }

Then our configuration looks something along these lines

var serviceCollection = new ServiceCollection()
    .AddLogging(configure =>
        configure.AddSerilog(new LoggerConfiguration()
            .MinimumLevel.Debug()
            .Enrich.With<LogFileNameEnricher>()
                .WriteTo.Map(LogFileNameEnricher.LogFilePathPropertyName,
                    (logFilePath, wt) => wt.File($"{logFilePath}"), 1)
            .CreateLogger()
        )
    );

using var registrar = new DependencyInjectionRegistrar(serviceCollection);
var app = new CommandApp(registrar);

app.Configure(config =>
{
    config.SetInterceptor(new LogInterceptor()); // add the interceptor
    config.AddCommand<MyCommand>("mycommand");
});

return app.Run(args);

TBH I'm not a huge fan of smuggling the file name around in a static variable, but I'm not totally sure a better way to get it from the interceptor into the enricher.

@patriksvensson, you have a better idea? If not I'm kind of tempted to create a new project in CLI examples

[phil-scott-78]

I created a demo app with this approach and pushed it here - https://github.com/phil-scott-78/spectre.console/tree/serilog-example/examples/Cli/Logging.

My chief concern is that if someone is logging outside of a command, then we won't have access to the command settings for that value. Biggest concern there would be a failure in Program.cs with configuring the command line parser and other bootstrapping code. It will log, just to a default filename.

Love some feedback on if this approach seems solid to you, @duncansmart. This is an excellent question about a common scenario, so I'd like to merge it into the main branch as an example for others in the future.

[duncansmart]

Great work @phil-scott-78, I got as far as ICommandInterceptor, but I started to draw a blank after that as my knowledge of Serilog is a bit light.

[phil-scott-78]

Glad it helped, I'm gonna work on getting my little example updated to also accept a LoggingLevel param once I figure out a clever way to set multiple properties with Seriolog.