Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Dependency correlation is broken after upgrade to .NET SDK 2.5 #706

Closed
older opened this issue Feb 19, 2018 · 8 comments
Closed

Dependency correlation is broken after upgrade to .NET SDK 2.5 #706

older opened this issue Feb 19, 2018 · 8 comments
Labels
Milestone

Comments

@older
Copy link

older commented Feb 19, 2018

Repro Steps

  1. Create azure function using example from Custom telemetry in C# functions using ApplicationInsights 2.5 NuGet package.
  2. Run azure function and check what is logged in application insights
  3. Downgrade ApplicationInsights NuGet package to version 2.4
  4. Run azure function and check what is logged in application insights

Actual Behavior

This is what I get with ApplicationInsights 2.5:
appinsights25

Expected Behavior

Screenshot using ApplicationInsights 2.4:
appinsights24

Version Info

SDK Version : 2.5
.NET Version : 4.6.1
How Application was onboarded with SDK(VisualStudio/StatusMonitor/Azure Extension) : Visual Studio
OS : Windows
Hosting Info (IIS/Azure WebApps/ etc) : Azure

@TimothyMothra
Copy link
Member

@lmolkova Can you please review this?
This seems to be related to PR #677

@lmolkova
Copy link
Member

@older
could you please verify if http dependency calls are collected? From the screenshots it's not clear whether the calls are not tracked or correlation between telemetry is broken.
You may filter only dependency calls in the search blade on the portal, or query depednencies in analytics. More on dependency tracking

@MS-TimothyMothra
#677 should not be a root cause of this issue as it introduces a new API, that is not used (yet) anywhere, but does not alter any old APIs.

@older
Copy link
Author

older commented Feb 21, 2018

Calls are tracked but they are not correlated. Azure functions runtime collects requests, but doesn't automatically collect dependencies so it has to be done manually according to the document I linked. Also application version property is lost (maybe others as well, but I haven't checked).

Anyway, this is fixed with simple NuGet downgrade from 2.5 back to 2.4 so this is either intended breaking change which went undocumented or it is a bug in 2.5.

@lmolkova
Copy link
Member

@older
Broken correlation is NOT intended behavior and definitely a bug. I assume missing fields is also not intended.

Could you please also share the requests and dependency examples preferably in Analytics. Just query requests in past 10 minutes, expand the row with any request and send the screenshot. Please do the same for dependencies.

Thanks a lot!

@older
Copy link
Author

older commented Feb 21, 2018

You won't see this problem with requests, as requests are logged by azure functions runtime. But dependencies are logged with custom C# code. I exported 2 requests and 2 dependencies to CSV, hope this helps.

@lmolkova
Copy link
Member

lmolkova commented Feb 21, 2018

@older

the problem you described earlier is correlation issues between requests and dependencies, but this comment

You won't see this problem with requests, as requests are logged by azure functions runtime.

makes me wonder if I understood you correctly.
Do you mean that you don't see relevant telemetry for dependencies only, but see it for requests? It should not depend on the type of telemetry.

Thanks for providing requests and dependencies.
I see following from there. Request with Id af7b09a9-e4b0-45fd-8e92-04dea4da6295 is correlated with one of dependency calls you've provided (i.e.e their operation_Id match and dependency.Parent_Id is equal to request Id field). You should be able to see all related telemetry for this operation in the portal. Dependency is tracked by AI SDK 2.4.

Another dependency you've provided tracked by AI SDK 2.5 does not have operation_Id or parentId.

I've been able to repro the issue.

Apparently, Azure Functions do not use our Activity/DiagnosticSource approach and instead ask to set operation context on telemetry client

            private static TelemetryClient telemetry =
                new TelemetryClient() { InstrumentationKey = key };

            [FunctionName("HttpTrigger2")]
            public static async Task<HttpResponseMessage> Run(
                [HttpTrigger(AuthorizationLevel.Anonymous, "get", "post", Route = null)]
            HttpRequestMessage req, ExecutionContext context, ILogger log)
            {
                log.LogInformation("C# HTTP trigger function processed a request.");

!!!                telemetry.Context.Operation.Id = context.InvocationId.ToString();
!!!                telemetry.Context.Operation.Name = "cs-http";
                telemetry.TrackDependency("Test Dependency", "swapi.co/api/planets/1/", start, DateTime.UtcNow - start, true);

This is error-prone approach as telemetry client may track multiple requests in parallel and context is shared between them. Telemetry client is reused and may accidentally track telemetry with wrong id.

So even in 2.4 correlation in Azure functions is not reliable

Now, what's wrong in 2.5?
It seems that in 2.5 propagation of TelemetryClient.Context is broken (see #708) - it's not set in the telemetry. I'll dig further on that.

@MS-TimothyMothra do you know if anything was changed around TelemetryClient.Context ?

Workaround (suitable for 2.4 and 2.5)

Set context on the telemetry, not the telemetry client! Do it for all telemetry reported: Traces, events, and metrics if applicable

                var dependency = new DependencyTelemetry
                {
                    Name = "Test Dependency",
                    Target = "swapi.co/api/planets/1/",
                    StartTime = start,
                    Duration = DateTime.UtcNow - start,
                    Success = true
                };
                    
                dependency.Context.Operation.Id = context.InvocationId.ToString();
                dependency.Context.Operation.ParentId = context.InvocationId.ToString();
                dependency.Context.Operation.Name = "cs-http";
                if (!String.IsNullOrEmpty(name))
                {
                    dependency.Context.User.Id = name;
                }
                telemetry.TrackDependency(dependency );

@TimothyMothra TimothyMothra added this to the 2.5.1 milestone Feb 21, 2018
@older
Copy link
Author

older commented Feb 21, 2018

I meant you won't see the problem with requests because in this case I have no control over the way requests are reported.

Thanks for the workaround, will try it tomorrow.

@TimothyMothra
Copy link
Member

Today we released Microsoft.ApplicationInsights (v2.5.1) and Microsoft.ApplicationInsights.Web (v2.5.1) with this fix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants