Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Feature Request] Allow libraries that don't use DI to make use of ILogger #50777

Open
noahfalk opened this issue Apr 6, 2021 · 38 comments
Open

Comments

@noahfalk
Copy link
Member

noahfalk commented Apr 6, 2021

My biggest current challenge recommending library authors to use ILogger in preference to EventSource is that their library may not use dependency injection. I mean this in the general sense that their library may not have a constructor parameter or a property where an ILogger object could be passed to them and they either can't or don't want to modify their library to add those parameters. Currently EventSource satisfies that use-case well because they can be new'ed up anywhere and automatically register globally, eliminating the need to pass them around. If we want ILogger to support a similar range of usage then we need to support some globally scoped ILoggers.

To be upfront - I've never had a specific library author push back because this issue affected them. However on the other hand I avoid making blanket statements that library authors should use ILogger, nor do I write that guidance in our docs, primarily because of this concern. Its possible if I started pushing there would be no issue at all, or alternatively the complaints might start rolling in that we didn't think this through before we started encouraging more people to use it. My best guess is that people would quietly make workarounds by adding mutable static fields to their libraries and adding APIs like Library.InitLogger(ILogger) and writing to it with MyLibrary.s_logger?.Log(...). It works for simple cases but it isn't a great place to be:

  • It requires all the library consumers to learn the different API conventions each library author used so they can call all the Init methods
  • Any scenario that would use more than one DI container will have more than one LoggerFactory, but only one ILogger can ever be registered.

I think this entails two steps:

  1. Provide some API that creates/registers a global ILogger. For example it might be LoggerFactory.Global.CreateLogger(loggerName).
  2. Provide a way for log consumers to subscribe to those global loggers. Two options so far:
    • One proposal was that you would register providers on the global factory just as you would any other factory. We would have some API that configures the DI container to use the global factory instead of creating a new LoggerFactory instance.
    • Another option is that you invoke some new API on any logger factory, ie factory.UseGlobalLoggers(), so that the loggers on the global factory become visible to the non-global factory.

At the moment the 2nd option sounds better to me, but there isn't broad agreement on it. The scenario I am imagining is something like you've got multiple test cases, each of which have their own DI container, their own LoggerFactory, and their own logging output. However all the test cases interact with a shared library and it would improve diagnosability if the log output from that shared library could be added to the test logging as well. The 2nd option appears to allow that easily whereas with the 1st option I didn't see a straightforward approach.

@dotnet-issue-labeler dotnet-issue-labeler bot added area-Extensions-Logging untriaged New issue has not been triaged by the area owner labels Apr 6, 2021
@ghost
Copy link

ghost commented Apr 6, 2021

Tagging subscribers to this area: @maryamariyan
See info in area-owners.md if you want to be subscribed.

Issue Details

My biggest current challenge recommending library authors to use ILogger in preference to EventSource is that their library may not use dependency injection. I mean this in the general sense that their library may not have a constructor parameter or a property where an ILogger object could be passed to them and they either can't or don't want to modify their library to add those parameters. Currently EventSource satisfies that use-case well because they can be new'ed up anywhere and automatically register globally, eliminating the need to pass them around. If we want ILogger to support a similar range of usage then we need to support some globally scoped ILoggers.

To be upfront - I've never had a specific library author push back because this issue affected them. However on the other hand I avoid making blanket statements that library authors should use ILogger, nor do I write that guidance in our docs, primarily because of this concern. Its possible if I started pushing there would be no issue at all, or alternatively the complaints might start rolling in that we didn't think this through before we started encouraging more people to use it. My best guess is that people would quietly make workarounds by adding mutable static fields to their libraries and adding APIs like Library.InitLogger(ILogger) and writing to it with MyLibrary.s_logger?.Log(...). It works for simple cases but it isn't a great place to be:

  • It requires all the library consumers to learn the different API conventions each library author used so they can call all the Init methods
  • Any scenario that would use more than one DI container will have more than one LoggerFactory, but only one ILogger can ever be registered.

I think this entails two steps:

  1. Provide some API that creates/registers a global ILogger. For example it might be LoggerFactory.Global.CreateLogger(loggerName).
  2. Provide a way for log consumers to subscribe to those global loggers. Two options so far:
    • One proposal was that you would register providers on the global factory just as you would any other factory. We would have some API that configures the DI container to use the global factory instead of creating a new LoggerFactory instance.
    • Another option is that you invoke some new API on any logger factory, ie factory.UseGlobalLoggers(), so that the loggers on the global factory become visible to the non-global factory.

At the moment the 2nd option sounds better to me, but there isn't broad agreement on it. The scenario I am imagining is something like you've got multiple test cases, each of which have their own DI container, their own LoggerFactory, and their own logging output. However all the test cases interact with a shared library and it would improve diagnosability if the log output from that shared library could be added to the test logging as well. The 2nd option appears to allow that easily whereas with the 1st option I didn't see a straightforward approach.

Author: noahfalk
Assignees: -
Labels:

area-Extensions-Logging, untriaged

Milestone: -

@maryamariyan
Copy link
Member

maryamariyan commented Apr 7, 2021

