Dependency calls not being logged by App Insights when being performed as part of a Polly retry #1923
Comments
|
I am experiencing a very similar error. The setup is similar to how @guysteel has set it up above. On retries, I do not see a dependency call being logged in app insights. I know the retries are happening because I see the info logs that I am writing within the retry policy handler. The packages/SDK I am using are: |
|
The retry calls will likely not be captured if the retries are transparent to the caller. ApplicationInsights collects httpcalls by subscribing to the DiagnosticSource events emitted by a DiagnosticHandler in the HttpClient. If the retry is happening without going through the full pipeline of handlers (esp DiagnosticHandler), then the retries will not be captured by ApplicationInsights. Don't think I can suggest a workaround at this stage, as the DiagnosticHandler is part of the HttpClient itself, so you may/may not have the ability to make sure it is called when using the Polly package to do the retry. |
|
@cijothomas I tried the same scenario but with an older version of our service. Basically, I checked out an older branch of my service and ran the same scenario. In app insights I can see the following: I know these are my retry calls, as there are no other services running in this environment at the moment, and I can see from the timestamp that the calls are due to the exponential backoff algorithm I have configured for Polly. .Net Core SDK 2.2.0 So it appears that this behaviour was available earlier but has since changed for some reason. My app insights config is as follows: My app insights config has not changed with my new version, except that now we configure the connection string instead of the instrumentation key and of course we use the newer packages which I mentioned in my earlier message. |
|
Also, Application Insights seem to log exceptions handled by Polly
|
In the ExceptionTelemetry, what is the SDKVersion field value. |
|
@cijothomas SDK Version is |
|
@pzbyszynski Ok. For functions, you need to raise this issue in https://github.com/Azure/azure-webjobs-sdk repo. Functions + ApplicationInsights integration is in that repo. (But if you see same behaviour outside of functions, let us know right here, we can help) |
|
@cijothomas Any update on the original question? I had posted some tests that I did in the message below:
|
|
@karun-verghese Is the only thing different is the SDK version,? need to double confirm this, as you said "checked out older branch of your service". (From what I see, in .Net core, we always relied on DiagnosticSource callbacks to collect http dependency. In very old versions esp. .NET Framework, there were alternate options to collect http calls) |
|
@cijothomas @guysteel I have invited you to be collaborators on a small repo that I set up to investigate this issue. The repo is simple: The configuration for Polly and App insights can be found in the Startup class and is exactly the same as we have in our actual services. On the branch 'OldSDK', I performed the same tests with the following setup: The tests performed are as follows: The isOperable endpoint intentionally calls a non-existing 'dependent api' which is a variation of some publicly available dummy test api's that I found in the following git repo: https://github.com/public-apis/public-apis#animals. Thus, the expected status code is a 404(Not Found) The test is very simple and has just 3 steps:
When I run the test for the latest SDK and packages I see the following in my logs:
When I run the test for the Old 2.2 SDK with the old Polly and App Insights packages I see the following:
The app insights instance I am pointing to is a private instance I created. As you can see, with a really stripped down service with nothing except the app insights and polly configuration, the behaviour is the same as reported earlier. With the old SDK I see the dependencies being logged for the retries. But with the latest .Net Core SDK that functionality has stopped working. |
|
@cijothomas I also gave this a try with the new .Net 5 SDK and packages. It's the same behaviour as described above. The configuration is as follows: |
|
There is no special handling in .NET5 which I am aware of, which would help with this issue. |
|
I came across the same (or very similar?) issue. Running in Azure Functions v3 (netcore 3.1) Some of the calls to an external API fail (usually time out after the 30 sec.). They are correctly retried by Polly. But AppInsights does not log another dependency call: I would expect that the retry call shows up as another dependency. The SDK version on the dependency telemetry is recorded as |
|
Any updates? |
|
Dear all, It's been a long time since we've had any update on this issue? Has any investigation been done on this? We even provided a minimal repo (as asked) for you guys to investigate. Looking forward to hearing from you guys. Thanks. |
|
We experience the original issue described with the following versions: |
|
We experience the same behaviour: It is disappointing to read through this thread, see the complete reproducible example and full detail provided by @karun-verghese and then the complete silence afterwards. |
|
We experience the same behavior with Polly version 3.1.13 and Azure functions 3.0.13. |
|
#2556 same/duplicate issue. |
@cijothomas Should this be be a runtime bug then? Perhaps they can reorder the DiagnosticHandler? This issue combined with #2556 makes DependencyTelemetry pretty useless when there's retry involved. |
|
We experience the same behavior: Any new on resolving it? |
|
Is there anyone who has found a workaround on this? Wrapping retries somehow and manually generating dependency telemetry? |
We do it using services.AddTransient<ApplicationInsightsPayloadTracerHandler>();
services
.AddHttpClient(..)
.AddPolicyHandler(..)
.AddHttpMessageHandler<ApplicationInsightsPayloadTracerHandler>();The custom public class ApplicationInsightsPayloadTracerHandler : DelegatingHandler
{
private readonly IServiceProvider _serviceProvider;
private readonly ILogger<ApplicationInsightsPayloadTracerHandler> _logger;
public ApplicationInsightsPayloadTracerHandler(...) { ... }
protected override async Task<HttpResponseMessage> SendAsync(
HttpRequestMessage request,
CancellationToken cancellationToken)
{
HttpResponseMessage response = null;
var requestTimestamp = DateTime.UtcNow;
try
{
response = await base.SendAsync(request, cancellationToken);
}
finally
{
await TraceDependencyAsync(request, response, requestTimestamp);
}
return response;
}
private async Task TraceDependencyAsync(
HttpRequestMessage request,
HttpResponseMessage response,
DateTimeOffset traceTimestamp)
{
string traceCorrelationId = ActivityTraceHelper.BuildTraceCorrelationId();
await TraceRequestAsync(request, traceCorrelationId, traceTimestamp);
await TraceResponseAsync(request, response, traceCorrelationId);
}
private async Task TraceRequestAsync(
HttpRequestMessage request,
string traceCorrelationId,
DateTimeOffset traceTimestamp)
{
try
{
using var requestScope = _serviceProvider.CreateScope();
var telemetryClient = requestScope.ServiceProvider.GetRequiredService<TelemetryClient>();
...
var requestTelemetry = new TraceTelemetry
{
SeverityLevel = SeverityLevel.Verbose,
Timestamp = traceTimestamp,
};
requestTelemetry.Properties.Add("TraceCorrelationId", traceCorrelationId);
// log headers, status code, etc.
telemetryClient.TrackTrace(requestTelemetry);
}
catch (Exception ex) { }
}
private async Task TraceResponseAsync(...)
{
// very likely as above
}
}Note: To get request headers, use With this setup if the first attemp fails, Polly triggers the retry that will end up in this handler again, so the request will be logged twice. |
Describe your environment. Describe any aspect of your environment relevant to the problem:
Since upgrading from v2.8.2, when using Polly to retry a failing Http request automatically only the first failing call to the dependency is being logged. Subsequent dependency calls are no longer appear to be logged.
Steps to reproduce.
In ConfigureServices - configure app insights and setup a named http client:
In Configure add a failing call to demonstrate the behaviour:
What is the expected behavior?
I would expect each call to the failing endpoint to be logged as a separate dependency call.
What is the actual behavior?
I see only a single dependency call logged - the initial call. In the previous version of App Insights all of the calls were being logged.
Additional context.
The above uses Polly 3.1.3
The text was updated successfully, but these errors were encountered: