search

microsoft / ApplicationInsights-dotnet

ApplicationInsights-dotnet
MIT License
567 stars 285 forks source link

How to find the source of "TelemetryChannel found a telemetry item without an InstrumentationKey" #2070

Open rnarayana opened 3 years ago

rnarayana commented 3 years ago 
Microsoft.ApplicationInsights Version="2.15.0"
Microsoft.ApplicationInsights.AspNetCore Version="2.15.0"
Microsoft.ApplicationInsights.Kubernetes Version="1.1.2"
Microsoft.ApplicationInsights.NLogTarget Version="2.15.0"

What are you trying to achieve? Almost all the telemetry comes through properly, but I still get the trace "AI: TelemetryChannel found a telemetry item without an InstrumentationKey. This is a required field and must be set in either your config file or at application startup." at regular intervals The key is set as the first step in ConfigureServices() itself in Startup.cs:

        public void ConfigureServices(IServiceCollection services)
        {
            var appInsightsKey = this.appConfig.GetConfig("App:ApplicationInsightsKey"); // Get my key
            services.AddAppInsights("LISTENER", appInsightsKey); // See extension method below
            services.AddControllers();
            ....
        }

        public static void AddAppInsights(this IServiceCollection services, string cloudRoleName,
            string instrumentationKey)
        {
            services.AddSingleton<ITelemetryInitializer>(new CloudRoleNameInitializer(cloudRoleName));
            services.AddApplicationInsightsTelemetry(o =>
            {
                o.InstrumentationKey = instrumentationKey;
                o.EnableAdaptiveSampling = false;
            });
            services.ConfigureTelemetryModule<DependencyTrackingTelemetryModule>((module, o) =>
            {
                module.EnableSqlCommandTextInstrumentation = true;
            });
            services.AddApplicationInsightsTelemetryProcessor<HealthCheckExclusionFilter>();
            services.AddApplicationInsightsTelemetryProcessor<CustomPropertyFilter>();
            services.AddApplicationInsightsKubernetesEnricher();
        }

What have you tried so far? I tried adding a TelemetryProcessor to try and inspect each item and figure out this, but did not get any leads.

cijothomas commented 3 years ago

Can you share the full code showing how you enabled ApplicationInsights? Its not clear which nuget package you are using, and which code snippet is being used. Without seeing them, its not possible to give any useful response.

rnarayana commented 3 years ago

My bad, I've updated the question with details. I thought adding the appinsights telemetry at the very beginning would make the key available everywhere, and am unable to track the intermittent error about not finding the key.

poveilleux commented 3 years ago

@rnarayana I have updated to v2.15.0 last night and I've started to see this problem happening. It is really hard to find the source, but I did not have the problem with v2.14.0, so I'll just revert to get back my telemetry

rnarayana commented 3 years ago

@poveilleux Are you also on kubernetes?

poveilleux commented 3 years ago

@rnarayana I am, but I don't see how this would be related.

cijothomas commented 3 years ago

@rnarayana Are you facing this issue only when deploying to AKS ? Are you able to seeing telemetry flowing correctly without issues when running locally?

rnarayana commented 3 years ago

@cijothomas I see this issue when deploying to kuberentes (AKS and non-AKS). Note that I have all my other telemetry flowing in correctly, but this one particular message keeps coming in at exactly 15 minutes apart. I've checked multiple services, and in every service, this entry is there, every 15 minutes. I have run locally in Debug mode for more than 15 mins, but did not see this issue.

image

cijothomas commented 3 years ago

@rnarayana The 15 min interval hints that this may have something to do with Heartbeat module..Can you check if you have heartbeats flowing for the app in aks/local? Heartbeats would be a "customMetric" with the name "heartbeat".

Also, if possible, can isolate the issue to particular version. Specifically - please confirm if you have repro with 2.15 only, or its repro in 2.14 as well? (There were changes in heartbeat modules in 2.15, so we want to narrow the scope down further to quickly reach the root cause). Appreciate your patience!

rnarayana commented 3 years ago

I can confirm that the following two methods get rid of this issue:

  1. Use version 2.14 and set key via AddApplicationInsightsTelemetry().
  2. Use version 2.15, but set APPINSIGHTS_INSTRUMENTATIONKEY env. var instead of setting the key via AddApplicationInsightsTelemetry()
vladislav-karamfilov commented 3 years ago

We encountered the described issue in a SF stateless ASP.NET Core service that is using the Microsoft.ApplicationInsights.AspNetCore v2.15.0 package. We have a lot of logs of this type.

We have noticed 1 more thing that might be a different issue but might be related to this one. Some of the Trace logs have provider name <undefined>. These logs are duplicated with logs that have the correct provider name set but this is still cluttering our logs.

vladislav-karamfilov commented 3 years ago

We encountered the described issue in a SF stateless ASP.NET Core service that is using the Microsoft.ApplicationInsights.AspNetCore v2.15.0 package. We have a lot of logs of this type.

We have noticed 1 more thing that might be a different issue but might be related to this one. Some of the Trace logs have provider name <undefined>. These logs are duplicated with logs that have the correct provider name set but this is still cluttering our logs.

Reverting back to v2.14.0 as @poveilleux suggested in 1 of the above comments fixes the AI: TelemetryChannel found a telemetry item without an InstrumentationKey. This is a required field and must be set in either your config file or at application startup. issue for us too. The issue with <undefined> provider name still persists.

cijothomas commented 3 years ago

Thanks everyone for reporting the issue. This would be a regression from 2.14, most likelyt in the heartbeat area. Wil investigate and provide fix.

yehiasalam commented 3 years ago

im getting the same problem, reverted to 2.14.0 and everything worked

rajkumar-rangaraj commented 3 years ago

@rnarayana, I started investigating this issue, but could not recreate in my environment. Adding the code as in issue description did not recreate an issue. I see a note stating issue does not get recreated in debug environment. Is it reproducible only in AKS? Could you please provide the steps the recreate an issue, this will help us investigate this issue faster.

Also it could help if you can provide below data.

cijothomas commented 3 years ago

We haven't fixed this yet, which means this won't be part of 2.16.

Will continue to get to the root cause for this, and will do 2.15.1 release for this, if this is confirmed to be a regression introduced by 2.15. (Similarly, it'll be part of 2.16.1 release as well)

2.16 cannot be delayed, as its a release done just to pick DiagnosticSource package version update to 5.0, which is releasing tomorrow.

rnarayana commented 3 years ago

@rnarayana, I started investigating this issue, but could not recreate in my environment. Adding the code as in issue description did not recreate an issue. I see a note stating issue does not get recreated in debug environment. Is it reproducible only in AKS? Could you please provide the steps the recreate an issue, this will help us investigate this issue faster.

Also it could help if you can provide below data.

* Do you see the heart beat information logged in the failure case. If so, could you please provide the heart beat data. Heartbeat information gets logged into CustomMetrics table with the name - `HeartbeatState`

I'll send full repro by this weekend.

rnarayana commented 3 years ago

I've uploaded the repro here Steps:

  1. Replace everything that says REPLACE_THIS
  2. Build project.
  3. Build docker
  4. Deploy helm to AKS.
  5. Wait for 30 minutes, check appinsights.
mmulhearn commented 3 years ago

My team is also seeing this on Microsoft.ApplicationInsights.AspNetCore 2.15.0 and we are trying to determine the cause as we have 1 API service exhibiting the issue and 3 that are not.

It's a very weird issue. If this is the issue, that the key isn't there, why is the iKey field filled in and correct? How are we also seeing legitimate logs next to it (for instance, in the middle of the items with the issue, we see a log telling us that one of our dependency requests was unsuccessful)?

Definitely sounds like a red herring to whatever the real issue is. At this point, we're pulling back slight configuration differences between the working and not working APIs to see if we can determine the cause.

mmulhearn commented 3 years ago

As we started to peel away, we found that removing this configuration from our api app in Azure fixed the issue, and re-adding it re-introduced the issue.

{
    "name": "ApplicationInsightsAgent_EXTENSION_VERSION",
    "value": "~2",
    "slotSetting": true
  }
mmulhearn commented 3 years ago

It would appear this configuration change causes the issue on a resource that is not currently exhibiting it:

This caused the issue in our QA environment resource that was not previous exhibiting the issue.

mmulhearn commented 3 years ago

We have confirmed that Interop with Application Insights SDK (preview) is the issue, not the ApplicationInsightsAgent_EXTENSION_VERSION configuration.

rajkumar-rangaraj commented 3 years ago

@rnarayana Thanks for the repro, it helped investigate an issue.

Workaround for this issue is to set EnableActiveTelemetryConfigurationSetup to true in ApplicationInsightsServiceOptions. For example,

services.AddApplicationInsightsTelemetry(o =>
{
     o.InstrumentationKey = instrumentationKey;
     o.EnableAdaptiveSampling = false;
     o.EnableActiveTelemetryConfigurationSetup = true;
});

Please note that still duplicate heartbeat is sent every 15 minutes and above proposed change will ensure that the duplicate heartbeat has InstrumentationKey and won't generate internal trace message.

Root Cause Microsoft.ApplicationInsights.NLogTarget package is creating an additional TelemetryConfiguration with HeartbeatProvider module registered. This causes two heartbeats to flow every 15 minutes instead of one. We will work on a fix to prevent the duplicate heartbeat. Please use the workaround to avoid internal trace message being logged in your component.

cijothomas commented 3 years ago

We have confirmed that Interop with Application Insights SDK (preview) is the issue, not the ApplicationInsightsAgent_EXTENSION_VERSION configuration.

Hi, for any issues with the Azure Web App monitoring, please raise support ticket, as the codeless components are not opensourced. This repo is only for SDK related issues.

AroglDarthu commented 3 years ago

Will you make a fix available for 2.17.x? Just noticed that the issue has not been resolved in 2.17.0

We are experiencing the same issue. It is really annoying, mainly because developers do not notice anything is off when they only updated the package with a newer minor version. Also, if you just add Application Insights to a new application now, by default you will be referencing a faulty version :-(

Might want to re-add the P1 label (assuming that is the highest prio).

iamalexmang commented 3 years ago

Confirmed - I am seeing this issue in our pre-production workload too. Do we have any updates?

heinrichgh commented 3 years ago

Any updates whether this will go into a minor release as a fix? (I notice that this has been removed from the 2.17 milestones and not been added to any other milestones)

rnarayana commented 3 years ago

@rnarayana Thanks for the repro, it helped investigate an issue.

Workaround for this issue is to set EnableActiveTelemetryConfigurationSetup to true in ApplicationInsightsServiceOptions. For example,

services.AddApplicationInsightsTelemetry(o =>
{
     o.InstrumentationKey = instrumentationKey;
     o.EnableAdaptiveSampling = false;
     o.EnableActiveTelemetryConfigurationSetup = true;
});

Please note that still duplicate heartbeat is sent every 15 minutes and above proposed change will ensure that the duplicate heartbeat has InstrumentationKey and won't generate internal trace message.

Root Cause Microsoft.ApplicationInsights.NLogTarget package is creating an additional TelemetryConfiguration with HeartbeatProvider module registered. This causes two heartbeats to flow every 15 minutes instead of one. We will work on a fix to prevent the duplicate heartbeat. Please use the workaround to avoid internal trace message being logged in your component.

Has this workaround stopped working in 2.17 for anyone? I'm starting to see "TelemetryChannel found a telemetry item without an InstrumentationKey" again on upgrading to 2.17

adrien-constant commented 3 years ago

The workaround doesn't work for me either. This is problematic since I have many services, it spams the logs all the time.

Using .NET 5.0 and 

    <PackageReference Include="Microsoft.ApplicationInsights.AspNetCore" Version="2.17.0" />
    <PackageReference Include="Microsoft.ApplicationInsights.Kubernetes" Version="1.1.4" />
    <PackageReference Include="Microsoft.ApplicationInsights.PerfCounterCollector" Version="2.17.0" />
RobK410 commented 3 years ago

There's only a couple of places where this error is logged, tracing back through, InMemoryChannel is one of those points.

perhaps this code in TelemetrySink.cs is the culprit?

this.telemetryChannel = new InMemoryChannel { EndpointAddress = telemetryConfiguration.EndpointContainer.FormattedIngestionEndpoint, };

I don't see the key being set anywhere here, and looks like blame shows some insight into what happened.

Perhaps the key here could be passed to TelemetrySink constructor and onto the InMemoryChannel.

bNobo commented 3 years ago

I have added EnableActiveTelemetryConfigurationSetup as indicated and the workaround works perfectly.

Here how I do it:

Add an ApplicationInsights section in appsettings.json

"ApplicationInsights": {
    "InstrumentationKey": "<add_instrumentation_key_here>",
    "DeveloperMode": false,
    "EnableRequestTrackingTelemetryModule": true,
    "EnableAdaptiveSampling": true,
    "EnableActiveTelemetryConfigurationSetup": true
  }

And load it with:

services.AddApplicationInsightsTelemetry(
                options => 
                    _configuration
                        .GetSection("ApplicationInsights")
                        .Bind(options)
            );

Now I have no more "AI: TelemetryChannel found a telemetry item without an InstrumentationKey." messages in traces.

eriksteinebach commented 3 years ago

Seeing the same message, but in our case it is in a netcore webjob project.

We are using the following code to setup Application Insights:

            var environment = configuration.GetEnvironment();
            var instrumentationKey = configuration.GetInstrumentationKey();
            builder.ConfigureLogging((context, loggingBuilder) =>
            {
                loggingBuilder.AddApplicationInsightsWebJobs(o =>
                {
                    o.InstrumentationKey = instrumentationKey;
                    o.EnableLiveMetrics = true;
                    o.SamplingExcludedTypes = "Exception";
                });
            });

Because it is not a aspnet project I don't have EnableActiveTelemetryConfigurationSetup available as a workaround. Any idea how to solve it in our case?

AroglDarthu commented 3 years ago

@cijothomas Any thoughts on a possible due date for the bugfix?

Will you make a fix available for 2.17.x? Just noticed that the issue has not been resolved in 2.17.0

We are experiencing the same issue. It is really annoying, mainly because developers do not notice anything is off when they only updated the package with a newer minor version. Also, if you just add Application Insights to a new application now, by default you will be referencing a faulty version :-(

Might want to re-add the P1 label (assuming that is the highest prio).

jhubsharp commented 2 years ago

We're seeing this same behavior in an Azure Function where we've added Application Insights to the logging path.

Here's where we've wired up AppInisghts to our logger: builder.Services.AddLogging(logBuilder => { logBuilder.AddApplicationInsights(); });

Here's what the configuration in host.json looks like:

{
  "version": "2.0",
  "logging": {
    "logLevel": {
      "default": "Information"
    },
    "applicationInsights": {
      "samplingSettings": {
        "isEnabled": false
      },
      "enableDependencyTracking": true,
      "dependencyTrackingOptions": { "enableSqlCommandTextInstrumentation": true }
    }
  }
}

We've got older function apps on .NET Core 3.1 that aren't having this problem. I've only seen it on our .NET 6.0 functions. We have both an APPINSIGHTS_INSTRUMENTATIONKEY and an APPLICATIONINSIGHTS_CONNECTION_STRING in the function configuration.

TimothyMothra commented 2 years ago

Has anyone experienced this issue using just the SDK? (ie. not using a logging adapter such as NLog or Log4Net.)

cijothomas commented 2 years ago

We're seeing this same behavior in an Azure Function where we've added Application Insights to the logging path.

Here's where we've wired up AppInisghts to our logger: builder.Services.AddLogging(logBuilder => { logBuilder.AddApplicationInsights(); });

Here's what the configuration in host.json looks like:

{
  "version": "2.0",
  "logging": {
    "logLevel": {
      "default": "Information"
    },
    "applicationInsights": {
      "samplingSettings": {
        "isEnabled": false
      },
      "enableDependencyTracking": true,
      "dependencyTrackingOptions": { "enableSqlCommandTextInstrumentation": true }
    }
  }
}

We've got older function apps on .NET Core 3.1 that aren't having this problem. I've only seen it on our .NET 6.0 functions. We have both an APPINSIGHTS_INSTRUMENTATIONKEY and an APPLICATIONINSIGHTS_CONNECTION_STRING in the function configuration.

I dont think it is supported to do AddApplicationInsights() in AzureFunctions, as Functions already wire up Application Insights, and adding again would cause incorrect configs.

Marusyk commented 2 years ago

I have the same issue with .NET6

<PackageReference Include="Microsoft.ApplicationInsights.AspNetCore" Version="2.17.0" />
<PackageReference Include="Microsoft.ApplicationInsights.WorkerService" Version="2.17.0" />

then

string instrumentationKey = context.Configuration["Logging:ApplicationInsights:InstrumentationKey"];
if (isWorker)
{
    services.AddApplicationInsightsTelemetryWorkerService(instrumentationKey);
}
else
{
    services.AddApplicationInsightsTelemetry(instrumentationKey);
}

image

Danieladu commented 2 years ago

@cijothomas Any updates on this? Thanks!

cijothomas commented 2 years ago

@cijothomas Any updates on this? Thanks!

The only update I have is that, based on https://github.com/microsoft/ApplicationInsights-dotnet/issues/2070#issuecomment-733227455, this issue is occurring when using LoggingAdapters (except ILogger), in .NET Core. It'd be helpful if anyone has a repro outside of this. (And in case of logging adapters, the workaround is as posted in the above comment. There are no plans to make the logging adapters integrate better with DI/ASP.NET Core.)

Danieladu commented 2 years ago

@cijothomas Any updates on this? Thanks!

The only update I have is that, based on #2070 (comment), this issue is occurring when using LoggingAdapters (except ILogger), in .NET Core. It'd be helpful if anyone has a repro outside of this. (And in case of logging adapters, the workaround is as posted in the above comment. There are no plans to make the logging adapters integrate better with DI/ASP.NET Core.)

Thanks for the quick reply!

alsami commented 2 years ago

@cijothomas Any updates on this? Thanks!

The only update I have is that, based on #2070 (comment), this issue is occurring when using LoggingAdapters (except ILogger), in .NET Core. It'd be helpful if anyone has a repro outside of this. (And in case of logging adapters, the workaround is as posted in the above comment. There are no plans to make the logging adapters integrate better with DI/ASP.NET Core.)

We have the same problem with one service that is running on-premise that uses Serilog. Funny thing is, that it does not happen for services that run on Azure. Weird issue tbh.

Danieladu commented 2 years ago

@cijothomas Any updates on this? Thanks!

The only update I have is that, based on #2070 (comment), this issue is occurring when using LoggingAdapters (except ILogger), in .NET Core. It'd be helpful if anyone has a repro outside of this. (And in case of logging adapters, the workaround is as posted in the above comment. There are no plans to make the logging adapters integrate better with DI/ASP.NET Core.)

We have the same problem with one service that is running on-premise that uses Serilog. Funny thing is, that it does not happen for services that run on Azure. Weird issue tbh.

Check your appsettings in Azure. Maybe the appservice set a default app insight key for your service.

alsami commented 2 years ago

My service is running on premise, logging to app insights. There is no app service.

flower7434 commented 1 year ago

Setting the APPINSIGHTS_INSTRUMENTATIONKEY config value solved it for me. The connection string was already set and worked. .NET6

Saibamen commented 1 year ago

Setting the APPINSIGHTS_INSTRUMENTATIONKEY config value solved it for me. The connection string was already set and worked. .NET6

@FredrikDahlberg: Adding InstrumentationKey into appsettings.json, next to ConnectionString doesn't fix this problem :(

I'm also using .NET6 app, Microsoft.ApplicationInsights.AspNetCore version 2.21.0

Saibamen commented 1 year ago

Workaround for this issue is to set EnableActiveTelemetryConfigurationSetup to true in ApplicationInsightsServiceOptions.

@rajkumar-rangaraj: Doesn't work for me

cijothomas commented 1 year ago

@Saibamen Could you share a repro app ? Its very hard to find whats wrong without seeing a repro.

Saibamen commented 1 year ago

@cijothomas: Repro app: https://github.com/Saibamen/AppInsightsTraceWarning

cijothomas commented 1 year ago

@cijothomas: Repro app: https://github.com/Saibamen/AppInsightsTraceWarning

Thanks. It looks like you are using Serilog and Serilog sink for Application Insights. Could you remove it and see if the issue repro?

Saibamen commented 1 year ago

@cijothomas: Still have this trace warning message :(

Code without Serilog is inside remove_serilog branch. You can see code changes in PR https://github.com/Saibamen/AppInsightsTraceWarning/pull/1

cijothomas commented 1 year ago

@cijothomas: Still have this trace warning message :(

Code without Serilog is inside remove_serilog branch. You can see code changes in PR Saibamen/AppInsightsTraceWarning#1

From a quick attempt, did not repro for me. Are you able to run the app locally (without docker or app service), and it still repros?