I have been thinking in detail about whether or not we could come up with a set of best practices (in case it doesn't exist yet) when dealing with libraries such as Logging that have been designed with DI in mind as their object creation pipeline.

I have gathered a set of bulletpoints (general ideas) below that I wanted to share here as it seems to be very relevant to the discussion here. These points are not specific to logging, but in general might make sense to always keep in mind when we want to design libraries that need to work well in combination with DI.

Allow libraries that don't use DI to make use of ILogger

I am in favor of making sure our Logging libraries are robust enough such the developers/library authors using it can still take advantage of it whether they are

  • [A] using DI containers to create/manage their objects (including ILogger instances)
  • [B] using global instances if they want to
  • [C] using a global container instance to get objects (ILogger instances in this case)
    or any other way.

From the point of view of the Developer using our library,

  • Developers using the logging library, should not be affected if we internally use DI as our object creation pipeline
  • Developers who DON'T care about DI should not be affected by our library using it internally
  • Developers who DO care about DI can choose the container they want to use and get both their objects and our library objects out of it.

From the point of view of the logging library itself:

  • Logging library would not need to know/care about how the objects (including ILogger) are wired up under the hood

Any scenario that would use more than one DI container will have more than one LoggerFactory, but only one ILogger can ever be registered.

My idea is that, it is good practice if library authors always consider having only one object creation pipeline in their applications. I want to learn about when it is actually appropriate for an application to have multiple DI containers available.


If the above bullet points are somewhat agreed upon, then we could hopefully use them as a basis to understand what we are missing for libraries authors/developers that do not use DI to make use of ILogger.

I came across this blog post as well (a bit old but still relevant) which helps back the bulletpoints I added above: https://docs.microsoft.com/en-us/archive/msdn-magazine/2009/november/dependency-injection-in-libraries#howd-we-do

@noahfalk
Copy link
Member Author

noahfalk commented Apr 7, 2021

I want to learn about when it is actually appropriate for an application to have multiple DI containers available.

Poking around a little on github it shows ~8000 results for C# code creating new LoggerFactory instances and 50,000 results for C# code creating new ServiceCollection instances. I didn't dive very deep, but a lot of the usage appears to be test cases.

Looking at the ASP.NET team's tests we see lots of xunit test cases that derive from LoggedTest and the Initialize() method creates a unique ServiceCollection and LoggerFactory object for each one. Each test's LoggerFactory is hooked up to a unique SerilogLoggerProvider that outputs to a unique named file. If all the tests were attempting to share a single global LoggerFactory (or a single DI container with a single factory inside it) then they would be unable to have those unique configurations.

From the point of view of the Developer using our library...

I think there are two different Developer points of view, not sure which you were refering to?

  • Library authors want to generate log messages (for example the ASP.Net dev team or a 3rd party library author)
  • Application authors want to configure which log messages to collect and where they should be stored

The scenario I had in mind is:

  • Library author doesn't want to use DI, but does want to use ILogger.
  • App developer may or may not want to use DI, but does want to receive log messages from that library

Trivial example, library code:

class Foo
{
    void DoSomething()
    {
        // As the library author I want to log this error. I am willing to change the implementation but
        // I do not want to change the public API (aka I am unwilling/unable to use a DI pattern).
        // This means there is no API that lets my caller pass me an ILogger instance.
        string errorString = "Oops a bad thing happened";
     }
}

Trivial example, app code:

LoggerFactory f = ConfigureFactory();
Foo f = new Foo();

// As the app author I want to see the error in this code get logged. I am flexible about what
// code goes inside ConfigureFactory() to make that happen.
f.DoSomething();

@maryamariyan
Copy link
Member

maryamariyan commented Apr 7, 2021

Thanks for the explanation. Based on the issue description, it seems like from a library author's standpoint, a sample problem at hand is regarding how they could potentially get a hold of a global ILogger in their codebase in a case like below:

their library may not have a constructor parameter or a property where an ILogger object could be passed to them and they either can't or don't want to modify their library to add those parameters.

My best guess is that people would quietly make workarounds by adding mutable static fields to their libraries and adding APIs like Library.InitLogger(ILogger) and writing to it with MyLibrary.s_logger?.Log(...). It works for simple cases but it isn't a great place to be:

  • It requires all the library consumers to learn the different API conventions each library author used so they can call all the Init methods
  • Any scenario that would use more than one DI container will have more than one LoggerFactory, but only one ILogger can ever be registered.

I think this makes it even more pressing that there needs to be general best practices here for library designs, not only for our logging library itself but also for any 3rd party library author dealing with ILogger in this case:

  • It should not matter if they do not rely on DI containers internally to manage their dependencies
  • But (I think) they should refrain from using static instantiation, not only because of the two bulletpoints that you stated above, but also because this would cause them to restrict their own library consumers or app developers from being able to use DI containers to instantiate ILogger if they wanted to (there would only ever be that one static ILogger that has now bled into the code and that DI container would not be able to access it if it has been set in the 3rd party library).

And the f.DoSomething() example you presented illustrates this challenge from the point of view of both the third party library using our ILogger as well that library's app author.

I am guessing the scope of this issue is to find out any sort of API or functionality that is missing in our logging library such that getting from the above example only requires the library authors to refactor their code using (a) internal APIs or (b) extension methods to make accessing of arbitrary ILoggers f.DoSomething() just work. (since the restriction is on them not wanting/being able to change their public APIs).

If that is the ask here, I would argue that the main purpose of trying to do DI constructor injection is to clearly state dependencies upfront. The alternative would be to hide this dependency through some sort of mechanism, abstraction, or factories, etc. I assume that it should be fine for a library author to not necessarily rely on DI ctor injection to declare its own inner dependencies, but they should do that in a format that does not block their own users from wanting to use DI containers, if they wanted, to get access to ILogger for example.


this blog post is very relevant to this issue https://docs.microsoft.com/en-us/archive/msdn-magazine/2009/november/dependency-injection-in-libraries, and it presents a very relevant logging case study as well.

@maryamariyan maryamariyan removed the untriaged New issue has not been triaged by the area owner label Apr 22, 2021
@maryamariyan maryamariyan added this to the 6.0.0 milestone Apr 22, 2021
@maryamariyan maryamariyan modified the milestones: 6.0.0, 7.0.0 Jul 22, 2021
@noahfalk
Copy link
Member Author

I've been looking into this more lately and pondering if we had cheaper options that might involve guidance/samples rather than new public APIs. Above I was suggesting that library developers wouldn't want to modify their public API at all but that is probably too strong a requirement. What seems more likely is that they don't want to make sweeping changes or modify their existing types, but they would be willing to add a small amount of new surface area that allows better interaction with ILogger. In fact in the initial description I proposed they would write some static InitLogger(ILogger logger) function which is an example of a minimal public surface area addition.

Instead of that InitLogger function we could suggest alternate patterns based on extension methods for ILoggerFactory or IServiceContainer that align more closely with how libraries would normally integrate into the DI container. This still has the limitation they can't have some of their library types logging to LoggerFactoryA and others logging to LoggerFactoryB, but I think that is a fundamental limitation of being unwilling to expose the logging dependency in a type's constructor/factory. For the other issues it offers libraries more consistent patterns on how to register and it could be implemented in a way that multiplexes the logging to multiple LoggerFactories.

App code

The app author gets to pick one of these:

App option 1 - No-host app:

static void Main(string[] args)
{
    ConfigureFactory();

    Foo f = new Foo();   // this type is provided by library author and it has logging inside it
    f.DoSomething();      
}

static void ConfigureFactory()
{
    ILoggerFactory factory = LoggerFactory.Create(builder =>
    {
        // whatever arbitrary config the app dev wants here...
        builder.AddConsole(); 
    });
    factory.AddFooLibLogging();  // this method was provided by the library author
}

App Option 2 - hosted app

static void Main(string[] args)
{
    IHost host = Host.CreateDefaultBuilder(args)
        .ConfigureLogging(logging =>
        {
            // whatever arbitrary config the app dev wants here...
            logging.AddConsole();
        })
        .ConfigureServices(services =>
        {
           services.AddFooLib(); // this method was provided by the library author
        })
    .Build();

    // one of many ways the app developer can run some code with their host...
    IHostApplicationLifetime lifetime = host.Services.GetService<IHostApplicationLifetime>();
    lifetime.ApplicationStarted.Register(() =>
    {
        Foo f = new Foo();  // this type is provided by library author and it has logging inside it
        f.DoSomething();
    });

    host.Run();
}

Library Code

The library dev gets to pick one of these depending on whether they want to reuse existing EventSources or they are instrumenting with ILogger directly:

Library Option 1 - Using ILogger

Library implements their Foo type with a static ILogger instance:

    class Foo
    {
        internal static ILogger<Foo> Log { get; set; } = new NullLogger<Foo>();

        public void DoSomething() 
        {
            Log.LogInformation("Something happened");
        }
    }

Library implements the extension methods to let app authors enable the logging:

    public static class ExtensionFunctions
    {
        public static ILoggerFactory AddFooLibLogging(this ILoggerFactory factory)
        {
            // this impl doesn't support multiplexing to multiple LoggerFactories but
            // but a more complex one could
            Foo.Log = factory.CreateLogger<Foo>();
            return factory;
        }

        internal static void RemoveFooLibLogging(this ILoggerFactory factory)
        {
            Foo.Log = new NullLogger<Foo>();
        }

        public static IServiceCollection AddFooLib(this IServiceCollection services)
        {
            services.AddHostedService<LoggerFactoryForwarder>();
            return services;
        }
    }

    class LoggerFactoryForwarder : IHostedService
    {
        ILoggerFactory _loggerFactory;
        public LoggerFactoryForwarder(ILoggerFactory factory)
        {
            _loggerFactory = factory;
        }

        public Task StartAsync(CancellationToken cancellationToken)
        {
            _loggerFactory.AddFooLibLogging();
            return Task.CompletedTask;
        }

        public Task StopAsync(CancellationToken cancellationToken)
        {
            _loggerFactory.RemoveFooLibLogging();
            return Task.CompletedTask;
        }
    }

Library Option 2 - Adapt pre-existing EventSource instrumentation

Library author has their existing implementation:

    [EventSource(Name = "FooCompany-Foo")]
    class FooEventSource : EventSource
    {
        [Event(1, Message = "Something happened")]
        public void SomethingHappened()
        {
            WriteEvent(1);
        }
    }

    class Foo
    {
        internal static FooEventSource Log { get; private set; } = new FooEventSource();

        public void DoSomething() 
        {
            Log.SomethingHappened();
        }
    }

Library dev creates this (sadly non-trivial) adapter. This is roughly cribbed from what Azure SDK is doing.

    public static class ExtensionFunctions
    {
        static LoggerFactoryForwarder s_forwarder; 
        public static ILoggerFactory AddFooLibLogging(this ILoggerFactory factory)
        {
            s_forwarder = new LoggerFactoryForwarder(factory);
            return factory;
        }

        public static IServiceCollection AddFooLib(this IServiceCollection services)
        {
            services.AddHostedService<LoggerFactoryForwarder>();
            return services;
        }
    }

    class LoggerFactoryForwarder : EventListener, IHostedService
    {
        ILoggerFactory _loggerFactory;
        ILogger<Foo> _logger;
        public LoggerFactoryForwarder(ILoggerFactory factory)
        {
            _loggerFactory = factory;
        }

        public Task StartAsync(CancellationToken cancellationToken)
        {
            Start();
            return Task.CompletedTask;
        }

        public void Start()
        {
            _logger = _loggerFactory.CreateLogger<Foo>();
            EnableEvents(Foo.Log, EventLevel.Informational);
        }

        public Task StopAsync(CancellationToken cancellationToken)
        {
            Stop();
            return Task.CompletedTask;
        }

        public void Stop()
        {
            DisableEvents(Foo.Log);
        }

        protected override void OnEventWritten(EventWrittenEventArgs eventData)
        {
           // AzureSDK had some custom formatting logic here which makes the adapter yet larger
           // I omitted it for brevity
            _logger.Log(ConvertLogLevel(eventData.Level), eventData.Message, new EventSourceEvent(eventData));
        }

        LogLevel ConvertLogLevel(EventLevel level)
        {
            return level switch
            {
                EventLevel.LogAlways => LogLevel.Critical,
                EventLevel.Critical => LogLevel.Critical,
                EventLevel.Error => LogLevel.Error,
                EventLevel.Warning => LogLevel.Warning,
                EventLevel.Informational => LogLevel.Information,
                _ => LogLevel.Trace
            };
        }

        private readonly struct EventSourceEvent : IReadOnlyList<KeyValuePair<string, object>>
        {
            public EventWrittenEventArgs EventData { get; }

            public EventSourceEvent(EventWrittenEventArgs eventData)
            {
                EventData = eventData;
            }

            public IEnumerator<KeyValuePair<string, object>> GetEnumerator()
            {
                for (int i = 0; i < Count; i++)
                {
                    yield return new KeyValuePair<string, object>(EventData.PayloadNames[i], EventData.Payload[i]);
                }
            }

            IEnumerator IEnumerable.GetEnumerator()
            {
                return GetEnumerator();
            }

            public int Count => EventData.PayloadNames.Count;

            public KeyValuePair<string, object> this[int index] => new KeyValuePair<string, object>(EventData.PayloadNames[index], EventData.Payload[index]);
        }
    }

I think seeing these working gives me a little more confidence giving blanket recommendations for ILogger, even though I feel a little gross asking a library dev to write that EventSource -> ILogger adapter if they find themselves in option 2. Maybe there aren't many devs that are in that situation, but if we get feedback that are a lot of people doing this we should try to make some shared community or runtime implementation of the forwarder.

Thoughts?
@maryamariyan @tarekgh @shirhatti @davidfowl

@tarekgh tarekgh modified the milestones: 7.0.0, .NET 7.0 Nov 24, 2021
@karelz karelz modified the milestones: .NET 7.0, 7.0.0 Nov 25, 2021
@roji
Copy link
Member

roji commented Dec 28, 2021

👍 on this, ran into this problem when adopting Microsoft.Extensions.Logging for the Npgsql library, where ADO.NET is not DI-compatible. Some best practices and documentation would be helpful.

@noahfalk
Copy link
Member Author

noahfalk commented Jan 3, 2022

@roji thanks for feedback! Were you primarily suggesting that the info above was good but needed to be more easily discoverable, or that more info is needed, or both?

Some best practices

I'll admit I have seen very few real world examples so far. I think and hope the above suggestions will be effective, but I wouldn't want to claim this is a well proven technique if Azure SDK is my only data point : )

@roji
Copy link
Member

roji commented Jan 4, 2022

@noahfalk I think the info above is good - it's mostly that it needs a home under the logging documentation section (i.e. a sub-page for implementing logging for libraries?).

One thing about "Library Option 1": there's a suggested AddFooLib which accepts an IServiceCollection, for making it easier to use in DI scenarios. First of all, I wouldn't necessarily recommend that applications take a dependency on Microsoft.Extensions.DependencyInjection.Abstractions just in order to provide such an adapter; if the library really isn't DI-compatible (after all, it accepts its ILoggerFactory statically) then it probably makes sense for users to just invoke the static configuration method directly.

If it is possible for the library to just get the ILoggerFactory from DI, like a proper DI-aware library (similar to ASP.NET, EF Core), then obviously static configuration of ILoggerFactory is out of place in the first place. So when explaining this to library maintainers, I'd maybe split this into "DI-aware libraries" and "non-DI-aware libraries", where only the latter accepts ILoggerFactory manually.

Apart from that, I haven't seen many libraries which have a pre-existing EventSource which they'd like to adapt to logging - but maybe that's useful.

@noahfalk
Copy link
Member Author

noahfalk commented Jan 5, 2022

then it probably makes sense for users to just invoke the static configuration method directly.

The tradeoff appears to be the library can either take the dependency on M.E.DI.Abstractions (43KB binary) + write some boiler plate code to get a more idiomatic looking configuration or it can avoid the reference and have a less idiomatic initialization. If the library author does do the extra work I think you get an app developer experience like this:

var builder = WebApplication.CreateBuilder(args);

// Add services to the container.
builder.Services.AddRazorPages();
builder.Services.AddFooLib();

var app = builder.Build();
...

and if you don't do the extra work you get an app developer experience like this:

var builder = WebApplication.CreateBuilder(args);

// Add services to the container.
builder.Services.AddRazorPages();

var app = builder.Build();
app.Services.GetService<ILoggerFactory>().AddFooLibLogging();
...

Admitedly as a guy who does most of my coding in not so pretty code inside the coreclr.dll this feels like a pretty minor distinction so I'm inclined to agree with you - it doesn't seem worth the extra effort. However I don't know if folks like @davidfowl have stronger opinions about the style/idioms he is trying to encourage. If I don't hear anything further I'm going to go with your suggestion that the non-DI-aware libraries make an 'AddFooLibLogging()' method available only.

@roji
Copy link
Member

roji commented Jan 5, 2022

Yeah, I do get the argument about API niceness.

Another argument here is that builder.Services.AddFooLib() gives the impression of a proper DI-aware library, where the ILoggerFactory gets managed within the service provider. This isn't the case - under the hood it's actually managed statically, which e.g. means that you can't have two service providers with different logging configurations in the same application. I'd say it's better not to hide that fact, and make the static aspect very explicit; in fact, rather than an AddFooLibLogging extension method, I'd simply tell users to call an explicitly static method to initialize logging, e.g. FooLoggingConfiguration.Initialize(ILoggerFactory loggerFactory).

@davidfowl
Copy link
Member

Also agreed with @roji above. For a library that has no way of accessing a LoggerFactory other than by having it cached in a static I think caching the one from the DI container is likely the best option. The only other options I see which feel worse:

I'll concede. That's the best option proposed here. However, put up warning signs here explaining that this static entry point should only be called once and that this library won't work well with unit tests and the other things that using DI makes easy (like having multiple in the same process).

@julealgon
Copy link

Not necessarily a (public) library author myself so take my opinion with a grain of salt. However:

My biggest current challenge recommending library authors to use ILogger in preference to EventSource is that their library may not use dependency injection.

I don't see how this matters to be honest. One doesn't need to use "dependency injection containers" to use proper inversion of control best practices. Some people even go with "poor-man's DI" on big projects and have success with that.

A library could still take an ILogger as a parameter and have a factory implementation that creates a "sensible default" without requiring static references. Then, if someone wants to use the library with a DI container, they can just not use the factory and register the classes directly on their end. This requires zero DI "support" from library developers.

I mean this in the general sense that their library may not have a constructor parameter or a property where an ILogger object could be passed to them and they either can't or don't want to modify their library to add those parameters.

Well if they don't want to do anything on their side, I don't think the framework should either. Adding static versions of ILogger and things like that would massively degrade the quality of these APIs and might push people away from proper inversion of control on new applications. I'd be 100% opposed of providing any static abstractions in Microsoft.Extensions.Logging and I think any library that does this currently shouldn't as well.

Currently EventSource satisfies that use-case well because they can be new'ed up anywhere and automatically register globally, eliminating the need to pass them around. If we want ILogger to support a similar range of usage then we need to support some globally scoped ILoggers.

Supporting this specific use case directly is a mistake IMHO. There is even an EventSource ILogger implementation already they can use by default. There shouldn't be any reason to ever hardcode a EventSource dependency for logging purposes: that just makes your library much worse to use/debug.

One such case is the .NET OpenTelemetry integration, which currently doesn't support logging through ILogger and uses EventSource directly in code. As a consumer of that library, this made me spend several hours of frustration until I realized that it was not logging errors to my logger and that I had to enable a listener or a self-diagnostics process.

@lmolkova
Copy link

lmolkova commented Aug 23, 2024

Adding some color to it from Azure SDK / System.ClientModel perspective.

Let's assume we take ILoggerFactory via public API in clients. We'll make it as DI friendly as it could be, so it's properly resolved for all apps that do DI

Let's assume there is non-negligeable number of users that don't use DI or use our clients unconventionally - e.g. don't register them in the DI and don't pass ILoggerFactory.

Now, imagine such user app has a problem and now they can't enable logs without code change and full redeployment.
Should users change their code to get awesome ILogger logs? Absolutely! Do we want to require them to change app code to get logs out in some form? Absolutely not.

This is the critical part of the problem for us. We don't necessarily need a perfect way to configure logger factory as a static singleton, we need the operational fallback.

As a solution we could do some form of Option 2 from the issue description:

  • Custom EventSource as a fallback to replicate ILogger logs
  • Take an explicit dependency on Microsoft.Extensions.Logging.EventSource and configure factory with ES provider as a fallback
  • Shade Microsoft.Extensions.Logging.EventSource to avoid taking a dependency

All of these options are possible, but have problems.

It seems to be a generic problem though and it'd be great if Microsoft.Extensions.Logging.Abstractions provided operational fallback that does at least something to get the logs out without asking users to change application code.

@julealgon
Copy link

@lmolkova

Let's assume there is non-negligeable number of users that don't use DI or use our clients unconventionally - e.g. don't register them in the DI and don't pass ILoggerFactory.

Can you provide an example of how that would look like for a hypothetical library class?

I just don't see why the library should make these types of decisions for the consumer. If they are using your class directly, and purposefully not passing an ILoggerFactory, then the library should just throw an ArgumentNullException requiring the ILoggerFactory to be provided.

That has nothing to do with DI containers.

The only difference is that, to more simply support DI registrations, your library would provide a AddX() extension method on IServiceCollection that registers the things it needs to run with "sensible defaults", either in the same DLL, or as part of a MyLIbraryThing.DependencyInjection or MyLIbraryThing.Extensions.Hosting separate package.

If the user opts to not use DI, then it's up to them to provide something the library can use. If they decide they don't need any logging and pass in a NullLoggerFactory (a null-object pattern implementation of ILoggerFactory) to your library code, and then later decide they do want some logging capability, that's on them to fix... putting that burden on the library to me is not appropriate and will just lead to a substantial increase in complexity in the library code.

It seems to be a generic problem though and it'd be great if Microsoft.Extensions.Logging.Abstractions provided operational fallback that does at least something to get the logs out without asking users to change application code.

What would these fallbacks look like exactly though?

@lmolkova
Copy link

lmolkova commented Aug 24, 2024

It can look like this:

https://github.com/StackExchange/StackExchange.Redis/blob/fe40d17167ec25b16b1d6d6f91b9bea53276d854/src/StackExchange.Redis/ConfigurationOptions.cs#L542

