Setting dependency telemetry timestamp to when the activity started#670
Conversation
…not when it finished
|
@billpratt, It will cover your contributions to all Microsoft-managed open source projects. |
|
@billpratt, thanks for signing the contribution license agreement. We will now validate the agreement and then the pull request. |
|
Thanks! |
|
This fixes #658 |
|
Thanks for merging. Do you have a rough idea on when this fix will get pushed? |
|
@billpratt 2.5-beta1 will be ready in a month or so (roughly, not a commitment). Meanwhile to work around this issue you can create a telemetry initializer that will rewrite the start time with end time minus duration as a workaround. |
|
@SergeyKanzhelev How would I access the end time in the initializer? |
|
end time is a current time |
|
@SergeyKanzhelev Will 2.5 be coming out soon? |
|
2.5 beta1 for Web SDK should be out in 2-3 days on nuget, followed by asp.net core sdk for application insights. |
In .NET Core 2.0, a dependency telemetry timestamp is set when the activity finished, not when it started. This PR is to set the correct timestamp.
I started to notice this when I upgraded an app to .NET Core 2.0 and looked at the telemetry data in App Insights. Below is a screenshot of a dependency that took 112ms to complete. Notice the placement dependency in the graph.
The request telemetry JSON (abbreviated)
{ "name": "Microsoft.ApplicationInsights.Dev.foo.Request", "time": "2017-08-17T20:48:03.9571942Z", "iKey": "...", "data": { "baseType": "RequestData", "baseData": { "ver": 2, "id": "...", "name": "...", "duration": "00:00:00.1258569", "success": true, "responseCode": "200" } } }The dependency telemetry JSON (abbreviated)
{ "name": "Microsoft.ApplicationInsights.Dev.foo.RemoteDependency", "time": "2017-08-17T20:48:04.0709835Z", "iKey": "...", "data": { "baseType": "RemoteDependencyData", "baseData": { "ver": 2, "name": "...", "id": "...", "data": "...", "duration": "00:00:00.1122218", "resultCode": "200", "success": true, "type": "Http (tracked component)", "target": "..." } } }If you take the difference between when the request started
2017-08-17T20:48:03.9571942Zand when the dependency is reported as started2017-08-17T20:48:04.0709835Zyou'll notice its around 112ms, which is the same value as the duration.