Elastic APM plus MS Application Insights spamms Logs in .net Core 2.1 Web App

Kibana version: 7.5 on premise

Elasticsearch version: 7.5 on premise

APM Server version: 7.5 on premise

APM Agent language and version: Elastic.Apm.NetCoreAll - 1.3

Browser version: Chrome - newest

Original install method (e.g. download page, yum, deb, from source, etc.) and version: NuGet

Fresh install or upgraded from other version? Fresh Install

Is there anything special in your setup? Nothing special about the APM Server

Description of the problem including expected versus actual behavior. Please include screenshots (if relevant):

We are using Elastic Apm and MS Apllication Insight in our .Net Core MVC Projects. Just this morning we noticed, that Application insights starts spamming the Consol with message. These message are send to Azure and fill up our cloud storage. At first we thought this might happen becouse of older NuGet Versions of AppInsight or the Elastic.Apm we are using. After updating these packages the problem still persists. We tryed another application wich is not using Application Insight but log's into a file. In the file we see this entrys.


image
This pointed me to the Kibana part of the apm-server.yml configuration. I updated the apm-server.yml but we do still see these error's been spammed. Is there an error in the apm-server configuration?

Application Insight Errors in console:
A few secounds after starting the .net core web app you can see lots of App Insight events.
image
image
The Console LogLine seems to point at Elastic.Apm

"data":{
"baseType":"MessageData",
"baseData":{
"ver":2,
"message":"{HttpDiagnosticListenerImplBase} Failed capturing request (failed to remove from ProcessingRequests) - This Span will be skipped in case it wasn't captured before. Request: method: POST, URL: https://dc.services.visualstudio.com/v2/track",
"severityLevel":"Warning",
"properties":{
"RequestUrl":"https://dc.services.visualstudio.com/v2/track",
"AspNetCoreEnvironment":"Development",
"Scope":"HttpDiagnosticListenerImplBase",
"HttpMethod":"POST",
"DeveloperMode":"true",
"CategoryName":"Elastic.Apm",
"{OriginalFormat}":"{{{Scope}}} Failed capturing request (failed to remove from ProcessingRequests) - This Span will be skipped in case it wasn't captured before. Request: method: {HttpMethod}, URL: {RequestUrl}"
}
}
}
}

Hi @marcus.labohm,

so, overall these requests are for a new feature that query the server for remote configuration. Here is more info on it - probably you already found that doc.

I also see you already configured the APM Server and everything for this functionality - is that right?

There is one interesting thing in your logs - there are the logs from CentralConfigFetched for the HTTP request with response forbidden with URL .../config/v1/agents?service.name=... - that's when the agent queries the server for configs, but it's not enabled in the server, so that's why it fails with 403.

But then you say you updated apm-server.yml, and in the logs after that I only see the HttpDiagnosticListenerImplBase warning with Failed capturing request..., so no info about the HTTP request to .../config/v1/agents?service.name=....

Is that right? Is that message (the one with CentralConfigFetched) gone after you configured the server?

Asking because there is another thread here with these warnings, and I suspect these two could be related and may have something to do with this remote configuration feature.

Hi @GregKalapos, thanks for your fast response.

Sorry i did'nt see the other thread :frowning:
After restarting the apm-server i get the following message in the logs and still get this messages.

[WRN] {HttpDiagnosticListenerImplBase} Failed capturing request (failed to remove from ProcessingRequests) - This Span will be skipped in case it wasn't captured before.

My configuration does not seem to work.
Both apm-server and kibana are running on the same server and the ip is correct. 10.17.113.6
image
The filelog looks like this now