ILoggerFactory must be optional - it's ok to use a library without logging. The clients could be registered in DI in many different ways, not just through blessed AddSomething methods.

The fallback could be the following:

  • if user provided a factory in any way (via DI, explicitly) - use it
  • if they didn't - create our own with LoggerFactory.Create(b => b.AddEventSourceLogger()) or something similar

Then users who configured logging will have it, those who don't can start listening to the corresponding event source via PerfView, dotnet-monitor or any other similar consumer without the need to change their code and redeploy the app.

@noahfalk
Copy link
Member Author

It seems to be a generic problem though and it'd be great if Microsoft.Extensions.Logging.Abstractions provided operational fallback that does at least something to get the logs out without asking users to change application code.

It wasn't clear what the request would be for M.E.L.Abstractions? It looked like you were suggesting the library would create its own LoggerFactory via LoggerFactory.Create() which is already a public API and something you could do without any runtime changes.

@lmolkova
Copy link

lmolkova commented Aug 24, 2024

@noahfalk
It requires us to take a dependency on M.E.L.EventSource, copy and paste its code or write our own custom EventSource.

Given that it's a generic problem for any library that can be used without DI, the ask is to have something operational by default out-of-the-box.

The alternative could be auto-discovery based on installed libraries - It's a common logging practice to enable logging by detecting an implementation package and/or configuring env vars. But with M.E.Logging we ask users to install things AND also pass ILoggerFactory to their clients (semi-magically or explicitly).

@davidfowl
Copy link
Member

davidfowl commented Aug 25, 2024

I'd like to make sure we don't make it easy for MEL to be used in that way. The testing situation with event source is not great and shared mutable state is a downfall of testability 😄. Let's not introduce this problem here.

@lmolkova
Copy link

lmolkova commented Aug 25, 2024

The trade-off is default user experience vs testability. For tracing and metrics we chose user experience and for logging we keep choosing testability. Why?

[Update] I'd be happy with any solution that reliably provides some default experience (not requiring users to pass ILoggerFactory to every instance of their client). EventSource is just the obvious one

@davidfowl
Copy link
Member

davidfowl commented Aug 25, 2024

I think the default for all of these APIs should be testability, but that's not the primary purpose. It's the side effects of what building a testable (and sometimes mockable) API enables. The ability to isolate calls to a specific logger factory instance (and same with meters and traces) is extremely useful when trying to build complex software.

Serilog has an interesting design here where there's a static Logger.Log can be assigned an ILogger instance:

using Serilog;

Log.Logger = new LoggerConfiguration()
    .WriteTo.Console()
    .CreateLogger();

try
{
    // Your program here...
    const string name = "Serilog";
    Log.Information("Hello, {Name}!", name);
    throw new InvalidOperationException("Oops...");
}
catch (Exception ex)
{
    Log.Error(ex, "Unhandled exception");
}
finally
{
    await Log.CloseAndFlushAsync(); // ensure all logs written before app exits
}

The reason this is "less bad" is because application code is supposed to do this, not library code. Library code should not be assuming shared static configuration (when it can be avoided).

@lmolkova
Copy link

lmolkova commented Aug 25, 2024

I agree with all you're saying, but it does not solve the problem for libraries.

If BCL does not provide a fallback, we'd need to do it ourselves. Some of libs might decide that lack of default experience is a blocker and will not do logging at all (or keep using EventSource).

All libs that will implement a fallback will do it differently making users life hard.

@davidfowl
Copy link
Member

The only blocker libraries should have is the dependency on ILoggerFactory. The only reason to log using event source is if you're unwilling to take that dependency or you are below the dependency graph of the ILoggerFactory (like you are implementing one and need to log errors from the logger implementation).

The library just has to worry about providing a way to set the ILoggerFactory so that the application can decide which configuration the library should use.

PS: This is what the Azure SDK should do instead of using the EventSource. It would make it much easier to use and test without the event source -> Ilogger adapter.

@lmolkova
Copy link

lmolkova commented Aug 25, 2024

I feel we're talking about different things. Let's forget about what Azure SDKs currently do and let's imagine a perfect future.

What we'd like to have:

  1. User created client and provided ILoggerFactory (registered via DI or explicitly) - we should use resolved factory and things work great out of the box - we do need to provide this experience
  2. User creates client without DI using explicit constructor and didn't explicitly provide the ILoggerFactory.
    1. user probably did it by mistake or lack of awareness. In the long term they should change their code and fix it (by passing ILoggerFactory to the clients in any supported way).
    2. but let's assume they have an immediate problem with their app and are requesting support on the issue from our library/service. We really want to have some way to get logs (+traces/metrics) out without asking them to change code and redeploy everything.

What I'd like to have to solve the p2.2

  • if we didn't get explicit ILoggerFactory use some FallbackFactory. We can do it today by creating our own factory instance. It has it's own drawbacks ([Feature Request] Allow libraries that don't use DI to make use of ILogger #50777 (comment))
  • it'd be nice if M.E.L provided some operational fallback (not just NullLoggerFactory) that we could use.
  • the only reasonably safe fallback I can imagine would be the EventSource provider, but that's an impl detail.

@davidfowl
Copy link
Member

What sorts of apps are your primary concern?

Practically, it seems like what is being proposed here is to provide an API that creates a logger factory with an event source logger provider. What do you tell the customer to do see the logs? Use dotnet trace or perfview?

Maybe the console logger is a more pragmatic solution…

@lmolkova
Copy link

lmolkova commented Aug 26, 2024

What sorts of apps are your primary concern?

nothing in particular. Any non-ASP.NET Core apps where DI is not a common practice.

Practically, it seems like what is being proposed here is to provide an API that creates a logger factory with an event source logger provider.

👍

What do you tell the customer to do see the logs? Use dotnet trace or perfview?

Any of those (+ dotnet-monitor), it's ok that it's inconvenient - it's the last resort to get some information out. We want people to configure logging properly.

Console logger might be an option too. Maybe the fact that it writes something (warn+) to console by default would make it even more obvious that logging is not configured properly.

@julealgon
Copy link

@lmolkova

Any non-ASP.NET Core apps where DI is not a common practice.

Why would DI not be a common practice? If it isn't, then you should push for it.

ILoggerFactory must be optional - it's ok to use a library without logging.

Make it mandatory and provide a NullLoggerFactory implementation.

If you want to fully decouple your library from logging concerns (and dependencies), create a separate package that people can opt into in "raw" scenarios. Example:

  • MyLibrary
  • MyLibrary.Logging
  • MyLibrary.Extensions.Hosting (includes both of the above + methods to register with DI seamlessly)

Then, on MyLibrary.Logging, you define logging decorator implementations using MEL. If a consumer wants to not have any logging, they use MyLibrary. If they want to use logging, but still don't want any DI or Hosting stuff, use MyLibrary.Logging and manually create the needed logging wrapper passing in a mandatory ILoggerFactory. If they want the seamless experience, they use DI+hosting and consume MyLibrary.Extensions.Hosting.

I still don't understand why you are trying to optimize for a bad default of having no DI though. Just ask people to use generic host which is what they should be doing anyways (IMHO).

We want people to configure logging properly.

...Maybe the fact that it writes something (warn+) to console by default would make it even more obvious that logging is not configured properly.

If logging is not configured and you want to make that obvious... make it mandatory, throwing if ILoggerFactory is not provided. Why make this so much more complicated than it needs to?

@noahfalk
Copy link
Member Author

noahfalk commented Aug 27, 2024

@noahfalk
It requires us to take a dependency on M.E.L.EventSource, copy and paste its code or write our own custom EventSource.

I'm comparing these two scenarios in my head when the library user doesn't provide ILogger (whether by choice, by accident, or because the library's author didn't provide an API to allow it)

1. Library creates and uses its own default LoggerFactory (lib authors could do this today)

static class MyLibrary
{
    internal static LoggerFactory DefaultLoggerFactory = LoggerFactory.Create(builder =>
    {
        builder.AddEventSourceLogger();
    });
}
            
public class SomeLibraryType
{
    ILogger _logger;
    public SomeLibraryType() 
    {
        _logger = MyLibrary.DefaultLoggerFactory.CreateLogger<SomeLibraryType>();
    }
}

2. M.E.L.A provides a static factory (in some future version of .NET)

M.E.L.A:

static class Logging
{
    public static ILoggerFactory DefaultLoggerFactory = LoggerFactory.Create(builder =>
    {
        builder.AddEventSourceLogger(); // this could be configured other ways too, ignoring that
                                        // aspect for now
    });
}

Library code:

public class SomeLibraryType
{
    ILogger _logger;
    public SomeLibraryType() 
    {
        _logger = Logging.DefaultLoggerFactory .CreateLogger<SomeLibraryType>();
    }
}

I'm curious to hear what you think of the pros/cons? This is what I thought about:

  • In both cases the app has a dependency on M.E.L.EventSource. In the first case the dependency is direct vs. in the 2nd it is indirect. There are also potential dependencies on M.E.L or refactoring that moves LoggerFactory implementation down into M.E.L.A. Adding more code or dependencies to M.E.L.A would mean .NET apps gain those dependencies regardless of whether they use the static factory.
  • If a M.E.L.A API was available I'd expect marginally less discrepancy in how library authors handled this default. Overall I can only recall hearing feedback around this from three total library owners so if we provided something it wasn't clear it would be used in many libraries aside from Azure SDK.
  • Testability would be poor on both approaches. My assumption is that if the library author cared about testing the logging they would provide some alternate code path that allows the factory to be injected and then unit test that entrypoint instead.
  • In both cases the LoggerFactory could be public for the user to adjust the configuration though not clear to me if that would be desirable. Presumably we are using this fallback because the user didn't want to configure and provide a factory (or the library author didn't want to allow it).

@lmolkova
Copy link

lmolkova commented Aug 27, 2024

@noahfalk what I'd like to have

class MyClient
{
    private readonly ILogger<MyClient> _logger;
    public MyClient(MyOptions options) {
       _logger = options.LoggerFactory.CreateLogger<MyClient>()
    }

    public DoSomething() {
       ...
       _logger.LogInfo("Did something!")
    }
}

class MyOptions {
   public ILoggerFactory LoggerFactory { get; set; } = CreateDefault();

   private static ILoggerFactory CreateDefault() {
      // Option 1 - you decide
      return LoggerFactory.CreateDefault();

      // Option 2 - we decide
      return LoggerFactory.Create(b => b.AddEventSourceLogger());
   }
}

We want users to pass configured ILoggerFactory and we want to support only the explicit one - there is no need in global static singleton, no need to let users configure/set it.

The sole purpose of this is to have some way of getting logs out (without code change) if users forgot to configure logging/did it incorrectly/don't use DI/don't know how to use DI, etc. That's the fallback - not the way to configure things.

[Update] You do Option 1 now and provide NullLoggerFactory as a fallback, but that's noop - we need something operational, not necessarily convenient

@tmds
Copy link
Member

tmds commented Aug 28, 2024

I don't have a strong opinion whether something should be added or not.

If something gets added, I think it would make sense for it to be a static ILoggerFactory in the Microsoft.Extensions.Logging.Abstractions package that you can set and get.

