Circular dependency exception when creating a custom logger relying on options with a options validator relying on a logger

Question

I have a .NET Core worker application and want to add a custom file logger since Microsoft.Extensions.Logging does not provide this. I don't want to use an extra package for this (e.g. Serilog).

I put information about the log directory and log file into my options class. This options class also has a validator implementing the IValidateOptions interface. This validator gets injected a logger instance to log validation errors if some occured.

The file logger provider needs to get injected the options monitor to get access to the directory and file configurations.

When running the application I unfortunately get an exception

System.AggregateException: 'Some services are not able to be constructed'

with the content

Error while validating the service descriptor 'ServiceType: Microsoft.Extensions.Hosting.IHostApplicationLifetime Lifetime: Singleton ImplementationType: Microsoft.Extensions.Hosting.Internal.ApplicationLifetime': A circular dependency was detected for the service of type 'Microsoft.Extensions.Logging.ILoggerFactory'. Microsoft.Extensions.Hosting.IHostApplicationLifetime(Microsoft.Extensions.Hosting.Internal.ApplicationLifetime) -> Microsoft.Extensions.Logging.ILogger<Microsoft.Extensions.Hosting.Internal.ApplicationLifetime>(Microsoft.Extensions.Logging.Logger<Microsoft.Extensions.Hosting.Internal.ApplicationLifetime>) -> Microsoft.Extensions.Logging.ILoggerFactory(Microsoft.Extensions.Logging.LoggerFactory) -> System.Collections.Generic.IEnumerable<Microsoft.Extensions.Logging.ILoggerProvider> -> Microsoft.Extensions.Logging.ILoggerProvider(Ajifsdjfijgsidjfijsdifjisd.FileLoggerProvider) -> Microsoft.Extensions.Options.IOptionsMonitor<MyLib.MyOptions>(Microsoft.Extensions.Options.OptionsMonitor<MyLib.MyOptions>) -> Microsoft.Extensions.Options.IOptionsFactory<MyLib.MyOptions>(Microsoft.Extensions.Options.OptionsFactory<MyLib.MyOptions>) -> System.Collections.Generic.IEnumerable<Microsoft.Extensions.Options.IValidateOptions<MyLib.MyOptions>> -> Microsoft.Extensions.Options.IValidateOptions<MyLib.MyOptions>(MyLib.MyOptionsValidator) -> Microsoft.Extensions.Logging.ILogger<Microsoft.Extensions.Options.IValidateOptions<MyLib.MyOptions>>(Microsoft.Extensions.Logging.Logger<Microsoft.Extensions.Options.IValidateOptions<MyLib.MyOptions>>) -> Microsoft.Extensions.Logging.ILoggerFactory

This makes sense because when injecting a new logger instance this one gets injected the options. And these will trigger the validator which gets injected a new logger instance. And so it starts again.

Logger => Options => Validator => Logger => Options => Validator => Logger => Options => Validator => ...

I don't know how to solve this problem because my file logger needs to get access to the configuration options and my options validator should log validation errors.

Any ideas?

---

If you want to get an overview about the application, this is what I did to reproduce it:

• Create a new .NET Core Worker project
• Head over to the .csproj file and add <FrameworkReference Include="Microsoft.AspNetCore.App" /> to the first item group to gain access to Kestrel and the web stuff
• I add a library MyLib to the project and reference it in the main project
• In the library I create a options class holding the information for the file logger

.

public class MyOptions
{
    public string DirectoryPath { get; set; }
    public string FileName { get; set; }
}

• I also add a simple options validator sample which makes use of a logger instance

.

public class MyOptionsValidator : IValidateOptions<MyOptions>
{
    private readonly ILogger<IValidateOptions<MyOptions>> logger;

    public MyOptionsValidator(ILogger<IValidateOptions<MyOptions>> logger)
    {
        this.logger = logger;
    }

    public ValidateOptionsResult Validate(string name, MyOptions myOptions)
    {
        if (string.IsNullOrEmpty(myOptions.DirectoryPath) || string.IsNullOrEmpty(myOptions.FileName))
        {
            logger.LogWarning("Invalid");

            return ValidateOptionsResult.Fail("Invalid");
        }

        return ValidateOptionsResult.Success;
    }
}

• I add the options to the appsettings.json file

.

"MyOptions": {
  "DirectoryPath": "C:\\Logs",
  "FileName": "log.log"
}

• In the library I extend the service collection to register the options validation

.

public static class IServiceCollectionExtensions
{
    public static IServiceCollection AddMyLib(this IServiceCollection services) =>
        services.AddSingleton<IValidateOptions<MyOptions>, MyOptionsValidator>();
}

• In the main project I setup the logging part. First I create a new file logger. Since this one can't be a "normal" service and won't be added to the DI container I simply expect the needed options in the constructor

.

internal class FileLogger : ILogger
{
    private readonly string fullLogFilePath;

    public FileLogger(string logDirectoryPath, string logFileName)
    {
        if (!Directory.Exists(logDirectoryPath))
            Directory.CreateDirectory(logDirectoryPath);

        fullLogFilePath = Path.Combine(logDirectoryPath, logFileName);
    }

    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
    {
        if (!IsEnabled(logLevel))
            return;

        using StreamWriter streamWriter = new StreamWriter(fullLogFilePath, true);
        streamWriter.WriteLine($"[{DateTime.Now}] [{logLevel}] {formatter(state, exception)} {exception?.StackTrace}");
    }

    public bool IsEnabled(LogLevel logLevel) => logLevel != LogLevel.None;

    public IDisposable BeginScope<TState>(TState state) => null;
}

• To serve this logger I added a provider

.

internal class FileLoggerProvider : ILoggerProvider
{
    private readonly IOptionsMonitor<MyOptions> myOptionsMonitor;

    public FileLoggerProvider(IOptionsMonitor<MyOptions> myOptionsMonitor)
    {
        this.myOptionsMonitor = myOptionsMonitor;
    }

    public void Dispose()
    {
    }

    public ILogger CreateLogger(string categoryName)
    {
        MyOptions myOptions = myOptionsMonitor.CurrentValue;

        return new FileLogger(myOptions.DirectoryPath, myOptions.FileName);
    }
}

• and extend the logging builder to add the file logger

.

public static class ILoggingBuilderExtensions
{
    public static void AddFileLogger(this ILoggingBuilder loggingBuilder)
    {
        loggingBuilder.Services.AddSingleton<ILoggerProvider, FileLoggerProvider>();
    }
}

• As you would do in a Web API project I added a startup file to configure all the options and setup the services

.

internal class Startup
{
    private readonly IConfiguration configuration;

    public Startup(IConfiguration configuration)
    {
        this.configuration = configuration;
    }

    public void ConfigureServices(IServiceCollection services)
    {
        services.AddMyLib();

        IConfigurationSection myOptionsSection = configuration.GetSection("MyOptions");
        services.Configure<MyOptions>(myOptionsSection);
    }

    public void Configure(IApplicationBuilder applicationBuilder)
    {
    }
}

• For the last part I updated the Program file to this

.

public class Program
{
    public static void Main(string[] args)
    {
        CreateHostBuilder(args).Build().Run();
    }

    public static IHostBuilder CreateHostBuilder(string[] args) =>
        Host.CreateDefaultBuilder(args)
            .ConfigureLogging(loggingBuilder =>
            {
                loggingBuilder
                    .ClearProviders()
                    .AddConsole()
                    .AddEventLog()
                    .AddFileLogger();
            })
            .ConfigureWebHostDefaults(webHostBuilder =>
            {
                webHostBuilder.UseKestrel().UseStartup<Startup>();
            })
            .ConfigureServices((hostContext, services) =>
            {
                services.AddHostedService<Worker>();
            });
}

• You should get a System.AggregateException because of a circular dependency

Answer 1

I followed @Olaf Svenson's recipe for replicating the problem, which I have been able to replicate. I then tried @Martin's approach by making the MyOptionsValidator aware that it needs a ILoggerFactory but it still resulted in a circular dependency scenario (somehow).

I think there should be a way to log unhandled exceptions so that you don't need to log anything in your MyOptionsValidator but rather let it return a failure result which would result in an exception being thrown and that be logged instead. But for Worker Services this seems to be an issue? Let's assume we cannot do this, then look at the solution I provided below...

(UPDATE: You actually don't even need to do this below but it was a cool challenge nonetheless. Don't log within your Validator. This will prevent the unnecessary complexity. The normal unhandled exception logging process will kick in and actually log to the other loggers when your logger's config is invalid. Super simple and very effective. Now you can have all kinds of loggers take care of this concern for you.)

My thinking is that this problem is a complicated one and you need to move the complexity to the DI space where it belongs (since that's where all the components and dependencies are wired up that caused this to happen) so that any new Validator that you write will not have to be aware of this "circular dependency" problem of a given logger that you want to inject.

The one method I tried to address this with is to create a Fall-back logger. Now I'm in no way saying my approach is the defacto standard but it solved the problem and since it should only run once (since the MyOptionsValidator is setup as a singleton) you don't have to worry about any performance hits at runtime.

I changed the code that did this:

public static IServiceCollection AddMyLib(this IServiceCollection services) =>
            services.AddSingleton<IValidateOptions<MyOptions>, MyOptionsValidator>();

To do this:

public static IServiceCollection AddMyLib(this IServiceCollection services) =>
            services.AddSingleton<IValidateOptions<MyOptions>, MyOptionsValidator>(
                sp => new MyOptionsValidator(CreateFallback<IValidateOptions<MyOptions>>()));

public static ILogger<T> CreateFallback<T>()
{
    return LoggerFactory.Create(x => x.AddConsole()).CreateLogger<T>();
}

I am not sure how to inject a secondary ILoggerFactory using the .NET Core DI infrastructure. Maybe you could create a wrapper class and use an embedded instance of a LoggerFactory and then resolve that wrapper class everywhere you would like to use the Fall-back logger?

You have to setup a separate LoggerFactory instance to make sure you don't expose the FileLogger that can cause the problem. This does mean that your AddMyLib extension method would have to move somewhere where you are happy to pull in the Microsoft.Extensions.Logging package (and whatever logger package you wish to use in the process) unless you can make use of the wrapper solution I mentioned (using an abstraction of course).

So if your app is incorrectly configured, it will log the configuration error and the app will stop running since the MyOptionsValidator causes an exception to be raised.

But if your app is correctly configured...

Answer 2

Look at this from a logical standpoint: if your logging configuration is invalid, you can't log using that configuration, period, so there's no use to introduce the circular dependency: the loggers created by your ILoggingFactory won't be able to log, because of the invalid configuration.

So if you want to log that your logging configuration is invalid, look at how other logging frameworks do that. First, decide for yourself whether you consider this a fatal state. Do you not want your application to run in this scenario? In other words: should an invalid logging configuration prevent the program from running, or should it run and not log?

Either let it throw an exception, so the configuration error leaks to the console or event log, or do it as log4net and the likes: have a default, fail-safe logging mechanism, like logging to console or an opt-in logger-error-logfile.

I'd opt for the latter, so let your logger fail silently, and add an optional setting like logErrorLogFile, to which your logger configuration can log its log configuration error, and have a separate DI flow for that (or hardcode it).

And if that fails, for example when the file is not writable, it can throw an exception. Or not.