2020-02-19 13:14:12.912 +01:00 [ERR] {CentralConfigFetcher} Exception was thrown while fetching configuration from APM Server and parsing it. ETag: <null>'. URL: "http://10.17.113.6:8200/config/v1/agents?service.name=DokumentProduktion&service.environment=Development"'. Apm Server base URL: "[http://10.17.113.6:8200/"'](http://10.17.113.6:8200/%22%27). WaitInterval: 5m. dbgIterationsCount: 35. +-> Request: Method: GET, RequestUri: '[http://10.17.113.6:8200/config/v1/agents?service.name=DokumentProduktion&service.environment=Development'](http://10.17.113.6:8200/config/v1/agents?service.name=DokumentProduktion&service.environment=Development%27), Version: 2.0, Content: <null>, Headers: { User-Agent: elasticapm-dotnet/1.2 User-Agent: System.Net.Http/4.6.27129.04 User-Agent: .NET_Core/2.1.7 Request-Id: |537eab8b-4946cafcfd44cfb3. } +-> Response: N/A +-> Response body [length: N/A]: N/A System.Net.Http.HttpRequestException: Ein Verbindungsversuch ist fehlgeschlagen, da die Gegenstelle nach einer bestimmten Zeitspanne nicht richtig reagiert hat, oder die hergestellte Verbindung war fehlerhaft, da der verbundene Host nicht reagiert hat ---> System.Net.Sockets.SocketException: Ein Verbindungsversuch ist fehlgeschlagen, da die Gegenstelle nach einer bestimmten Zeitspanne nicht richtig reagiert hat, oder die hergestellte Verbindung war fehlerhaft, da der verbundene Host nicht reagiert hat at System.Net.Http.ConnectHelper.ConnectAsync(String host, Int32 port, CancellationToken cancellationToken) --- End of inner exception stack trace --- at System.Net.Http.ConnectHelper.ConnectAsync(String host, Int32 port, CancellationToken cancellationToken) at System.Threading.Tasks.ValueTask1.get_Result()
at System.Net.Http.HttpConnectionPool.CreateConnectionAsync(HttpRequestMessage request, CancellationToken cancellationToken)
at System.Threading.Tasks.ValueTask1.get_Result() at System.Net.Http.HttpConnectionPool.WaitForCreatedConnectionAsync(ValueTask1 creationTask)
at System.Threading.Tasks.ValueTask1.get_Result() at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken) at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) at System.Net.Http.DiagnosticsHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) at System.Net.Http.HttpClient.FinishSendAsyncBuffered(Task1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
at Elastic.Apm.BackendComm.CentralConfigFetcher.FetchConfigHttpResponseImplAsync(HttpRequestMessage httpRequest)
at Elastic.Apm.Helpers.AgentTimerExtensions.TryAwaitOrTimeout(IAgentTimer agentTimer, Task taskToAwait, AgentTimeInstant until, CancellationToken cancellationToken)
at Elastic.Apm.Helpers.AgentTimerExtensions.TryAwaitOrTimeout[TResult](IAgentTimer agentTimer, Task1 taskToAwait, AgentTimeInstant until, CancellationToken cancellationToken) at Elastic.Apm.Helpers.AgentTimerExtensions.AwaitOrTimeout[TResult](IAgentTimer agentTimer, Task1 taskToAwait, AgentTimeInstant until, CancellationToken cancellationToken)
at Elastic.Apm.BackendComm.CentralConfigFetcher.FetchConfigHttpResponseAsync(HttpRequestMessage httpRequest)
at Elastic.Apm.BackendComm.CentralConfigFetcher.WorkLoopIteration()

@GregKalapos after checking the apm-server configuration again i found the problem. The configuration was wrong and the apm-server was not running at all. Now with the corret configuration the server is running and the log files are looking a lot better :slight_smile:
The MS Application Insight log is also a lot cleaner.

So to sum up the solution:

apm-server Config for kibana was wrong.
App Insight was the default log provider in the c# .net core mvc app and kept logging the apm-agent warning to azure.

Thank you Marcus for the info.

Nice, so the CentralConfigFetcher log is in my opinion valid, and I'd say the agent correctly logged that.

Nevertheless I looked into the other logs with HttpDiagnosticListenerImplBase} Failed capturing request (failed to remove from ProcessingRequests). These were troubling to me, because these are warnings.

If your log level is Error then you won't see it, but if you set it to Warning or lower, then these will still show up.

I already have a reproducer locally and some info here: https://github.com/elastic/apm-agent-dotnet/issues/734

Greg

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.