Something like:

static class FallbackLogger
{
    static void SetInstance(ILoggerFactory); // Could throw InvalidOperationException if already set.
    static ILoggerFactory Instance { get; }  // Returns NullLogger.Instance when not set.
}

A library developer could then:

public MyClient(ILoggerFactory? factory = null) => _factory = factory ?? FallbackLogger.Instance;

An application developer can initialize the fall back logger in their Main method:

using ILoggerFactory loggerFactory = LoggerFactory.Create(builder => builder.AddConsole());
FallbackLogger.SetInstance(loggerFactory);
...

I think the using (that is: ILoggerFactory.Dispose()) is needed to flush the logging.

Though this doesn't initialize a default ILoggerFactory (which is opinionated), it enables an application developer do to it in a way that affects all code that is using FallbackLogger.Instance.

@julealgon
Copy link

@noahfalk what I'd like to have

class MyClient
{
    private readonly ILogger<MyClient> _logger;
    public MyClient(MyOptions options) {
       _logger = options.LoggerFactory.CreateLogger<MyClient>()
    }

    public DoSomething() {
       ...
       _logger.LogInfo("Did something!")
    }
}

class MyOptions {
   public ILoggerFactory LoggerFactory { get; set; } = CreateDefault();

   private static ILoggerFactory CreateDefault() {
      // Option 1 - you decide
      return LoggerFactory.CreateDefault();

      // Option 2 - we decide
      return LoggerFactory.Create(b => b.AddEventSourceLogger());
   }
}

@lmolkova passing service dependencies through an options model seems like such an anti-pattern to me... I'd honestly hate to interact with a library that took dependencies this way. Options are meant for configuration values, not for service injection.

Once again, to me, you are just making things more complicated than they need to be by doing things like this.

@noahfalk
Copy link
Member Author

private static ILoggerFactory CreateDefault() {
      // Option 1 - you decide
      return LoggerFactory.CreateDefault();

      // Option 2 - we decide
      return LoggerFactory.Create(b => b.AddEventSourceLogger());
   }

Cool that refines the 'what' part a bit. Where I am still struggling is the 'why?' The pros/cons for this seem close to the example I gave above and so far I don't see a compelling reason to build option (1) as a new thing when option (2) already exists. You mentioned standardization and that this would apply to many libraries, but given the (lack of) feedback I've seen from other library authors I don't have an expectation many library authors would create these fallback paths even if the API existed. I'd also guess that the library authors interested in that API would be content to write option (2) instead if we recommended it and they knew it would have the same outcome.

@lmolkova
Copy link

lmolkova commented Aug 28, 2024

@noahfalk that's fair.
The reason I suggested it is that without some fallback (or a way to change default) logging is not complete.

E.g. in Java you configure logging by providing logging implementation and configuring it with env vars/files. You can provide logging implementation without changing the code (by adding javaagent option). It provides much more than a fallback. E.g. you can drop otel javaagent into user's app (Az Function, AppService, k8s container), update config and now you get fully blown otel including logs. Python has a similar story.

In .NET we can get this amazing experience for tracing and metrics, but not for logs. For logs we can get nothing at all if users didn't do the DI stuff in a certain way.

So this is why the logging feels incomplete and not on par with the experience our users can get in other languages. The fallback could address some of it in the most basic way.

I take the point that Azure SDKs probably care the most about it (and the only ones that would even consider EventSourceProvder 😅 )

@noahfalk
Copy link
Member Author

Thanks @lmolkova!

The reason I suggested it is that without some fallback (or a way to change default) logging is not complete

I'll gladly admit the lack of symmetry between the logging API and the other telemetry signal APIs bugs the part of my brain that likes everything orderly. If I wanted to appease that part of my brain I'd probably have an API like this:

ILogger logger   = loggerFactory.Create<Foo>(...);
ILogger logger   = new Logger<Foo>();                 // this one is missing
Meter m          = meterFactory.Create(...);
Meter m          = new Meter(...);
ActivitySource a = activitySourceFactory.Create(...); // this one is missing
ActivitySource a = new ActivitySource(...);

But a few things hold me back from acting on that impulse for logger:

  • the existence of 'good enough' workarounds
  • relatively few complaints from .NET library developers
  • the concern that making it easier to use the API outside of the standard DI pattern will create confusion or lead .NET developers to make bad API design choices. I don't want to speak for them but both @davidfowl and @julealgon comments appear aligned with this. I share the concern somewhat, but probably I don't weight this factor as strongly as others do.

For logs we can get nothing at all if users didn't do the DI stuff in a certain way.

I think of this as two separate pitfalls that lead to a similar outcome:

  1. As the app developer configuring logging, I could not add the EventSourceLogger or clear it if it was there before and I've just disabled all out-of-proc logging capture. I'm guessing a substantial portion of the time this happens the dev was unaware of the impact.
  2. As a library developer with an API that doesn't force the user to provide an ILogger I could omit having a fallback that logs to the EventSourceLogger.

For (2) I land back where I was above... I don't think where we are is ideal but there are decent workarounds + the lack of feedback saying this is a significant problem discourages me from investing in changes. If that changed, either broader feedback or finding the existing workarounds were more problematic, then I'd have more motivation to explore changes.

@davidfowl
Copy link
Member

davidfowl commented Aug 31, 2024

I'm against a shared mutable static global configuration API for ILogger (I don't like the ones we have for meter and activities either). I'm less concerned about a default logger factory implementation that has the event source logger. We can just recommend that library authors provide a fallback that uses the event source logger (I understand the event source is shared mutable global state).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

9 participants