Azure / azure-functions-dotnet-worker

Azure Functions out-of-process .NET language worker
MIT License
429 stars 183 forks source link

How to get AppInsights working in .NET 8 Functions v4 #1182

Open LockTar opened 1 year ago

LockTar commented 1 year ago

Hi,

Sorry for the new issue but I think this will bring a lot of open issues together to a final solution in a sample repository. Hopefully we can make something default/officially/easier for new people because it took me a long time to figure everything out.

I want to thank @brettsam, @jviau and @kshyju for posting helpful comments that let me finally see some logging in Azure Application Insights lower than Warning (so Trace, Debug, Information).

See the sample repository for more details to get it running. See the details of the Func.Isolated.Net7.With.AI project.

Screenshots from Azure: image image

SeanFeldman commented 1 year ago

@LockTar, is that repo public?

LockTar commented 1 year ago

@LockTar, is that repo public?

Oeps! Forgot to change that. It's public now

LockTar commented 1 year ago

@SeanFeldman Basically it results in the following:

  1. Add the 2 new lines of the preview package
  2. Remove the warning and above logger
  3. Use appsettings.json as configuration file
  4. Configure logging from appsettings.json
  5. Optional setup DI for testing injected classes with ILogger<T>

Program.cs

using Microsoft.Extensions.Hosting;
using Microsoft.Azure.Functions.Worker;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using Func.Isolated.Net7.With.AI;

var host = new HostBuilder()
    .ConfigureFunctionsWorkerDefaults(builder =>
    {
        // Is added by package "Microsoft.Azure.Functions.Worker.ApplicationInsights".
        // Documented here because it is still preview: https://github.com/Azure/azure-functions-dotnet-worker/pull/944#issue-1282987627
        builder
            .AddApplicationInsights()
            .AddApplicationInsightsLogger();        
    })
    .ConfigureServices((ctx, serviceProvider) =>
    {
        // You will need extra configuration because above will only log per default Warning (default AI configuration) and above because of following line:
        // https://github.com/microsoft/ApplicationInsights-dotnet/blob/main/NETCORE/src/Shared/Extensions/ApplicationInsightsExtensions.cs#L427
        // This is documented here:
        // https://github.com/microsoft/ApplicationInsights-dotnet/issues/2610#issuecomment-1316672650
        // So remove the default logger rule (warning and above). This will result that the default will be Information.
        serviceProvider.Configure<LoggerFilterOptions>(options =>
        {
            var toRemove = options.Rules.FirstOrDefault(rule => rule.ProviderName
                == "Microsoft.Extensions.Logging.ApplicationInsights.ApplicationInsightsLoggerProvider");

            if (toRemove is not null)
            {
                options.Rules.Remove(toRemove);
            }
        });

        // Setup DI
        serviceProvider.AddTransient<IUserDataService, UserDataService>();
    })
    .ConfigureAppConfiguration((hostContext, config) =>
    {
        // Add appsettings.json configuration so we can set logging in configuration.
        // Add in example a file called appsettings.json to the root and set the properties to:
        // Build Action: Content
        // Copy to Output Directory: Copy if newer
        //
        // Content:
        // {
        //   "Logging": {
        //     "LogLevel": {
        //       "Default": "Error" // Change this to ie Trace for more logging
        //     }
        //   }
        // }
        config.AddJsonFile("appsettings.json", optional: true);
    })
    .ConfigureLogging((hostingContext, logging) =>
    {
        // Make sure the configuration of the appsettings.json file is picked up.
        logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging"));
    })
    .Build();

host.Run();

Add appsettings.json file with settings Build Action: Content and Copy to Output Directory: Copy if newer:

{
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Func.Isolated.Net7.With.AI.MyOtherFunctions": "Error",
      "Func.Isolated.Net7.With.AI.MyUserFunctions": "Debug",
      "Func.Isolated.Net7.With.AI.UserDataService": "Trace"
    }
  }
}
jviau commented 1 year ago

@LockTar thank you for summarizing all of this for others to reference. Glad you were able to get it working. Was the logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging")); call what we were ultimately missing in the previous discussions? If so, I wonder if the Logging:ApplicationInsights:LogLevel:Default = Information would actually work with that? This would replace the need for the Configure<LoggerFilterOptions> hack.

Anyways - is there any action items you want from our side as an outcome of this issue? Keep in mind we do already have intentions to address telemetry in Functions (ideally go with OpenTelemetry).

LockTar commented 1 year ago

Was the logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging")); call what we were ultimately missing in the previous discussions? If so, I wonder if the Logging:ApplicationInsights:LogLevel:Default = Information would actually work with that? This would replace the need for the Configure<LoggerFilterOptions> hack.

Just tested it for you. If I don't set the delete logger filter rule from you and change appsettings.json to:

{
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Func.Isolated.Net7.With.AI.MyOtherFunctions": "Error",
      "Func.Isolated.Net7.With.AI.MyUserFunctions": "Debug",
      "Func.Isolated.Net7.With.AI.UserDataService": "Trace"
    },
    "ApplicationInsights": {
      "LogLevel": {
        "Default": "Debug"
      }
    }
  }
}

Then I would see Debug messages as well. So, this would change the default warning rule.

BUT If I change it to Logging:ApplicationInsights:LogLevel:Default = Error, then I of course only see Error messages but I'm losing in example the Logging:LogLevel:Func.Isolated.Net7.With.AI.UserDataService = Trace messages.

That's not what you want... Maybe you have fix for that as well but that is exactly the thing that everyone is saying. It is to unclear how everything is working for Azure (Isolated) Functions.

LockTar commented 1 year ago

Anyways - is there any action items you want from our side as an outcome of this issue? Keep in mind we do already have intentions to address telemetry in Functions (ideally go with OpenTelemetry).

Yes.

  1. My console logging (localhost debugging) is missing completely. How can this be fixed... Is this related with #1090?
  2. I/We want an official sample application or new VS2022 default project template with clear documentation on how to set logging. Now we have 3 places to set logging and it's unclear how everything is working. We have host.json, appsettings:Logging:LogLevel and appsettings:Logging:ApplicationInsights:LogLevel. Everything is based on assumptions.

I don't know if OpenTelemetry is going to fix everything but I guess this will not be finished tomorrow. We create new Azure Functions on almost daily level. We need to have clear logging (documentation) from the start.

jviau commented 1 year ago

For the log filters: Logging:ApplicationInsights:LogLevel:Default = Error and Logging:LogLevel:Func.Isolated.Net7.With.AI.UserDataService = Trace only showing Error in App Insights is behaving as expected. The first one is a provider specific filter, which takes precedence over the second filter you have. This reminds me why I have that filter removal 'hack' in my code and not the config approach. It is the same situation as you: I wanted to control log filters through the non-provider configuration (Logging:LogLevel:*). App insights package always adding that Warning filter gets in the way, so I removed it. The hack isn't the best, but also not the worst. We will not be porting that into our app insights package as we do not want to conflict with what the AppInsights package has decided to do. We will leave the decision to include that filter customization to the end user.

For the console logging missing completely in local debugging, something I was missing this entire time was that stdout for the worker is piped to the host, which is not always forwarding them to the terminal you are running in. @fabiocav / @brettsam what is the recommended way to get console logs from worker in local debugging?

And we do intend for the OpenTelemetry work to address all of these concerns. You will have much more control over the logs. However, something that won't change is the multiple places to configure logging. Ultimately, you have two processes running - the host and the worker and they have their own respective logging configuration. We will always have to expose the ability to configure them separately (host.json for the host config, then you are ultimately in control of the setting file(s) for the worker). As for the multiple "LogLevel" sections to configure, that is also out of our control. This is how Microsoft.Extensions.Logging works - we do not own that API or its configuration.

To summarize, sounds like we just need to help you with the worker --> host stdout pipe causing issues with console logging.

LockTar commented 1 year ago

App insights package always adding that Warning filter gets in the way, so I removed it. The hack isn't the best, but also not the worst. We will not be porting that into our app insights package as we do not want to conflict with what the AppInsights package has decided to do. We will leave the decision to include that filter customization to the end user.

I understand that you don't want to make conflicts with the AppInsights packages. Otherwise, you will get mixed results in MS Azure services. But removing the Warning filter could be added to the project template in VS20xx. Maybe not enabled but in comment. Maybe with a link to the docs (that I can't find anywhere for Azure Functions...). (See below bullet 2)

And we do intend for the OpenTelemetry work to address all of these concerns. You will have much more control over the logs. However, something that won't change is the multiple places to configure logging. Ultimately, you have two processes running - the host and the worker and they have their own respective logging configuration. We will always have to expose the ability to configure them separately (host.json for the host config, then you are ultimately in control of the setting file(s) for the worker). As for the multiple "LogLevel" sections to configure, that is also out of our control. This is how Microsoft.Extensions.Logging works - we do not own that API or its configuration.

Thank you for the explanation. I understand that there are 2 types of places to configure.

To summarize, sounds like we just need to help you with the worker --> host stdout pipe causing issues with console logging.

  1. Well, yes. Console logging would be nice for local debugging.
  2. How can we make things clearer for people that create a new project. The appsettings.json and Program.cs as stated above aren't default. There is no clear documentation from an Azure Function Isolated perspective how to set this all up... It took me hours and I'm not the only one. It would be nice to have documentation about this and a changed project template.

Don't get me wrong (not attacking you or colleagues at all) but my employers want me to write (small) business solutions. Azure Functions are ideal for this. That's why I'm using Functions from the beginning. Logging should be more an addition for troubleshooting. It now takes me longer to figure out how logging works (it changes a lot) than I'm writing a complete API...

drew-fc commented 1 year ago

hi @LockTar ,

Thank you so much for putting this together. I have integrated your changes into my project, but the result I am getting is that nothing is printed at all to the terminal during debugging sessions. Previously, I was only getting Information and above to print. I have downloaded your entire repo and tried to get your project to work, but it fails on host.Run() when it starts. The error I get is

`Exception has occurred: CLR/System.InvalidOperationException An unhandled exception of type 'System.InvalidOperationException' occurred in System.Private.CoreLib.dll: 'The gRPC channel URI 'http://:7283' could not be parsed.'

Any ideas how to move forward? I am using Visual Studio Code if that matters, not Visual Studio, although I have VS if you think that's absolutely needed to move forward. thanks again

LockTar commented 1 year ago

@drew-fc

Thank you so much for putting this together.

Your welcome.

I have integrated your changes into my project, but the result I am getting is that nothing is printed at all to the terminal during debugging sessions. Previously, I was only getting Information and above to print.

I have exactly the same problem. See above comment 1 and comment 2 about this. I think this is related with #1090 but I want that answer from Microsoft because they understand this better than I do.

I have downloaded your entire repo and tried to get your project to work, but it fails on host.Run() when it starts.
Any ideas how to move forward? I am using Visual Studio Code if that matters, not Visual Studio, although I have VS if you think that's absolutely needed to move forward.

I never use Visual Studio Code with Azure Functions so I don't know if this is the issue. This is a normal new Azure Function template created with the latest version of Visual Studio 2022.

P.S. I think it's not a good idea to mix issues here. Could you please remove you stack trace from above because it's not really well formatted and has nothing to do with this issue. Thank you very much in advance.

drew-fc commented 1 year ago

@LockTar , thank you so much, I was able to get the console logs working with that fix of AddConsole().

SeanFeldman commented 1 year ago

Is there documentation by any chance to explain how the isolated worker functions work with logging, with some visualization? The sample @LockTar has put together is great, but I'd want to see this made into the official documentation. There are samples, and there are code snippets. There should be solid documentation to distill this down.

cc @fabiocav

SeanFeldman commented 1 year ago

I'm getting flooded with messages with the category Azure.Core at the Information log level despite configuring the default logging level to Error on both, host.json and appsettings.json. @LockTar, did you have to filter out that one?

LockTar commented 1 year ago

I'm getting flooded with messages with the category Azure.Core at the Information log level despite configuring the default logging level to Error on both, host.json and appsettings.json. @LockTar, did you have to filter out that one?

@SeanFeldman Is there a simple overview to see all the messages of a category? I see a lot of messages with category Host etc. (opened a few of them).

I think the default (is it with a capital or lower d?) level is doing something. I get mixed results. Can't really figure out what it is. We need Microsoft for this.

LockTar commented 1 year ago

@drew-fc please create new issues for this and remove your comments. This has nothing to do with Azure Functions and logging. This is C# DI. I think StackOverflow is a better place for this question.

LockTar commented 1 year ago

My personal opinion is to inject loggers in the constructor. Just like this. How to inject multiple classes is a DI related question. That's why I said that. But I really think you should create a seperate issue for this and delete your comments (and then I can delete my comments) because this is really something else. Tag me in the other issue so I can maybe assist you. Thanks

rellis-of-rhindleton commented 1 year ago

This is what I'm getting from reading through all these comments and doing some experimentation. Please correct me if I'm wrong. Happy to edit/change/delete this comment to avoid confusion.

(edited: host.json and overrides)

I'm just trying to understand what I'm dealing with. Having to jump back and forth between computers to write this so forgive me if I get a detail wrong.

LockTar commented 1 year ago

I think you are correct about everything. A lot is speculating so I'm not sure about everything. Hopefully Microsoft will bring some official documentation about this and a new project template. But there is not much response anymore about this...

Adding the ApplicationInsights logging packages causes problems with seeing log entries in local development.

This should solve it (not tested it myself).

stevelknievel76 commented 1 year ago

@LockTar This thread has been very useful and enabled me to get my log levels working. Thanks very much. I have 1 outstanding issue though which I don't understand. Apologies if I did something stupid, but would be grateful if you can shed some light on it. Here is an example Invocation Log:

image

Notice that the "Type" column is not populated for all messages other than the first (that message was generated by the TimerTrigger framework, and not by my code).

When I look in traces I see that the customDimensions has a different format for the first message from all others (and does not include LogLevel):

image

... versus ...

image

Do you see this too?

SeanFeldman commented 1 year ago

@SeanFeldman Is there a simple overview to see all the messages of a category? I see a lot of messages with category Host etc. (opened a few of them).

At this point, I'm not sure what's going on. Not only are the Azure SDKs at fault for logging multiple messages with the Information level, but also the number of categories (Azure.Core, Azure.Core.1, Azure.Messaging.ServiceBus, etc.). This is where a good, solid official sample is necessary, along with a proper documentation. Besides the noise in Application Insights, this will directly impact Azure bill clients will pay, and I'm concerned there's no good way to filter out the unnecessary logs.

@brettsam, @fabiocav, the issue with AppInsights and logging is becoming more of a pain with financial impact rather than just an inconvenience.

brandonh-msft commented 1 year ago

Even with all this, I'm not able to get Debug+ logs to console and AI in .NET 6 Isolated while debugging locally. :/

brettsam commented 1 year ago

Going to see if I can go through and comment on any remaining issues here.

First, from @rellis-of-rhindleton (https://github.com/Azure/azure-functions-dotnet-worker/issues/1182#issuecomment-1330817907):

  • Logging can be configured as needed in the function app, e.g. with ConfigureLogging or by the use of an appsettings file as in the above examples.

Correct. The goal is to make the isolated worker feel as much like a "normal .NET console app" as possible. That means all docs apply, all libraries work, etc. You have full control over DI just like you would in any console app. This applies to logging as well. This is, however, confusing, because the host also writes logs. We're trying to reconcile this -- but an ideal solution is likely to be on a longer time frame.

  • Log entries go out via the host. If the host has filters applied that won't pass log entries through, they get dropped, e.g. if host.json has minimum level of Information then you won't see any Debug entries come through no matter how the app itself is configured. (This might not apply with third party logging sinks e.g. via Serilog.)

This depends. There are some logs that go out via the host. With the new AppInsights packages, some logs are going directly from your isolated worker to App Insights. This is, indeed, confusing. We're trying to figure out the best way to manage this still (which is one reason these App Insights packages are still in preview). Ultimately, you're dealing with 2 processes -- host and worker. Historically, we've tried to make this easy and say "the host logs everything!". However, this has proven to be less than ideal as there's all kind of richness that you get when running App Insights in your isolated worker process (auto-DependencyTelemetry, ITelemetryProcessors, etc). .NET isn't the only language seeing this, either -- Java is doing something similar to .NET with logging to Application Insights directly from the worker process and other languages would like to.

  • Likewise, if the host is not listening for log entries, they will be dropped. (This could be what is happening prior to host.Run() but I'm just speculating.)

If you're referring to the setup of "not using the new preview Application Insights package", this is correct. The host has a filter that means it will only write logs that it receives if they are in the context of an invocation (this is via grpc; I think stdout follows different rules). So logs coming from background services, initialization, etc, do not get written as you'd expect. If you're using the new package, any logs should go to App Insights just as if it were any "normal console app".

  • Logging configuration for the host (host.json) does not appear to follow the same rules you would expect in e.g. ASP.NET. In particular, category names for logging from functions are not class names; instead they are "Function.FunctionName" for entries generated by the host/framework, and "Function.FunctionName.User" for entries generated directly from code (logger.LogInformation). This is not obvious as category names are not shown in local development.

They follow the same rules. It's just that we use custom names for the categories for Functions. We wanted this to be the same across all languages, so relying on class names didn't really work for node, etc. This has been this way since Functions v2 and is documented here: https://learn.microsoft.com/en-us/azure/azure-functions/configure-monitoring?tabs=v2#configure-categories

  • Overrides for host.json work for some logging categories but not all. AzureFunctionsJobHostlogginglogLevelFunction works, but ...FunctionFunctionNameUser does not.

The correct filter there would be AzureFunctionsJobHost__logging__logLevel__Function.FunctionName.User. This is documented here: https://learn.microsoft.com/en-us/azure/azure-functions/configure-monitoring?tabs=v2#overriding-monitoring-configuration-at-runtime. Internally, this is relying on the .NET log filtering and configuration system. The __ represents the hierarchical key you'd see in a json file. Any host.json setting can be represented by mapping it to an app setting and using __ as the separator. https://learn.microsoft.com/en-us/aspnet/core/fundamentals/configuration/?view=aspnetcore-7.0#configuration-keys-and-values

  • Adding the ApplicationInsights logging packages causes problems with seeing log entries in local development.

This is a bug and there's a handful of other issues out there covering it. We're trying to take stop Application Insights double-logging and the approach currently is to remove all grpc logs from making it to the host. Well, that means that not only do you lose App Insights there (which was the goal), you're also losing console, file, etc, which was not the goal. There are a couple PRs out now to address this (https://github.com/Azure/azure-functions-dotnet-worker/pull/1183, https://github.com/Azure/azure-functions-host/pull/8965), but due to the holidays, there won't be a release until the new year...

  • In my own experiment (.NET 6, isolated process) the AddApplicationInsights* helpers do not appear to be necessary during local development. As long as an APPINSIGHTS_INSTRUMENTATIONKEY setting exists, log entries are making it to Application Insights (?!). They are also visible in the local host terminal.

This depends on what you're trying to do. Without those settings, everything will flow through the host but you'll lose access to structured logging, auto-dependency tracking, any custom ITelemetryInitializers, etc.

  • There is work planned to improve all this. There will be a focus on enabling/encouraging OpenTelemetry.

Correct!

brettsam commented 1 year ago

Reply to @stevelknievel76 (https://github.com/Azure/azure-functions-dotnet-worker/issues/1182#issuecomment-1332902091):

Notice that the "Type" column is not populated for all messages other than the first (that message was generated by the TimerTrigger framework, and not by my code).

What you're seeing is a discrepancy between the host writing a log and the isolated worker writing a log. On the host, we use an ITelemetryInitializer to write out the LogLevel in a custom property, which the portal then uses in that screen from your screenshot.

We're trying to be very "hands-off" with the custom properties we add on the worker-side and allow you to customize this on your own. I realize this may mean some properties don't match 1:1 across worker and host. We could add some configuration to help with this in the future, but we'd want to see how desirable this is.

In this case, you can add an ITelemetryInitializer that adds the LogLevel custom property based on the current Severity (that's what App Insights calls LogLevel).

brettsam commented 1 year ago

Replying to @SeanFeldman (https://github.com/Azure/azure-functions-dotnet-worker/issues/1182#issuecomment-1333209478):

Can you file a separate issue for this with a sample? All these logs you're mentioning are coming from the Azure SDK and should be filter-able so I'm not sure what's happening in your case.

brettsam commented 1 year ago

Replying to @brandonh-msft (https://github.com/Azure/azure-functions-dotnet-worker/issues/1182#issuecomment-1345344248):

Even with all this, I'm not able to get Debug+ logs to console and AI in .NET 6 Isolated while debugging locally. :/

I just commented on it above, but console logs are currently broken locally. You should, however, see your logs in App Insights, even when running locally, as long as the APPLICATIONINSIGHTS_CONNECTION_STRING is set in local.settings.json.

If you've got all that, can you also create a separate issue with a sample? It's mentioned above in a couple of places, but App Insights adds their own log filter that can be a bit confusing to work around if you don't know it's there. @LockTar has specific code to remove it in the comment here. I wonder if you're running into that, but all logs should be able to be viewed, based on the filters.

rellis-of-rhindleton commented 1 year ago

@brettsam - Thank you for all of that, it’s very helpful.

I found the categories section of the monitoring article a little hard to follow. It all makes sense now, but when I was first trying to get things working it didn’t really help. Using custom category names for functions isn’t a bad idea in itself (though I wish the hierarchy was a little different) — but it discards category names that might have been provided in the code, class name or otherwise. That’s not what we’ve been trained to expect. 😁 After figuring it out I opened pull request 102112 to try to make it a bit clearer. It hasn’t been merged yet. If you feel like making sure it doesn’t mislead anyone you might want to take a look at it. It’s not big.

I knew about the double underscore delimiter but must have missed the periods at the end of the category names. Since they aren’t logged in local development it can be awkward trying to discover them.

Sounds like I should add the ApplicationInsights packages when running on Azure even if not using them during local development.

Again, thanks for the info and context.

plamber commented 1 year ago

Hello @brettsam, Do you have some suggestions on manipulating the "RoleName" property using this setup?

I aim to assign a specific role name to multiple Azure Function instances. This helps us to filter the Azure functions based on specific roles.

I appreciate your help

larry-lau commented 1 year ago

@LockTar Following this thread, my Isolated .net 7 functions app could log traces in AppInsights successfully but not for long. My function is queue-triggered. For the first few invocations, logging works. but after that nothing from my app is logged in AppInsights.
image Only the host logging appears. image And it will stay like this until I restart the Functions and logging will start working for the first few invocations say 2-3.

@LockTar Have you seen this behaviour? Any suggestion on what I could try next would be appreciated.

brettsam commented 1 year ago

Responding to @plamber (https://github.com/Azure/azure-functions-dotnet-worker/issues/1182#issuecomment-1364973524):

Do you have some suggestions on manipulating the "RoleName" property using this setup?

RoleName is controlled in Application Insights by the telemetry.Context.Cloud.RoleName. You can write your own ITelemetryInitializer and set this to whatever you want: https://learn.microsoft.com/en-us/azure/azure-monitor/app/api-filtering-sampling#add-a-cloud-role-name

This will, however, only apply to logs coming from the worker. The logs coming from the host will not be affected. We have an issue tracking that here: https://github.com/Azure/azure-functions-dotnet-worker/issues/655.

brettsam commented 1 year ago

Responding to @larry-lau (https://github.com/Azure/azure-functions-dotnet-worker/issues/1182#issuecomment-1372630620):

For the first few invocations, logging works. but after that nothing from my app is logged in AppInsights.

Can you file a separate issue with these details and tag me? Be sure to include the code that you used to enable AppInsights in the worker.

Done3319 commented 1 year ago

For me Application Insights works perfectly now for .Net isolated. Thanks @brettsam for the implementation and @LockTar for the great summary!

The only thing I'm unable to do is disabling Dependency Tracking.

I tried via host.json / appsetting.json, but no matter what I try, dependency data is still being logged:

{
  "logging": {
    "applicationInsights": {
      "samplingSettings": {
        "isEnabled": true,
        "maxTelemetryItemsPerSecond": 0.1,
        "excludedTypes": "Exception;Trace"
      },
      "enableDependencyTracking": false,
      "logLevel": {
        "default": "Warning",
        "Azure": "Warning",
        "Function": "Warning",
        "Host": "Information",
        "Microsoft": "Warning"
      }
:
:

Any idea how Dependency Tracking can be disabled?

LockTar commented 1 year ago

@LockTar Have you seen this behaviour? Any suggestion on what I could try next would be appreciated.

I haven't really seen this behaviour but to be honest, I'm currently not really paying attention to it because we are working on a big new project and we are not running in production yet (with load over a longer period). As suggested by @brettsam create a new issue and link it to this one.

For me Application Insights works perfectly now for .Net isolated. Thanks @brettsam for the implementation and @LockTar for the great summary!

Your welcome.

I'm currently not really focussing on logging right now because I'm implementing business logic in app. I'm hoping that a few bugs are fixed in the next few weeks (and new packages are released) so I can update my sample projects and of course my application. Just in time to release it to production with correct logging. Just checked but I think my sample applications are still up to date.

rattrick1 commented 1 year ago

@SeanFeldman Basically it results in the following:

  1. Add the 2 new lines of the preview package
  2. Remove the warning and above logger
  3. Use appsettings.json as configuration file
  4. Configure logging from appsettings.json
  5. Optional setup DI for testing injected classes with ILogger<T>

Program.cs

using Microsoft.Extensions.Hosting;
using Microsoft.Azure.Functions.Worker;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using Func.Isolated.Net7.With.AI;

var host = new HostBuilder()
    .ConfigureFunctionsWorkerDefaults(builder =>
    {
        // Is added by package "Microsoft.Azure.Functions.Worker.ApplicationInsights".
        // Documented here because it is still preview: https://github.com/Azure/azure-functions-dotnet-worker/pull/944#issue-1282987627
        builder
            .AddApplicationInsights()
            .AddApplicationInsightsLogger();        
    })
    .ConfigureServices((ctx, serviceProvider) =>
    {
        // You will need extra configuration because above will only log per default Warning (default AI configuration) and above because of following line:
        // https://github.com/microsoft/ApplicationInsights-dotnet/blob/main/NETCORE/src/Shared/Extensions/ApplicationInsightsExtensions.cs#L427
        // This is documented here:
        // https://github.com/microsoft/ApplicationInsights-dotnet/issues/2610#issuecomment-1316672650
        // So remove the default logger rule (warning and above). This will result that the default will be Information.
        serviceProvider.Configure<LoggerFilterOptions>(options =>
        {
            var toRemove = options.Rules.FirstOrDefault(rule => rule.ProviderName
                == "Microsoft.Extensions.Logging.ApplicationInsights.ApplicationInsightsLoggerProvider");

            if (toRemove is not null)
            {
                options.Rules.Remove(toRemove);
            }
        });

        // Setup DI
        serviceProvider.AddTransient<IUserDataService, UserDataService>();
    })
    .ConfigureAppConfiguration((hostContext, config) =>
    {
        // Add appsettings.json configuration so we can set logging in configuration.
        // Add in example a file called appsettings.json to the root and set the properties to:
        // Build Action: Content
        // Copy to Output Directory: Copy if newer
        //
        // Content:
        // {
        //   "Logging": {
        //     "LogLevel": {
        //       "Default": "Error" // Change this to ie Trace for more logging
        //     }
        //   }
        // }
        config.AddJsonFile("appsettings.json", optional: true);
    })
    .ConfigureLogging((hostingContext, logging) =>
    {
        // Make sure the configuration of the appsettings.json file is picked up.
        logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging"));
    })
    .Build();

host.Run();

Add appsettings.json file with settings Build Action: Content and Copy to Output Directory: Copy if newer:

{
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Func.Isolated.Net7.With.AI.MyOtherFunctions": "Error",
      "Func.Isolated.Net7.With.AI.MyUserFunctions": "Debug",
      "Func.Isolated.Net7.With.AI.UserDataService": "Trace"
    }
  }
}

You have no idea how much that little comment you posted saved us:

// Is added by package "Microsoft.Azure.Functions.Worker.ApplicationInsights". // Documented here because it is still preview: https://github.com/Azure/azure-functions-dotnet-worker/pull/944#issue-1282987627

Saved my colleague and I. So many examples show AI being wired up this way, but none mention that this was via a preview package. Thank you!

ErikPilsits-RJW commented 1 year ago

There's mention here of using Serilog as an alternative logger. We use Serilog for all our apps and I think I got it working now with a v4 isolated function on .NET 6. I have not done full testing for log correlation, but I am seeing logs in app insights on the portal. I am not getting app insights logs locally in VS 2022 when debugging however, which is frustrating, but I have console logging for that. Here's the gist of it.

You'll need these packages.

    <PackageReference Include="Microsoft.Azure.Functions.Worker.ApplicationInsights" Version="1.0.0-preview3" />
    <PackageReference Include="Serilog" Version="2.12.0" />
    <PackageReference Include="Serilog.Extensions.Hosting" Version="5.0.1" />
    <PackageReference Include="Serilog.Settings.Configuration" Version="3.4.0" />
    <PackageReference Include="Serilog.Sinks.ApplicationInsights" Version="4.0.0" />
    <PackageReference Include="Serilog.Sinks.Console" Version="4.1.0" />

appsettings.json

  "Serilog": {
    "WriteTo": {
      "ConsoleSink": "Console"
    },
    "MinimumLevel": {
      "Default": "Debug",
      "Override": {
        "Microsoft": "Warning",
        "System": "Warning",
        "Microsoft.Hosting.Lifetime": "Information"
      }
    },
    "Enrich": [ "FromLogContext" ]
  }

Program.cs

var host = new HostBuilder()
    .ConfigureFunctionsWorkerDefaults((_, builder) =>
    {
        builder
            .AddApplicationInsights()
            .AddApplicationInsightsLogger();
    })
    .ConfigureAppConfiguration(config =>
    {
        string environment = Environment.GetEnvironmentVariable("AZURE_FUNCTIONS_ENVIRONMENT") ?? Environments.Production;

        config
            .SetBasePath(Directory.GetCurrentDirectory())
            .AddJsonFile("appsettings.json", optional: true, reloadOnChange: false)
            .AddJsonFile($"appsettings.{environment}.json", optional: true, reloadOnChange: false)
            .AddUserSecrets<Program>(optional: true);
    })
    .UseSerilog((context, sp, config) =>
    {
        config.ReadFrom.Configuration(context.Configuration)
            .WriteTo.ApplicationInsights(sp.GetRequiredService<TelemetryConfiguration>(), TelemetryConverter.Traces);
    })
    .ConfigureServices(Configure)
    .Build();

await host.RunAsync();

void Configure(HostBuilderContext context, IServiceCollection services)
{
    // optional worker telemetry configuration
    services.Configure<TelemetryConfiguration>(config =>
    {
        var builder = config.DefaultTelemetrySink.TelemetryProcessorChainBuilder;
        builder.UseAdaptiveSampling(excludedTypes: "Request;Exception;Trace");
        builder.Build();
    });

    // main configuration continues ...
}

I'm interested to hear anyone else's experience with this config, and if it's missing anything that's been discussed above.

ibrahim-13 commented 1 year ago

@ErikPilsits-RJW Working for me for Isolated V4 Function on .NET 7 The following made the difference-

+    <PackageReference Include="Microsoft.Azure.Functions.Worker.ApplicationInsights" Version="1.0.0-preview3" />
    <PackageReference Include="Serilog" Version="2.12.0" />
    <PackageReference Include="Serilog.Extensions.Hosting" Version="5.0.1" />
    <PackageReference Include="Serilog.Settings.Configuration" Version="3.4.0" />
    <PackageReference Include="Serilog.Sinks.ApplicationInsights" Version="4.0.0" />
    <PackageReference Include="Serilog.Sinks.Console" Version="4.1.0" />
var host = new HostBuilder()
+    .ConfigureFunctionsWorkerDefaults((_, builder) =>
+   {
+        builder
+            .AddApplicationInsights()
+            .AddApplicationInsightsLogger();
+    })
    .ConfigureAppConfiguration(config =>
    {
        string environment = Environment.GetEnvironmentVariable("AZURE_FUNCTIONS_ENVIRONMENT") ?? Environments.Production;

        config
            .SetBasePath(Directory.GetCurrentDirectory())
            .AddJsonFile("appsettings.json", optional: true, reloadOnChange: false)
            .AddJsonFile($"appsettings.{environment}.json", optional: true, reloadOnChange: false)
            .AddUserSecrets<Program>(optional: true);
    })
    .UseSerilog((context, sp, config) =>
    {
        config.ReadFrom.Configuration(context.Configuration)
            .WriteTo.ApplicationInsights(sp.GetRequiredService<TelemetryConfiguration>(), TelemetryConverter.Traces);
    })
    .ConfigureServices(Configure)
    .Build();

await host.RunAsync();

void Configure(HostBuilderContext context, IServiceCollection services)
{
    // optional worker telemetry configuration
    services.Configure<TelemetryConfiguration>(config =>
    {
        var builder = config.DefaultTelemetrySink.TelemetryProcessorChainBuilder;
        builder.UseAdaptiveSampling(excludedTypes: "Request;Exception;Trace");
        builder.Build();
    });

    // main configuration continues ...
}
tflanitzer commented 1 year ago

To see logs in the console while debugging locally, adding logging.AddConsole() in ConfigureLogging worked for me:

    .ConfigureLogging(
        (hostingContext, logging) =>
        {
            logging.AddConsole();
            logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging"));
        })

Btw thanks for bringing all the information together here. It was maddening to see logging examples everywhere that just don't work as expected (e.g. here).

p-m-j commented 1 year ago

@brettsam - Is the any timeline for when this might occur ↓

This is a bug and there's a handful of other issues out there covering it. We're trying to take stop Application Insights double-logging and the approach currently is to remove all grpc logs from making it to the host. Well, that means that not only do you lose App Insights there (which was the goal), you're also losing console, file, etc, which was not the goal. There are a couple PRs out now to address this (https://github.com/Azure/azure-functions-dotnet-worker/pull/1183, https://github.com/Azure/azure-functions-host/pull/8965), but due to the holidays, there won't be a release until the new year...

Even after following everything in this thread (except Serilog) I still cannot get both app insights and console logging working at the same time.

Feel like I'm losing my mind.


Edit: I admitted defeat and added Serilog with the appinsights sink ala https://github.com/Azure/azure-functions-dotnet-worker/issues/1182#issuecomment-1461507394 to fix structured logging - https://github.com/Azure/azure-functions-host/issues/7452

locally I still have no console but can add a sink for grpc or udp to run with a log viewer (or just write a clef file)

brettsam commented 1 year ago

We're waiting on the host 4.16 to arrive everywhere in production and then finally in Core Tools. It's still not there. It's currently released in production for Windows and Linux Dedicated SKUs. It's still rolling out for Linux Consumption. After that, a new version of Core Tools will be released.

We also need to get #1307 merged and released. There's a lot of back-and-forth comments on that issue but it's getting close. I'm working to get this done soon, but you won't notice any improvement until Core Tools is running 4.16.

I can't give you an ETA as I do not control this release, and any ETA I provide will be wrong :-)

AKruimink commented 1 year ago

With the help of this article I managed to setup my NET7 isolated functions app with AI, i am however still having an issue (which might or might not be related?).

I am seeing the logging in the cloud, im also seeing them in the console and the visual studio output window, but for some reason non of it is being caught by the debug session telemetry/visual studio application insights search,

Is this an existing issue with the package in preview, even in a new http triggered function app fllowing the steps outlined here does not log anything in the local search.

braher commented 1 year ago

Hi @LockTar ,

I just wanted to say a big thank you for your awesome solution! It really helped me fix those pesky duplicate logs in Application Insights and made it easy to add my custom dimensions using beginScope.

I was just wondering, do you have any tips on how to include the operation_name in the logs? I'd really appreciate your input!

Thanks a bunch!

LockTar commented 1 year ago

I just wanted to say a big thank you for your awesome solution! It really helped me fix those pesky duplicate logs in Application Insights and made it easy to add my custom dimensions using beginScope.

Your welcome!

I was just wondering, do you have any tips on how to include the operation_name in the logs? I'd really appreciate your input!

Sorry can't help you with that...

simonlrostron commented 1 year ago

@LockTar, you rock. Decided to take the plunge and try .NET 7 Functions for the first time. The notes alone are valuable, but the sample repo is next-level.

We have people like you to thank for the success of the community. Many thanks.

drazen-relias commented 1 year ago

APPLICATIONINSIGHTS_CONNECTION_STRING

Hi @brettsam, If I hard code this setting as an environment variable for my isolated Azure Function (v4) – everything works fine, however if I try to read it from azure app config and set it as environment variable during runtime – that seems not to be working. I am deploying my azure function to k8s cluster, could you please advise if there is a way to dynamically read that connection string from my azure app config and put it as an environment variable?

jviau commented 1 year ago

If I hard code this setting as an environment variable for my isolated Azure Function (v4) – everything works fine, however if I try to read it from azure app config and set it as environment variable during runtime – that seems not to be working. I am deploying my azure function to k8s cluster, could you please advise if there is a way to dynamically read that connection string from my azure app config and put it as an environment variable?

This only applies to the worker process: Instead of setting that environment variable, you can structure the connection string in Azure AppConfiguration as ApplicationInsights:ConnectionString, and then it should automatically be mapped onto the ApplicationInsightsServiceOptions.

BUT I think your primary problem is the host process! That step I just described AND mapping to an environment variable that you described will not work for the host process. You must have this value available for the host process well before the worker process even starts up. This means you will probably have to find some k8s specific solution for getting the environment variable prepped for the host process.

Fabiest commented 1 year ago

Hi @LockTar ,

I just wanted to say a big thank you for your awesome solution! It really helped me fix those pesky duplicate logs in Application Insights and made it easy to add my custom dimensions using beginScope.

I was just wondering, do you have any tips on how to include the operation_name in the logs? I'd really appreciate your input!

Thanks a bunch!

I have the exact same issue. Anyone figured a solution?

jviau commented 1 year ago

@Fabiest you can use an ITelemetryInitializer to set operation_name. It is .Context.Operation.Name

LockTar commented 1 year ago

Hi all, Microsoft removed the preview version of Microsoft.Azure.Functions.Worker.ApplicationInsights. You can now use the v1 version from Nuget. See the official GA release here.

The sample applications GitHub are now updated to the latest version and are reflecting the new documentation added by Microsoft.

I want to thank @p-m-j for helping updating the sample applications.

AJMikalauskas commented 1 year ago

Please feel free to ask me for anything as I am new to posting my questions on GitHub. Here is my question: I am trying to get my .NET 7 Azure Function App to be connected to Application Insights, but currently am only getting logs locally and not sent to the actual Application Insights. I added all of the code except for the

.ConfigureLogging((hostingContext, logging) => { // Make sure the configuration of the appsettings.json file is picked up. logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging")); }).

When I add that, all that gets returned is null even when my appsettings.json looks like this

"Logging": { "LogLevel": { "Default": "Information" } },

I am assuming it would be no big deal to add other environment variables after the logging section in the appsettings.json, correct? Another question I have is can I run my Service Bus Queue Triggered Function App locally and still log data to application insights? I'm not sure I see where the connection exists from logging to a specific application insights as in .NET 6 I had to provide the instrumentation key or connection string for my application insights in my .net 6.0 function app.

AJMikalauskas commented 1 year ago

Please feel free to ask me for anything as I am new to posting my questions on GitHub. Here is my question: I am trying to get my .NET 7 Azure Function App to be connected to Application Insights, but currently am only getting logs locally and not sent to the actual Application Insights. I added all of the code except for the

.ConfigureLogging((hostingContext, logging) => { // Make sure the configuration of the appsettings.json file is picked up. logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging")); }).

When I add that, all that gets returned is null even when my appsettings.json looks like this

"Logging": { "LogLevel": { "Default": "Information" } },

I am assuming it would be no big deal to add other environment variables after the logging section in the appsettings.json, correct? Another question I have is can I run my Service Bus Queue Triggered Function App locally and still log data to application insights? I'm not sure I see where the connection exists from logging to a specific application insights as in .NET 6 I had to provide the instrumentation key or connection string for my application insights in my .net 6.0 function app.

Minor Update: I am seeing logs in my Application Insights but only after providing the application insights like this: serviceProvider.AddApplicationInsightsTelemetryWorkerService((ApplicationInsightsServiceOptions options) => options.ConnectionString = ctx.Configuration.GetValue<string>("APP_INSIGHTS_CONNECTION_STRING"));

drew-fc commented 9 months ago

hey @LockTar , sorry to tag you, but I am following your example and I am stuck. I am using the latest app insights which you linked above, and trying to get logs to work in my .NET 8.0 v4 function app. My program.cs looks pretty much identical to this:https://github.com/devops-circle/Azure-Functions-Logging-Tests/blob/master/Func.Isolated.Net7.With.AI/Program.cs

However, everything is being written to AppInsights as "trace" with "Information" as the severity level. Here's an example:

_logger.LogTrace("TestLog Trace"); _logger.LogInformation("TestLog Information"); _logger.LogError( "TestLog Error"); _logger.LogError(new Exception("something wrong"),"TestLog ErrorWithException");

Shows up like this: image

Any ideas?