cijothomas
commented
8 months ago Looks like a VS specific issue. Shouldn't affect any prod scenarios, as this is only when vs/debugger is attached.
Open verdysh opened 9 months ago
cijothomas
commented
8 months ago Looks like a VS specific issue. Shouldn't affect any prod scenarios, as this is only when vs/debugger is attached.
verdysh
commented
8 months ago How is it theoretically possible that the VS debugger has such impact on some C# code if you didn't write some specific logic just for VS debugger case (which would be really weird)? Also, let me remind you that with Rider debugger attached I can't reproduce this behavior.
Shouldn't affect any prod scenarios, as this is only when vs/debugger is attached.
How can I be sure? It shouldn't affect VS debugging scenario, should it?
garrettlondon1
commented
8 months ago @cijothomas
My telemetry goes absolutely haywire in VS Code, Rider, and Visual Studio when the debugger is attached as well.
It's sending events multiple times a second even to my local sql server instance
cijothomas
commented
8 months ago @cijothomas
My telemetry goes absolutely haywire in VS Code, Rider, and Visual Studio when the debugger is attached as well.
It's sending events multiple times a second even to my local sql server instance
Can you elaborate on what is the issue you are experiencing? It's sending events multiple times a second even to my local sql server instance -- This statement is not clear.. Application Insights does not send telemetry to local sql server instance, so not sure what does this mean. The screenshot shows dependency calls captured by application insights - not able to tell what is incorrect in that screenshot. Please elaborate so we can help.
garrettlondon1
commented
8 months ago @cijothomas My telemetry goes absolutely haywire in VS Code, Rider, and Visual Studio when the debugger is attached as well. It's sending events multiple times a second even to my local sql server instance
Can you elaborate on what is the issue you are experiencing? It's sending events multiple times a second even to my local sql server instance -- This statement is not clear.. Application Insights does not send telemetry to local sql server instance, so not sure what does this mean. The screenshot shows dependency calls captured by application insights - not able to tell what is incorrect in that screenshot. Please elaborate so we can help.
Sorry, to be clear:
Application insights is capturing dependency calls between my local sql server instance and running Blazor application. Why is the frequency of dependency calls so high?
cijothomas
commented
8 months ago Application insights is capturing dependency calls between my local sql server instance and running Blazor application. Why is the frequency of dependency calls so high?
Application Insights does not dictate the frequency of dependency calls, it is merely collecting all the sql calls from your app. Can you confirm if you app is not making as many calls as captured by application insights? It is entirely possible that the app is actually making a high number of sql calls and app insights is just captured each of them!
It'll be easy if you make a minimal repro app, so we can see if there is any issue within the ApplicationInsights collection logic.
cijothomas
commented
8 months ago How is it theoretically possible that the VS debugger has such impact on some C# code if you didn't write some specific logic just for VS debugger case (which would be really weird)? Also, let me remind you that with Rider debugger attached I can't reproduce this behavior.
Shouldn't affect any prod scenarios, as this is only when vs/debugger is attached.
How can I be sure? It shouldn't affect VS debugging scenario, should it?
To be honest, I am also bit surprised, but not totally surprised. The reason being - historically, Application Insights and Visual Studio has had a very tight integration! AppInsights emits logs to a format understood by Visual Studio so it can show telemetry locally, Visual Studio had features to enable app insights sdk, AppInsights uses a "developer" mode when run inside Visual Studio and so on!. But this particular thing about EventCounter being collected every second is puzzling me as well.
If you see this is PROD, please open Azure support ticket, so someone can help you sooner. (If it is indeed a bug in app insights and has caused extra billing costs, support team should be able to help you there.)
If you are seeing this only in local runs, would you collect the logs from the SDK and narrow down the issue further:? I do have some vague memory about EventCounters going rogue, so we have added this internal log - https://github.com/microsoft/ApplicationInsights-dotnet/blob/main/WEB/Src/EventCounterCollector/EventCounterCollector/EventCounterListener.cs#L203 (I am the original author of this feature)
You can following this doc (https://learn.microsoft.com/en-us/troubleshoot/azure/azure-monitor/app-insights/asp-net-troubleshoot-no-data?source=recommendations#net-core) to enable internal log collection to a file. The log we are interested in is at Warning level, so you need to set Warning as severity, as shown below.
services.AddSingleton<ITelemetryModule, FileDiagnosticsTelemetryModule>();
services.ConfigureTelemetryModule<FileDiagnosticsTelemetryModule>((module, options) => {
module.LogFilePath = "C:\\somewhere-accessible";
module.LogFileName = "mylog.txt";
module.Severity = "Warning";
});The logs from above will confirm if EventCounters infra itself is misbehaving and emitting it every 1 sec, instead of the configured 60 secs! Once you confirm this, I can tag possible owners (owners of EventCounters itself), to help with actual fix, if any needed.
garrettlondon1
commented
8 months ago @cijothomas I will have to get back to you, but looking at my production instance of application insights:
470k dependency events in 24 hours, for a database that barely gets called.
With message {"AspNetCoreEnvironment":"Production","_MS.ProcessedByMetricExtractors":"(Name:'Dependencies', Ver:'1.1')"}
I will have to do more digging and writeup when I have free time, I apologize for the little information.
Some basics:
cijothomas
commented
8 months ago 470k dependency events in 24 hours, for a database that barely gets called
Some guesses, while we wait for further information!
Do you have sampling enabled? It is possible that the overall volume of telemetry (not the db calls), is high, causing aggressive sampling, and that can result in inflated count of database calls! If you use standard metrics and plot the count - you should see the accurate count. If sampling is indeed the issue, then you should see a much smaller number for db calls when using standard metrics, matching the actual calls your app has made.
cijothomas
commented
8 months ago 470k dependency events in 24 hours, for a database that barely gets called
Some guesses, while we wait for further information!
Do you have sampling enabled? It is possible that the overall volume of telemetry (not the db calls), is high, causing aggressive sampling, and that can result in inflated count of database calls! If you use standard metrics and plot the count - you should see the accurate count. If sampling is indeed the issue, then you should see a much smaller number for db calls when using standard metrics, matching the actual calls your app has made.
I have learned that the UI already uses standard metrics (unless you have done some filter etc. in the UI), so that count is already unaffected by sampling, and should reflect reality! I don't have any other guesses at the moment, so will wait to hear more details from you!
verdysh
commented
8 months ago @cijothomas here is the log file mylog.txt
PS. in the first post you can find a link on repo, so you can run the app locally and play with it.
cijothomas
commented
8 months ago @cijothomas here is the log file mylog.txt
PS. in the first post you can find a link on repo, so you can run the app locally and play with it.
Microsoft.ApplicationInsights.Extensibility.TraceSource Warning: 14 : EventCounter actual interval of 1.8909356594085693 secs is less than configured interval of 60 secs.
Such warnings are logged throughout, so EventCounters are fired at much higher frequency than the configured 60 secs. This confirms that the issue is in EventCounters itself.
This needs to be reported to https://github.com/dotnet/runtime/issues. You may need to provide a minimal-repro for the same. However, it is entirely possible that this won't be fixed, given the general direction of moving away from EventCounters to new Metrics API....
verdysh
commented
8 months ago Can I make Microsoft.ApplicationInsights.AspNetCore to use new Metrics API?
cijothomas
commented
8 months ago Can I make Microsoft.ApplicationInsights.AspNetCore to use new Metrics API?
No. The new metrics API is supported in OpenTelemetry based Application Insights only. It is already GA : https://learn.microsoft.com/en-us/azure/azure-monitor/app/opentelemetry-enable?tabs=aspnetcore but not at feature parity with the asp.net core package from this repo yet. But eventually, OpenTelemetry based solution will be the only supported one. If you would like, please give it a try.
garrettlondon1
commented
7 months ago @cijothomas extremely sorry for the delay here. I did some investigating and turning off dependency tracking solved the issue. Please view above Application Insights dashboard.
void AppInsightsOptions(ApplicationInsightsServiceOptions options)
{
options.ConnectionString = webApplicationBuilder.Configuration["ApplicationInsights:ConnectionString"] ?? throw new ArgumentNullException("ApplicationInsights:ConnectionString");
options.EnableDependencyTrackingTelemetryModule = false;
}
services.AddApplicationInsightsTelemetry(AppInsightsOptions);Unfortunately yes I was solving this at 3:30am :)..
Asp .NET 8 app, created from template, without anything extra. Here is it: https://github.com/verdysh/AppInsightsMetrics/ Microsoft.ApplicationInsights.AspNetCore 2.22.0 Visual Studio 17.8.6 Windows 10 It's reproduced on .NET 6 and some previous version of VS as well.
Here is how I add and configure AI:
Having code above I expect having value of
gen-0-sizecounter once per 60 seconds in all the possible cases. But it's not so in each case.If I run my app locally using VS, I have this counter every second. Here is a peace of log from VS's Output window:
You can see that this event is written every second. In my real app I have more than 1 metric and a lot of logs in Output window. It wouldn't be a problem if it didn't slowed down debugging. This slows down debugging a lot. If I turn metrics off, my debugging experience become much more better.
If I run the app (configured with connection string to AI instance) in the Azure, I have this counter once per 60 seconds in the logs.
I thought that something is wrong with my local machine. Then I decided to try running the app using Rider. If I run the app using not VS but Rider, I see the event once per second:
Why does it send events every second when I use VS? How to make it sends events once per 60s?