Azure / azure-functions-dotnet-worker

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

Application Insights: telemetry initializer / processor not called for request telemetry items #2024

Open gabrielweyer opened 8 months ago

gabrielweyer commented 8 months ago

I noticed that telemetry initializers and processors are not called for request telemetry items. I assume that's because request telemetry items are emitted by the host. This reduces the usefulness of the Application Insights integration:

kshyju commented 8 months ago

You can configure your isolated process application to emit logs directly Application Insights, giving you control over how those logs are emitted. This replaces the default behavior of relaying custom logs through the host.

See https://learn.microsoft.com/en-us/azure/azure-functions/dotnet-isolated-process-guide#application-insights for mode details on how to get started.

gabrielweyer commented 8 months ago

Sorry, I should have provided more details. I did follow https://learn.microsoft.com/en-us/azure/azure-functions/dotnet-isolated-process-guide#application-insights.

I referenced Microsoft.ApplicationInsights.WorkerService version 2.21.0 and Microsoft.Azure.Functions.Worker.ApplicationInsights version 1.0.0.

Program.cs:

var host = new HostBuilder()
    .ConfigureFunctionsWorkerDefaults()
    .ConfigureServices(services =>
    {
        services
            .AddApplicationInsightsTelemetryWorkerService()
            .ConfigureFunctionsApplicationInsights()
            .AddApplicationInsightsTelemetryProcessor<HealthRequestFilter>();
    })
    .Build();

HealthRequestFilter.cs:

internal sealed class HealthRequestFilter : ITelemetryProcessor
{
    private readonly ITelemetryProcessor _next;

    public HealthRequestFilter(ITelemetryProcessor next)
    {
        _next = next;
    }

    public void Process(ITelemetry item)
    {
        if (item is RequestTelemetry { ResponseCode: "200" } request &&
            "HealthFunction".Equals(request.Name, StringComparison.OrdinalIgnoreCase))
        {
            return;
        }

        _next.Process(item);
    }
}

If required, I can push my repro.

AlrikOlson commented 5 months ago

Hi @satvu,

Could we get an update on fixing telemetry initializer/processor for request telemetry items? It's crucial for custom tag correlation. We are experiencing the same issue, but with ITelemetryInitializer implementations.

Thank you!

basilfx commented 4 months ago

I'm also experiencing this problem. In particular, I want to filter the 'Executing ..' (FunctionStarted) and 'Executed ..' (FunctionCompleted) telemetry items. That was working fine for in-process.

However, when I add a ITelemetryProcessor, I get a lot of telemetry items, but none that represents the said trace items.

brettsam commented 4 months ago

In short -- this is by-design. We're not going to automatically pick up services from a dotnet-isolated app and consume them in the host. However, I think we can solve for the scenarios.

To frame some of the decisions -- let me say that the transition from in-proc to isolated has a ton of benefits, but one of the drawbacks is having direct control over what the host does via DI or code customizations. This is partially on purpose -- we're trying to run less customer code in the host and instead allow customers to have 100% control over the isolated process and how it runs. With in-proc there were a lot of restricted services/actions. And even if something wasn't restricted, the behavior was not always clear because of how services composed. A slight change in our logic -- or even minor bumps in dependencies -- could break many customers that relied upon very specific behavior. Running "our" code and "your" code side-by-side in the same process can be very messy to say the least.

So to focus on dotnet-isolated logging -- some logs are emitted to Application Insights by the worker (where you have complete control via ITelemetryProcessor/ITelemetryInitializer). And others are emitted by the host -- which is a separate process -- where you have more limited control via the host.json log filtering mechanisms (https://learn.microsoft.com/en-us/azure/azure-functions/configure-monitoring?tabs=v2#configure-log-levels). We are not likely to ever allow your dotnet-isolated App Insights ITelemetryProcessor code to get loaded and injected into the host. Instead, we're focusing our efforts on what we can do to improve the experience across all languages.

Even though many non-dotnet customers (node, python, java, etc) have been running with these restrictions for a while, the influx of in-proc customers moving to isolated are highlighting some rough edges on our logging story. But I think they're mostly solvable.

For host-side filtering -- in this issue I see:

As for adding custom tags/properties to telemetry -- I'll need to follow-up with the OTel/distributed tracing experts, but my understanding was that due to the parent/child relationship of a function invocation (we pass the traceparent id to the worker and it all gets included in telemetry), adding tags in the worker alone should be enough to perform correlation in Application Insights. In other words -- I think that logging this from the worker in the context of an invocation -- or adding it to the current Activity in the worker -- is enough. I will see if I can get a better answer for you there (and a sample as well) as this would apply to all other languages -- not just dotnet. Ultimately things like OTel have defined how distributed tracing should work and we want to make sure we're following along with that as that's where the industry/tools are all going.

basilfx commented 4 months ago

@brettsam Thank you for your explanation.

filtering of FunctionStarted/FunctionCompleted -- this should be possible today. These are logged with the category Function. and therefore can be filtered per-function in host.json. Please let me know if you're finding this is not the case. This should never have required an initializer/processor.

There is a difference between filtering it from logging completely, or filtering it from Application Insights only. With the in-process model, we were using a ITelemetryProcessor to filter FunctionStarted/FunctionCompleted from Application Insights only, but have it in our console and other logging 'as usual'. The same applies to other messages we filter (such as trigger details).

I don't see any method in the host.json reference to accomplish the same.

lnhzd commented 4 months ago

It works if you swich to function app with asp.net core integration, but the trouble is asp.net core integration doesn't seem to be stable at all based on recent bugs raised.

Trimatix commented 2 weeks ago

Many thanks @brettsam for your detailed comment - this was super helpful in understanding the behaviour of the isolated worker model, and helped me diagnose why we weren't getting FunctionStarted/FunctionCompleted logs in app insights 👍