dotnet / diagnostics

This repository contains the source code for various .NET Core runtime diagnostic tools and documents.
MIT License
1.19k stars 354 forks source link

ILogger guidance #1605

Closed noahfalk closed 2 years ago

noahfalk commented 4 years ago

We've long had confusing guidance (or absent guidance) about where to use ILogger and where to use EventSource. Even within the .NET organization informed opinions vary about where each option is best suited and if it is reasonable to offer simple guidance that tells .NET developers to just use one and ignore the other. This issue is an attempt to bring that discussion together in one recorded place rather than the various emails, meetings, and ad-hoc conversations where it often pops up.

An ideal outcome would be that we have documented guidance on docs.microsoft.com that not only describes how to use a particular logging technology, but also gives clear advice about which logging technology the .NET team recommends to use. The advice should be clear, concise, and handle most (not necessarily all) situations.

The best documented history on this issue I am aware of: https://github.com/aspnet/Logging/issues/332 (from 2016)

As a strawman I'll propose the guidance is "Reference the most recent version of Microsoft.Extensions.Logging and log with the ILogger interface." At minimum this is lacking in detail which needs to be fleshed out, but possibly we'll find there are some more substantive problems that need to be addressed. This issue is an opportunity to poke at this strawman in hopes of either shoring it up or changing it to something that works better before we document it.

This is an initial set of concerns I want to get addressed either via my own research or feedback from others:

  1. When some code wants to log, where does the instance of ILogger come from? For libraries that were designed with ILogger and dependency injection in mind from the start there is an established pattern of putting an ILogger typed parameter in the constructor. However if you had a pre-existing library that doesn't have such constructors are you intended to add them? This would also require the ILogger instance to be passed as an argument through every method that eventually calls one of those constructors. This appears extremely invasive on API design. Using a static storage location and some static or singleton entrypoint to initialize it might be a reasonable way forward?
  2. What code component is in charge of creating ILogger instances from the ILoggerFactory? In the DI scenario the DI container does this task, but without a DI container whose job is it?
  3. Are there any cases we are aware of where it is unreasonable to take the assembly dependency on M.E.L? For example M.E.L has had some breaking changes in the past, is this likely to lead apps to encounter unresolvable versioning conflicts at build time or runtime? There are some low-level framework libraries that can't reference M.E.L. for layering reasons, but these can probably be ignored because it isn't a restriction typical .Net developers would encounter.
  4. EventSource supports a scenario where out-of-process tools can retrieve logs from an instrumented library even if the app author who included the library made zero effort to configure logging or didn't configure logging for specific libraries. Is a similar capability possible from ILogger or do we think the value of this scenario is low enough that we can ignore its absence?
  5. I've heard people say they think EventSource isn't suitable for logs primarily intended for human consumption whereas ILogger isn't suitable for profiling style events intended for automated consumption. Are there technical reasons to make such a distinction? Would doing both of these tasks with ILogger lead to confusion or a worse experience?
  6. EventSource has features that support activity tracking, keywords, tasks, opcodes, tags, ETW/EventPipe/Lttng integration, and dynamic discovery/subscription. Does ILogger provide the same capabilities (for example via the EventSourceLoggerProvider bridge), or suitable alternatives, or we think the features are suitably corner case that they can be ignored in most cases?
  7. We tied EventCounters to EventSource, does it look weird to tell people to create EventSources for counters at the same time we are recommending them to ignore EventSource for logging? New metric APIs that don't have direct coupling on EventSource might alleviate this?

More opinions, concerns, questions, and feedback are all encouraged. Thanks!

cc @shirhatti @brianrob @maryamariyan @tarekgh @dotnet/dotnet-diag @davidfowl @reyang @cijothomas

noahfalk commented 4 years ago

@pakrym @KrzysztofCwalina - I think you guys now have some experience using both EventSource and ILogger in Azure SDK. You probably have good feedback on things that have worked well or poorly?

cijothomas commented 4 years ago

When some code wants to log, where does the instance of ILogger come from?

I remember discussing this in Activity/ActivitySource discussions. Today, one must obtain the ILogger from the exact same instance of LoggerFactory to which providers are registered. This puts the burden on developers to pass around the LoggerFactory to every place where there is a need to obtain ILogger. (For Asp.Net Core apps, DI can be used, but for other app models, the burden is on the developer to pass around the LoggerFactory, and ask every classes to call LoggerFactory.CreateLogger() on this particular instance)

Do we have an opportunity to make obtaining ILogger instance similar to creating ActivitySource? i.e allow people to simply create ILogger instance out of thin air, just like ActivitySource (new ActivitySource(name,ver)) The logging providers could be provided with a way to subscribe to any ILogger instances based on their name, just like ActivityListener model?

davidfowl commented 4 years ago

I think we'd need to reconcile with the DI model, there can't be more than a single source of truth. The real issue ends up being what guidance would exist for libraries that want to exist in both worlds. Also when libraries start to do this it starts to be a challenge for multitenancy scenarios that care about having different loggerfactory instances.

noahfalk commented 4 years ago

there can't be more than a single source of truth

I'm not sure what aspect you are trying to ensure converges. The guidance, the coding patterns, the instances of ILogger or ILoggerFactory in the process?

starts to be a challenge for multitenancy scenarios that care about having different loggerfactory instances

Do you have any good examples of multi-tenancy in practice? Every code sample I see (aside from tests) winds up being a singleton DI container with a singleton LoggerFactory inside of it.

davidfowl commented 4 years ago

I'm not sure what aspect you are trying to ensure converges. The guidance, the coding patterns, the instances of ILogger or ILoggerFactory in the process?

Getting the ILogger instantce from the "correct" ILoggerFactory.

Do you have any good examples of multi-tenancy in practice? Every code sample I see (aside from tests) winds up being a singleton DI container with a singleton LoggerFactory inside of it.

The beautify of the design is the DI container is the root of isolation. You have a container per tenant usually and a singleton ILoggerFactory in that DI container. Makes it trivial for components to be resolved in that context and get the right ILogger instance from the right ILoggerFactory (it also makes testing easy).

pakrym commented 4 years ago

I think you guys now have some experience using both EventSource and ILogger in Azure SDK. You probably have good feedback on things that have worked well or poorly?

  1. No built-in easy ways to listen to events.

There is no console logger listener, not file listener etc. Every guide about how to get logs would have to start with installing some tool or implementing a custom listener.

That's why we ship AzureEventSourceListener.

  1. No built-in integration with ILogger

There is no good story about forwarding events from ES to ILogger. We ship our own forwarder for Azure SDK event logs but customers need to know to initialize it.

  1. Lack of docs on how to consume event sources easily.

Everything seems to be scary or complicated.

  1. Inability to subscribe to a few related event sources.

We have 1 core eventsource where most events are produced from and a few library-specific event sources.

ILogger allows you to control events using patterns but in EventSource world, you have to know the name or Guid of every one of them. We use traits to group Azure SDK sources and allow mass subscriptions but it works only in-process.

noahfalk commented 4 years ago

@pakrym thanks for the notes! If the guidance had said "Use ILogger for all your logging and ignore EventSource" would that have made you happy or you would have a different set of concerns? (I'm guessing the latter but trying not to bias the answer : )

I found some logging guidance that tells people how to use AzureEventSourceListener to get console or Trace logging. I didn't find anything that tells them how to integrate with ILogger. Not sure if I missed it or you currently don't intend for them to do that? Have you gotten feedback from your users on whether they like this current logging story with the AzureEventSourceListener?

I did find EventSourceLogForwarder but I didn't see where the user is able to configure the the ILoggerFactory that they would pass in.

pakrym commented 4 years ago

If the guidance had said "Use ILogger for all your logging and ignore EventSource" would that have made you happy or you would have a different set of concerns? (I'm guessing the latter but trying not to bias the answer : )

Very hard to tell. I suspect we would have different concerns.

I found some logging guidance that tells people how to use AzureEventSourceListener to get console or Trace logging. I didn't find anything that tells them how to integrate with ILogger. Not sure if I missed it or you currently don't intend for them to do that? Have you gotten feedback from your users on whether they like this current logging story with the AzureEventSourceListener?

You get if for free when you use the integration package https://github.com/Azure/azure-sdk-for-net/blob/master/sdk/extensions/Microsoft.Extensions.Azure/README.md we need to make sure this information is more prominent and add a way to create the forwarder explicitly.

noahfalk commented 4 years ago

Aha, yeah I missed that integration library completely, thanks for the link!

noahfalk commented 2 years ago

We've been giving internal guidance for teams adopting OTel to use ILogger for a good while now and we've received very little pushback, so I've gone ahead and updated the public guidance to recommend ILogger as a good default choice. I know there are likely to be some people who disagree or who want more caveats documented. I'm glad to take the feedback and re-evaluate if it causes more trouble than anticipated.

In terms of some of answering some of the questions above, this is my current thoughts:

When some code wants to log, where does the instance of ILogger come from?

In order of preference:

  1. Libraries designed to use DI should take ILogger in their constructor
  2. Libraries not designed to use DI but where the author is willing to expose ILogger as a constructor or method parameter should pass it as a parameter. Use ILoggerFactory if the code will need to create multiple loggers.
  3. For libraries retrofitting ILogger where it would be problematic or high churn to modify the existing APIs, add a standalone static method that allows library consumers to pass in an ILoggerFactory. See https://github.com/dotnet/runtime/issues/50777 for more details.

Are there any cases we are aware of where it is unreasonable to take the assembly dependency on M.E.L?

The versions of M.E.L with breaking changes are no longer supported. There are some low level libraries in the runtime that can't take the dependency because it would create cycles, but that isn't a concern for any typical library. For libraries that want to be very stingy about their dependencies they may choose to stick with EventSource, but for practical purposes I'd expect nearly any .NET Core app to have M.E.L in its dependency closure.

EventSource supports a scenario where out-of-process tools can retrieve logs from an instrumented library even if the app author who included the library made zero effort to configure logging or didn't configure logging for specific libraries. Is a similar capability possible from ILogger or do we think the value of this scenario is low enough that we can ignore its absence?

The EventSourceLoggerProvider is enabled by default in GenericHost and WebApplication so most apps will default to have this capability. If the app developer explicitly turns it off then we should assume they don't want this capability by design. Apps could use isolated LoggerFactory and omit the EventSource option unintentionally, but if it is functionality they want to use then they'll probably find the oversight before too long and adjust.

I've heard people say they think EventSource isn't suitable for logs primarily intended for human consumption whereas ILogger isn't suitable for profiling style events intended for automated consumption. Are there technical reasons to make such a distinction? Would doing both of these tasks with ILogger lead to confusion or a worse experience?

I don't think the distinction adds value and I am not aware of why doing both with ILogger would be problematic (some caveats in the next question)

EventSource has features that support activity tracking, keywords, tasks, opcodes, tags, ETW/EventPipe/Lttng integration, and dynamic discovery/subscription. Does ILogger provide the same capabilities (for example via the EventSourceLoggerProvider bridge), or suitable alternatives, or we think the features are suitably corner case that they can be ignored in most cases?

ILogger's connection to EventSource/ETW/EventPipe does get enveloped which could make it harder to parse, but this could be improved by changing the EventSourceLoggerProvider in the future. I did put a mention in the public guidance that if you want tight control over how events appear when emitted into ETW/EventPipe that could be a reason to prefer using EventSource directly.

We tied EventCounters to EventSource, does it look weird to tell people to create EventSources for counters at the same time we are recommending them to ignore EventSource for logging? New metric APIs that don't have direct coupling on EventSource might alleviate this?

We are pivoting the recommendation to use the new Metric APIs so this concern is diminishing over time and probably wasn't a big deal regardless.