MicrosoftDocs / azure-docs

Open source documentation of Microsoft Azure
https://docs.microsoft.com/azure
Creative Commons Attribution 4.0 International
10.31k stars 21.49k forks source link

Discrepancy between host.json log filters and dotnet log filters should be documented #72168

Open allanlw opened 3 years ago

allanlw commented 3 years ago

Having failed to understand this and spent a while figuring it out, I would like to save someone else the pain.

E.g. Attempting to get logs at trace level, setting a log filter in host.json does not work:

{
    "version": "2.0",

    "logging": {
        "logLevel": {
            "default": "Trace"
        },
        "applicationInsights": {
            "samplingSettings": {
                "isEnabled": false
            }
        }
    }
}

Instead you must do:

            var host = new HostBuilder()
                .ConfigureFunctionsWorkerDefaults()
                .ConfigureLogging(logging =>
                {
                    logging.AddFilter("System.Net.Http", LogLevel.Trace);
                })
                .ConfigureServices(s =>
                {
                    s.AddHttpClient();
                    // etc
                })
                .Build();

Same with the "default": "Trace" key and logging.SetMinimumLevel(LogLevel.Trace), although the latter causes my function to not start correctly and time out, the first one does not enable trace level logging globally.

This should be documented in the "Logging" section.


Document Details

Do not edit this section. It is required for docs.microsoft.com ➟ GitHub issue linking.

ChaitanyaNaykodi-MSFT commented 3 years ago

Hello @allanlw, Thank you for your feedback! We will review and update as appropriate.

felinepc commented 3 years ago

@allanlw Just want to say THANK YOU. I was going nuts trying to stop the ocean of Microsoft logs in my function (I use EF Core, so every query command etc...), and just couldn't get it to work via either host.json or local.settings.json ("logging:loglevel:..." etc). Magically I clicked the link at the very bottom of the doc to get to this page. Yes you absolutely saved lots of pain :).

I sincerely hope .NET 5 Azure Function will get some first-class treatment (Visual Studio integration etc) and updated docs from Microsoft soon.

ggailey777 commented 3 years ago

Thanks @allanlw for reporting this.

@brettsam do we not still support host.json settings to control logging in .NET isolated, or is there a bug somewhere?

felinepc commented 3 years ago

@ggailey777 @brettsam Thanks for looking into this. While you're at it, I just want to let you know that IConfiguration DI via local.settings.json also seems to be broken, which means the Options pattern described in this doc does not work. See this.

kinetiq commented 3 years ago

@ggailey777 @brettsam @felinepc Can confirm this problem re: IConfiguration. This is currently a show stopper for my efforts to port to Core 5. Is there a workaround? I have code that needs to work in both MVC and Azure Functions.

felinepc commented 3 years ago

@kinetiq I had to make a few duplicate service configuration code files and use Environment.GetEnvironmentVariable just for the Azure Function project.

I also configured some options directly via services.AddOptions<TOptions>().Configure(options =>{...}).

Thankfully my project is still small. I can see this being a problem for larger projects that already make heavy use of the IOptions pattern.

kinetiq commented 3 years ago

@felinepc Thanks for getting back to me on that. I'm only having this issue in one place... Fortunately. I can see this being a real problem for people.

I think what I'm going to do is try and add calls to Environment.GetEnvironmentVariable in the event that IConfiguration can't find a value. I have to make sure this works in both MVC and Azure Functions, which is tricky, although in the previous version of AF this was working fine.

If you have something cleaner please let me know!

ggailey777 commented 3 years ago

I just chatted with @brettsam and there are 2 points that need to be clarified in the docs:

felinepc commented 3 years ago

@ggailey777 DI itself registered via .ConfigureServices in out-of-process Azure Functions does work. The problem is specific to IConfiguration and config/options binding.

To put it more clearly, in traditional ASP.NET Core we have appsettings.Environment.json files in which we can enter configuration variables, and access them via either IConfiguration or IOptions (if binding is configured).

Where do these configurations should go now with out-of-process Azure Functions?

With improved DI support in Azure Functions, and the fact that Microsoft specifically stated out-of-process hosting has the benefits of allowing us to use the standard .NET 5 libraries without being restricted to function runtime, a natural use scenario for Azure Functions is to have it share the existing libraries (such as for data access etc) with other ASP.NET Core projects, as @kinetiq pointed out as being his core requirement.

Because these standard codes likely make heavy use of the Options pattern, I hope Azure Functions with .NET5 will provide native support for it.

P.S. I recommend to have all the updated docs related to out-of-process Azure Functions with .NET 5 added or referenced in this .NET 5 Azure Functions guide, which is to date the most specific official doc related to this product.

kinetiq commented 3 years ago

Yes, to be extremely specific: in the previous version of Azure Functions, if I injected IConfiguration, it would automatically pick up values in local.settings.json... Only the Values array was loaded. In Production, it looks like it would also pick up environment variables instead.

That could be useful in cases where code needed to be shared between MVC and Functions... It was possible to drop the value in local.settings.json and appsettings.Environment.json and IConfiguration would work for both.

However, I can see that this behavior is at odds with MVC configuration, where you have to manually tell it to use appsettings.json. Seems like it might be best long term to bring all this into parity. Of course, backwards compatibility problems abound...

felinepc commented 3 years ago

@kinetiq Hey looks like I just missed mhoger's reply here. Adding

.ConfigureAppConfiguration(c =>
{
    c.AddEnvironmentVariables();
})

to HostBuilder in Program.cs made IConfiguration pick up values in local.settings.json again (still have to be under Values section).

It's also working for the Options pattern as described in the old DI doc. The configurations to be bound to need to be placed under the Values section in local.settings.json, in the format of "OptionClass:Property" : "PropertyValue"

They stated that they'll add this by default in the next release.

Sorry I think I may have driven this particular issue a bit off-topic, which is related to logging configuration.

kinetiq commented 3 years ago

@felinepc I did miss it at first, thanks! Works great!

felinepc commented 3 years ago

@allanlw @ggailey777 @brettsam After getting the DI issue sorted out, I conducted extensive testing on the logging configuration. Here's what I found (its current behavior is very quirky):

  1. The "default": log level actually can ONLY be set in host.json. Configuring it via .AddFilter has no effect. Furthermore, when it is set to Information or above in host.json, it applies globally AND overrides all other more verbose log level configurations such as Trace.

For example: If default is set to Information, then logging.AddFilter("System.Net.Http", LogLevel.Trace) will have no effect. Similarly, if default is set to Warning, then all other Information level logs will be suppressed.

  1. If default is set to Trace in host.json, it enables trace level logging ONLY for the Azure Function host related logs (trigger, operation etc). It does not apply globally, so other unconfigured logs will NOT show trace.

However, since Trace is already the most verbose, other log configurations set to Trace, such as the logging.AddFilter("System.Net.Http", LogLevel.Trace) configuration above, will work.

  1. All other non default log configurations such as Microsoft etc are completely ignored in host.json, regardless if .AddJsonFile is used. These configurations can only be set via .ConfigureLogging as posted by @allanlw. Again they will only work if they're no more verbose than the default set in host.json, which defaults to Information if unset.

Hopefully this helps. @allanlw let me know if these findings match yours.

allanlw commented 3 years ago

What @ggailey777 says matches my understanding of the issue. I don't really care where I configure log filters (json or in the code) but the documentation right now is IMO confusing if not outright wrong.

felinepc commented 3 years ago

@allanlw What I meant was, from what I observed in my test, this section in your host.json:

"logging": {
        "logLevel": {
            "default": "Trace"
        }

actually did have effects, though it by itself wouldn't enable your other trace logs.

If you don't mind doing a test, change the default level above to Information or Warning, or remove this section completely from your host.json, you should see the logging.AddFilter("System.Net.Http", LogLevel.Trace) configuration in your .ConfigureLogging method stop working.

The behavior of this default filter configuration and its "maximum verbosity" effects on the rest of the filters was described in my previous post.

Furthermore, loading host.json as json configuration provider seems to have no effect, as suggest by @ggailey777, as the non-default log filters appear to only work if configured via ConfigureLogging.