Support structured logging from worker

[brettsam]

The .NET worker is getting requests for structured logging from the worker -> host -> app insights. We'll need to update the GRPC contract for this to work.

[brettsam]

Related: Azure/azure-functions-dotnet-worker#423

[fabiocav]

Moving this to 108 as we're still working with other teams to get feedback and work through the design

[kjeske]

Could you provide us with some time estimates for this fix? It's blocking Azure/azure-functions-dotnet-worker#423 and it seems this bug is being constantly postponed.

[fabiocav]

@kjeske we're still working on some design/open questions and the issue is primarily tracking that work at the moment. When we have more details and start on implementation, we'll be in a better position to provide an ETA

[emmorts]

@fabiocav, any update on this?

This is quite a crucial feature in our use case. Is there an alternative you could suggest for the time being?

[kelps]

As a workaround, I thought of adding a custom logger factory to DI that would create an ILogger that doesn't flow through the host GRPC channel and would connect directly to Insights. In theory it should work, but we would loose all console and stream logs in Azure and local dev and would be forced to rely on Insights for ANY diagnostics. If we try to keep the connection to GRPC, to also show in the stream logs, Insights would get duplicated entries with and without the structured information.

It should work, but I didn't have the time to try and test it yet.

This NEEDS to be FIXED soon. It is a very serious bug. From the looks of it, I'm worried that it might only happen for .NET 7, but that would be a serious case of not giving enough importance to very important community feedback. This specific issue is already 7 months old, and it was not the first on this problem.

If the intention really is to have only isolated process in .NET 7, as the roadmap suggests, EVERYTHING that work in process will need to work in isolated, including structured logs.

Please make it available as a fix in 6, not only in 7!

[tommck]

I'm thinking .NET 8 at the earliest

[marios-siatis]

Hey guys I have a workaround for structured logging by using serilog, to replace the existing ms logger.
I think is clean as I only need to modify the startup of the application.

https://medium.com/@marios.shiatis/addressing-the-structured-logging-application-insights-issues-in-azure-functions-v4-net-6-0-f1f63b99807d

[colinrippeyfinarne]

@fabiocav @brettsam is there any update you can share on this issue? I am conscious that as we approach the release of dotnet 7 the capability to go "all in" on the isolated model will be pushed (in particular the support for durable functions which has made me stay with the in-proc model for now) but not if structured logging is still not working?

[timmkrause]

At least an "official" statement regarding the roadmap of this issue would be something.

Transparency is key.

[cloudmelon]

hi @colinrippeyfinarne the durable function support is currently in public preview.

https://github.com/Azure/azure-functions-dotnet-worker/projects/2

cc @cgillum

[cloudmelon]

Had a quick check, we had done the work to pull AppInsights logs directly from Worker -> AppInsights, so it supports anything .NET supports directly

Related issue :
Azure/azure-functions-dotnet-worker#944 (comment)

Feel free to try it out :
https://www.nuget.org/packages/Microsoft.Azure.Functions.Worker.ApplicationInsights/1.0.0-preview1

[MullenStudio]

Had a quick check, we had done the work to pull AppInsights logs directly from Worker -> AppInsights, so it supports anything .NET supports directly

Related issue : Azure/azure-functions-dotnet-worker#944 (comment)

Feel free to try it out : https://www.nuget.org/packages/Microsoft.Azure.Functions.Worker.ApplicationInsights/1.0.0-preview1

I just tested and it seems that it still doesn't support structured log.

I noticed this line in the code
options.IncludeScopes = false;

But even if I set IncludeScopes to true in the options, it still doesn't work.

builder.AddApplicationInsights().AddApplicationInsightsLogger(options =>
                    {
                        options.IncludeScopes = true;
                    });

Any suggestion?

[arkiaconsulting]

Tested with https://www.nuget.org/packages/Microsoft.Azure.Functions.Worker.ApplicationInsights/1.0.0-preview3. Still no scoped properties.

[mxvoloshin]

Any plans when this will be working?

[madushans]

This is broken and prevents using .NET 7 and having any meaningfully useful logs and metrics.

PLEASE consider updating execution mode comparison to prevent people wasting their time upgrading and end up breaking logs and dashboards that rely on structured logging and custom metrics.

[sid2934]

Do we have an idea of when this work may be picked up?

[madushans]

Unfortunately doesn't look like it. The team appears to be focusing on other thinks like Durable Functions and updates to Python experience.

Since worker/isolated mode is the way forward for dotnet as well, this will have to be fixed be ready before dotnet 6 goes out of support (12 Nov 2024). Until then, dotnet 6 is supported in the in-process mode which has this working, and it is LTS.

Bit less pessimistic view is they may fix this before end of 2023 (or mid 2024 like they did for dotnet 7 in mid 2022?) so people can move to dotnet 8 LTS in time to get out of dotnet 6.

[DOMZE]

I was able, through the other issue, to get structured logging to show up in application insights.

Here's a snippet on how to get this going. Note that I deployed this on a Windows App Service Plan. Did not try on Linux.
Install the Microsoft.Extensions.Logging.ApplicationInsights package to get the extension method to be discoverable on the ILoggingBuilder

class Program
{
	static async Task Main(string[] args)
	{
		var host = new HostBuilder()
			.ConfigureFunctionsWorkerDefaults()
			.ConfigureLogging((context, builder) =>
			{
				// does not work as per https://github.com/Azure/azure-functions-dotnet-worker/issues/423
				//builder.AddApplicationInsights();

				var applicationInsightsConnectionString = context.Configuration["APPLICATIONINSIGHTS_CONNECTION_STRING"];
				if (!string.IsNullOrEmpty(applicationInsightsConnectionString))
				{
					builder.AddApplicationInsights(configureTelemetryConfiguration =>
					{
						configureTelemetryConfiguration.ConnectionString = applicationInsightsConnectionString;
					}, _ => { });
				}
			})
			.Build();

		await host.RunAsync();
	}
}

[brettsam]

This is the right direction @DOMZE. We have a specific package in preview right now that wraps the default App Insights packages and does this wire-up for you. There's a couple small tweaks it makes, but behind-the-scenes it's basically doing what you're doing there.

See this for more details on the App Insights package (including the "docs" in the PR): Azure/azure-functions-dotnet-worker#1263

[JayAtSherweb]

@brettsam Your documentation seems to outline how to use in an application, but not an isolated function.
Please help.

[brettsam]

@JayAtSherweb -- Once you've set things up with App Insights as mentioned in the docs (specifically, calling AddApplicationInsightsLogger(), any logging you do will go directly to Application Insights. Their ILogger implementation supports structured logging. I couldn't find an official doc with an example, but a log like this:

_logger.LogWarning("C# HTTP trigger function processed a request. {guid}", Guid.NewGuid());

will write the message to the traces table in App Insights -- and you'll see the guid extracted into the customDimensions.

[p-m-j]

@brettsam - This doesn't seem to work with ILogger.BeginScope<TState> however

e.g.

  [Function("Pong")]
  public void QueueTrigger([QueueTrigger("ping")] string myQueueItem)
  {
      using var scope = _logger.BeginScope(new Dictionary<string, object>{ ["A"] = "12345" });

      _logger.LogInformation("pong {B}", "12345");
  }

Has a customDimension.B but no customDimension.A present

Edit: By this I mean

<PackageReference Include="Microsoft.Azure.Functions.Worker.ApplicationInsights" Version="1.0.0-preview3" />

[brettsam]

@p-m-j -- can you make sure to set up App Insights to IncludeScopes for now? This is incorrectly set to false in the last preview -- but I'm removing this line in a PR soon:

https://github.com/Azure/azure-functions-dotnet-worker/blob/584cab006b82e0cbc2b95a8b66e2546d3a8ddfe4/src/DotNetWorker.ApplicationInsights/FunctionsApplicationInsightsExtensions.cs#L51

You can override this with

.AddApplicationInsightsLogger(o => o.IncludeScopes = true);

[p-m-j]

@brettsam works like a charm, cheers

[fleed]

I was able, through the other issue, to get structured logging to show up in application insights.

Here's a snippet on how to get this going. Note that I deployed this on a Windows App Service Plan. Did not try on Linux. Install the Microsoft.Extensions.Logging.ApplicationInsights package to get the extension method to be discoverable on the ILoggingBuilder

class Program
{
	static async Task Main(string[] args)
	{
		var host = new HostBuilder()
			.ConfigureFunctionsWorkerDefaults()
			.ConfigureLogging((context, builder) =>
			{
				// does not work as per https://github.com/Azure/azure-functions-dotnet-worker/issues/423
				//builder.AddApplicationInsights();

				var applicationInsightsConnectionString = context.Configuration["APPLICATIONINSIGHTS_CONNECTION_STRING"];
				if (!string.IsNullOrEmpty(applicationInsightsConnectionString))
				{
					builder.AddApplicationInsights(configureTelemetryConfiguration =>
					{
						configureTelemetryConfiguration.ConnectionString = applicationInsightsConnectionString;
					}, _ => { });
				}
			})
			.Build();

		await host.RunAsync();
	}
}

Thank you @DOMZE !
But how do you configure the level for a specific category?
I tried the "standard" way, but it doesn't seem to work:

host.json:

{
    "version": "2.0",
    "logging": {
        "applicationInsights": {
            "samplingSettings": {
                "isEnabled": true,
                "excludedTypes": "Request"
            }
        },
        "logLevel": {
            "MyNamespace.MyClass": "Trace"
        }
    }
}

The logger MyNamespace.MyClass doesn't send anything below Information.

I get logs if I manually set the log level in code:

builder.SetMinimumLevel(LogLevel.Trace);

@brettsam from my tests, it also works if I add the package Microsoft.Azure.Functions.Worker.ApplicationInsights 1.0.0-preview4 and avoid the call builder.AddApplicationInsights(...), but still the configuration level is not set for a specific logger (at least not via host.json).

[p-m-j]

@fleed host.json configures the host process so there's not going to be any log categories with your namespaces there.

Check out Azure/azure-functions-dotnet-worker#1182

[brettsam]

I'm marking this issue as "won't fix" because this is all taken care of with the Microsoft.Azure.Functions.Worker.ApplicationInsights package.

We've decided that the best approach for the future is to not alter the grpc contract for structured logging and instead support logs that go directly to Application Insights (or any logging solution) from the worker.

In other words, instead of:

worker -> host (via grpc) -> application insights

All logging now relies on the Application Insights SDK to emit telemetry directly from the worker to the App Insights backend, without passing through the host.

worker -> application insights

There's a bunch of benefits to this:

• The host's grpc contract does not have to account for the logging structure of every language.
• The host doesn't have to chase new features or improvements that come from the different supported workers. You can use the latest and greatest bits from the App Insights SDK in the worker.
• Because we have no tight coupling with Application Insights in the worker and you're not depending on the host to emit your telemetry, you're free to listen to the "Microsoft.Azure.Functions.Worker" ActivitySource in the worker and wire up other telemetry solutions. We imagine we'll be expanding samples and guidance for OpenTelemetry in the future, for example.
• All the App Insights features are available to you in the worker -- register Initializers, Processors, etc. You're in full control of the way the worker creates and delivers the telemetry to Application Insights.
• And, specific to this issue, structured logging is fully supported without the Functions host needing to do anything.

There are, however, some confusing pieces that folks are still struggling with:

• host.json does not control logging levels in the worker by default. This file is parsed and applied by the host. Instead, think of the worker as "just a .NET console application". You can configure logging via code (ILoggingBuilder) or via Configuration just like any other .NET application. You can even load the host.json and apply it's Configuration to the worker, if you so choose. But by default, the worker does not look at host.json.
• Application Insights, by default, sets the minimum logging level for its ILogger at Warning. This can be confusing as .NET defaults this to Information. Application Insights has examples (including in the link above) showing how you can override this, and we show how to remove the filter completely in one of our samples here.

I'm also compiling some specific logging-related samples in a repo to help show full end-to-end repros that hopefully help explain some of the scenarios. One that was written for a specific customer's question about App Insights and some of the verbose logging coming from various SDKs was added here, for example: https://github.com/brettsam/dotnet-isolated-worker-samples/tree/main/ApplicationInsightsFiltering.

If there are more questions around this, please let us know and I'll see about adding more clarification.

We're ultimately trying to "get out of your way" with some of these changes, but the transition from the old "log through the host" model to this one has introduced some confusion that we're still trying to clear up.

[devagarwal007]

In .NET core 3, we were able to log traces with custom properties, and at that time, they were logged with the prefix "prop" like ""prop_CustomPropertyName." However, after implementing the above solution in .net 8, it is no longer adding the "prop" prefix. How to add that prefix?

[marspox]

Hi,
Do you know where I can find example code with working structured logging in Application Insights for the isolated worker (.NET 8)?