Example of using NLog with CacheManager in .Net 5

[suntereo]

I cannot seem to get NLog working with CacheManager 2.0 PR. Here is the info I'd love to log with NLog:

info: CacheManager.Core.BaseCacheManager[0]
      Cache manager: adding cache handles...
info: CacheReflectionHelper[0]
      Creating handle 59979737-2b4c-495b-8e80-4acd9e474279 of type CacheManager.SystemRuntimeCaching.MemoryCacheHandle`1[TCacheValue].
info: CacheReflectionHelper[0]
      Creating handle 2f97cc37-c4ac-47d0-b066-1a335ec45b8a of type CacheManager.Redis.RedisCacheHandle`1[TCacheValue].
info: CacheManager.Redis.RedisConnectionManager[0]
      Trying to connect with the following configuration: '123.12.1.12:6379,allowAdmin=True,user=someuser,password=*****'
info: CacheManager.Redis.RedisCacheHandle[0]
      Loading scripts.

At best, I can only get this info to log to console.

Here's my Program.cs:

public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .ConfigureWebHostDefaults(webBuilder =>
        {
            webBuilder.UseStartup<Startup>();
        })
        .ConfigureLogging(logging =>
        {
            logging.ClearProviders();
            logging.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Information);
        })
        .UseNLog(new NLogAspNetCoreOptions() { ShutdownOnDispose = true });

And here is where I identity the logger for CacheManager:

public class CachingInstaller : IInstaller
{
    public void InstallServices(IServiceCollection services, IConfiguration configuration)
    {
        services.AddCacheManagerConfiguration(configuration, cfg =>
        {
            var loggerFactory = services.BuildServiceProvider().GetRequiredService<ILoggerFactory>();
            cfg.WithMicrosoftLogging(loggerFactory);
        });
        services.AddCacheManager();
    }
}

The above logs to console, but not via NLog and so my NLog target (Graylog) never receives this info.

I cannot seem to get cfg.WithLogging() working with any Type. CacheReflectionHelper always fails this check:

CheckImplements<ILoggerFactory>(configuration.LoggerFactoryType);

For example, if I do:

services.AddCacheManagerConfiguration(configuration, cfg =>
{
    cfg.WithLogging(typeof(LogFactory), new LogFactory());
    // -or -
    cfg.WithLogging(typeof(LogFactory), LogManager.GetCurrentClassLogger().Factory);
});

Then I get:
System.InvalidOperationException: 'Type must implement ILoggerFactory, but NLog.LogFactory does not.'

I'm guessing I'm just not passing the correct object. But what do I pass for NLog here?

Thanks

[MichaCo]

I guess it depends when your code to get the ILoggerFactory from the services collection runs.
If NLog creates a new Microsoft.Exntesions.Logging ILoggerFactory somewhere, then you might get one which was created beforehand.
Best would be to inject ILoggerFactory to the ctor of your startup and then pass that to cfg.WithMicrosoftLogging

cfg.WithLogging only accepts, implementations CacheManager's ILoggerFactory interface.
That's the pain with abstractions ;)

:edit:
@suntereo I got it working with the HostingExample app from here: https://github.com/NLog/NLog.Extensions.Logging/tree/master/examples/NetCore2

Had to move UseNLog to run before configure services. That's still a bit fishy, because I still have to build the services collection and then am just lucky to get the right instance of the LoggerFactory ~~.
But it works at least.

var hostBuilder = new HostBuilder()
    .ConfigureLogging(builder => builder.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Trace))
    .UseNLog(new NLogProviderOptions()
    {
    })
    .ConfigureServices((hostContext, services) => 
    {
        services.AddHostedService<ConsoleHostedService>();
        services.AddCacheManagerConfiguration(b =>
        {
            var loggerFactory = services.BuildServiceProvider().GetRequiredService<ILoggerFactory>();
            b.WithDictionaryHandle();
            b.WithMicrosoftLogging(loggerFactory);

        });
        services.AddCacheManager();
    });

By looking into the code what the UseNLog extension is doing, I found that they in the end call services.Replace(ServiceDescriptor.Singleton<ILoggerFactory, NLogLoggerFactory>, which basically replaces the already configured ILoggerFactory from ConfigureLogging with a new one. That's why you don't pass the right instance to CacheManager in your code I think.
So in that case order matters.

[suntereo]

Wow! You found it. I can confirm that putting ConfigureWebHostDefaults after UseNLog works for me in .Net 5 as well.

public static IHostBuilder CreateHostBuilder(string[] args) =>
   Host.CreateDefaultBuilder(args)
       .ConfigureLogging(logging =>
       {
           logging.ClearProviders();
           logging.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Trace);
       })
       .UseNLog(new NLogAspNetCoreOptions() { ShutdownOnDispose = true })
       .ConfigureWebHostDefaults(webBuilder => // this must be after UseNLog()
       {
           webBuilder.UseStartup<Startup>();
       });

I don't think I would have ever found that on my own. Thank you so much!

[suntereo]

After using this solution for a little while, I realized that I'm only seeing CacheManager initialization info. But I'm not seeing trace info for each cache operation. For example, see Logging. On add(), I'm not seeing:

CacheManager.Core.BaseCacheManager<object>: Trace: Add: key 
CacheManager.Core.BaseCacheManager<object>: Trace: Add: successfully added key  to handle redis
CacheManager.Core.BaseCacheManager<object>: Trace: Add: successfully added key  to handle default

I'm not sure what is keeping this info from making its way into the log. Are you seeing it in your HostingExample app logging?

[MichaCo]

Probably filtered? The initialization is info level. What you are looking for is Trace level. I guess your nlog config or something else has some log level filtering

[suntereo]

Yes, that was it. It turns out I had a appsettings.Development.json that was setting the default LogLevel to Information. Once I changed it to Trace, I began to see the operation log entries. I didn't think to look at the dev config. Thanks again!