Populate DependencyTelemetry with Operation Data for Initializers by michaelwstark · Pull Request #897 · microsoft/ApplicationInsights-dotnet-server

michaelwstark · 2018-04-26T05:59:38Z

Fix Issue # .
[Consolidated]
#900

[Original]
#820
#747
#587

Populate DependencyTelemetry with operation data for initializers.

I ran Unit Tests locally.

For significant contributions please make sure you have completed the following items:

Changes in public surface reviewed
Design discussion issue # Support adding arbitrary HTTP response headers from dependencies #587
CHANGELOG.md updated with one line description of the fix, and a link to the original issue.
The PR will trigger build, unit tests, and functional tests automatically. If your PR was submitted from fork - mention one of committers to initiate the build for you.
If you want to to re-run the build/tests, the easiest way is to simply Close and Re-Open this same PR. (Just click 'close pull request' followed by 'open pull request' buttons at the bottom of the PR)
Please follow [these] (https://github.com/Microsoft/ApplicationInsights-dotnet-server/blob/develop/CONTRIBUTING.md) instructions to build and test locally.

…ights-dotnet-server into develop

michaelwstark · 2018-04-26T06:00:45Z

I assume there is a change to the core SDK nuget package required, but as that hasn't been built yet, I just worked with the update locally. If there is a better processor for changes which modify both, please point me in the right direction -- appreciated.

lmolkova

Thanks for the PR and all the tests, overall looks great!

I have a concern here regarding duplication in the OperationDetails dictionary.

http response and headers should be mutually exclusive: in most of the cases reponse is available. the case where only headers are available is corener case and an ugly workaround.
It seems Sql connection is avaialble through the command.

lmolkova · 2018-04-26T16:49:29Z

Src/DependencyCollector/Shared/HttpCoreDiagnosticSourceListener.cs

            {
                this.ParseResponse(response, telemetry);
+                telemetry.OperationDetails[RemoteDependencyConstants.HttpResponseOperationDetailName] = response;
+                telemetry.OperationDetails[RemoteDependencyConstants.HttpResponseHeadersOperationDetailName] = response.Headers;


why do we need to populate response AND headers? I'd prefer them to be mutually exclusive.
In case of .NET Core there is no case when a response is missing, but headers are present

That was actually how I originally had it (until I hit the corner case where the response was not present). My rationale for always including them was to make development of a initializer easier -- if the developer is only interested in headers, headers is always populated. This is not a stance of principal or conviction -- you are much more familiar with what the developer experience of the initializers should be, so I will defer to you. Please ack that you would prefer to only have the headers when the response is not available and I will make the change after I finish an update on the SDK pull request.

I hear your concern. I consider the scenario as very advanced and rare. And within this scenario case when a response is not available is rare itself. Making it convenient for a very small subset of users should come with a lowest possible performance impact even if it makes usage a bit less convenient.

So yes, I would prefer to have headers only when a response is not available.

lmolkova · 2018-04-26T16:56:11Z

...ncyCollector/Shared/Implementation/SqlClientDiagnostics/SqlClientDiagnosticSourceListener.cs

+                            telemetry.OperationDetails[RemoteDependencyConstants.SqlCommandOperationDetailName] = command;
+                            if (connection != null)
+                            {
+                                telemetry.OperationDetails[RemoteDependencyConstants.SqlConnectionOperationDetailName] = connection;


The connection is available through the command, why do we need to explicitly add it to the dictionary?

Similar rationale as the response\headers comment above. I was not sure that the command would always be populated based on the failure cases, and I wanted to make it easier to develop the initializer if someone was only interested in properties on the connection. I will wait for confirmation on the comment above, and align the two to be consistent.

lmolkova · 2018-04-26T17:12:42Z

@anpete
Could you please help us review these SQL dependency collection changes?

Our goal is to enable scenario when users add arbitrary dynamic properties to their dependency telemetry. In HTTP case it could be adding request or response header value to the telemetry.

Could you please help us understand whether it is relevant for SQL and what kind of information could be useful/not useful.

Basically, we proxy DiagnostiSource payload to users through telemetry instance (but this info is not serialized and is never sent to the backend as it). It's up to users to access these objects and modify telemetry based on them.

This is a very advanced scenario we don't expect the absolute majority of users to implement.

cijothomas

Would like to have a 'flag' to turn this feature on/off if customer desires so, since some people may find the additional memory consumption not worth..
something like https://github.com/Microsoft/ApplicationInsights-dotnet-server/blob/develop/Src/DependencyCollector/Shared/DependencyTrackingTelemetryModule.cs#L57.

I have added couple other comments as well.

cijothomas · 2018-04-27T20:39:51Z

...ncyCollector/Shared/Implementation/SqlClientDiagnostics/SqlClientDiagnosticSourceListener.cs

                                Target = string.Join(" | ", connection.DataSource, connection.Database),
                                Data = operation,
-                                Success = true
+                                Success = true,


intentional?

Not intentional, but it is a coding style from my projects. I'll remove the trailing comma when we hear back regarding the feature flag.

cijothomas · 2018-04-27T20:43:29Z

...ncyCollector/Shared/Implementation/SqlClientDiagnostics/SqlClientDiagnosticSourceListener.cs

-
+
+                            // Populate the operation details for intializers
+                            telemetry.SetOperationDetail(RemoteDependencyConstants.SqlCommandOperationDetailName, command);


need similar change here as well:
https://github.com/Microsoft/ApplicationInsights-dotnet-server/blob/develop/Src/DependencyCollector/Shared/Implementation/ProfilerSqlProcessingBase.cs
This contains SQL dependency collection logic with Profiler installed.

cijothomas · 2018-04-27T20:49:38Z

CHANGELOG.md


 ## Version 2.7.0-beta1
 - [Added support to collect Perf Counters for .NET Core Apps if running inside Azure WebApps] (https://github.com/Microsoft/ApplicationInsights-dotnet-server/issues/889)
+- [Add operation details for HTTP and SQL operation to the dependency telemetry.](https://github.com/Microsoft/ApplicationInsights-dotnet-server/issues/587)


If possible create a new issue in gh, which contain detail about the specific fix. The original issue is quite long discussion, and it'll be hard to figure out which part from that is being implemented here.

Also helpful if an example TelemetryInitializer can be provided which utilizes this new feature.

@cijothomas - Did you want the sample to be checked in somewhere and included in this PR, or inline in the new issue you were requesting on GitHub?

Either is fine. Inline in a GH issue is easier to find as it's linked from release notes.

K. I'll code up a sample as I was intending to use this feature and include it in a new GH issue.

Here is a consolidated issue with a code sample for intended use:
#900

cijothomas · 2018-04-27T21:13:53Z

@SergeyKanzhelev and @Dmitry-Matveev - Please share your thoughts on making this under a feature flag, and having them OFF by default. I'd assume that this is only useful if customer has their own telemetry initializer which makes use of this. Those customers can turn this feature ON, so regular users dont see increased memory usage from AI SDK.

michaelwstark · 2018-04-27T23:38:33Z

@cijothomas - While we are waiting for @SergeyKanzhelev and @Dmitry-Matveev to respond to whether this needs to be placed under a feature flag, can you point me to a current example? I presume it would be something similar to ExcludeComponentCorrelationHttpHeadersOnDomains or IncludeDiagnosticSourceActivities on the current dependency collection module, but am not completely sure.

cijothomas · 2018-04-30T17:41:43Z

@michaelwstark Yes you are pretty close. More relevant example is DisableDiagnosticSourceInstrumentation flag on DependencyTrackingTelemetryModule which turns on/off DiagnosticSource based dependency tracking.
https://github.com/Microsoft/ApplicationInsights-dotnet-server/blob/develop/Src/DependencyCollector/Shared/DependencyTrackingTelemetryModule.cs#L57

michaelwstark · 2018-04-30T23:37:33Z

Thanks for the pointer. I will create a branch off of my current working code with this change in anticipation of @SergeyKanzhelev or @Dmitry-Matveev indicating that we should include a flag for this behavior.

lmolkova · 2018-05-01T01:18:52Z

@cijothomas
I believe the reason you are proposing the feature flag is making sure it does not break users not interested in this or it's easy to disable if it is broken.

However, this feature does not look risky: DependencyTelemetry has a new property that is just assigned to something we have validated. It will be safely ignored by existing users.
Users would need to write code to use the feature, they do not gain anything by default, i.e. it is de-facto disabled by default.

I could not see what can go wrong here and why we'd wan't to disable this feature.

lmolkova · 2018-05-01T01:27:18Z

Those customers can turn this feature ON, so regular users dont see increased memory usage from AI SDK.

There should be no increase in memory usage. The new properties DependencyTelemetry gets already present in the memory and are cleaned up after dependency call is finished.

E.g. in case of HTTP we add Http request and Http response - there are no new allocations, except for dictionary with 2 items.

lmolkova · 2018-05-01T01:44:24Z

@michaelwstark

we discussed it with @cijothomas offline.
The concern is that the feature would postpone GC for the requests/responses since reference would be kept in dependency telemetry until it is sent to the backend (that happens asynchronously).

I wonder, can we clean up the OperationDetails in TrackDependency call after initialize is called to address this concern?

Here

        public void TrackDependency(DependencyTelemetry telemetry)
        {
            if (telemetry == null)
            {
                telemetry = new DependencyTelemetry();
            }

            this.Track(telemetry);

!!!         telemetry.OperationDetails.Clear();
        }

It totally makes sense to me, as Track happens syncronously with dependency call and request/response should not be accessed after that.

Dmitry-Matveev · 2018-05-02T01:14:00Z

@michaelwstark, I'm with Cijo on this one - due to increased memory usage for default scenario, I'd suggest to make this feature opt-in rather than on by default. Performant apps (let's say 500+ RPS) may all of a sudden become less performant if we store all request/responses/headers for 30 seconds (15000 * 3 objects). Super-performant apps (1000+ RPS) may struggle even if we come up with some optimization to release object sooner - it will still exist more than ASP.NET intended it to.
Making this opt-in will require a switch or flag that you are discussing with Cijo already.

michaelwstark · 2018-05-02T01:16:55Z

@Dmitry-Matveev - Just wanting to confirm -- so the ask is to clear the captured objects on Track() as well as add a feature opt-in?

lmolkova · 2018-05-02T03:23:44Z

@Dmitry-Matveev @michaelwstark
I do think having both: clean up AND feature flag is an overkill. If no additional references exist after dependency is tracked, there is nothing to protect from by feature flag.

lmolkova · 2018-05-02T18:30:27Z

Chatted with @Dmitry-Matveev offline (he had to run for a meeting so cannot reply right now).
He is fine with the approach when we clean up details immediately after tracking telemetry (sync with response events). He agrees that in this case feature flag is not needed.

Dmitry-Matveev · 2018-05-02T21:06:09Z

Thanks, @lmolkova! @michaelwstark, in case we do not copy nor keep response/request objects after the request is over - we are good without the feature flag.

michaelwstark · 2018-05-02T23:08:35Z

@Dmitry-Matveev Thanks! @lmolkova - I think that all of the outstanding feedback has been resolved, please let me know what else needs to be done prior to merging these PRs into their respective repos. I noticed there are some VSTS checks which never provide any feedback -- anything I need to do there?

cijothomas · 2018-05-02T23:52:30Z

@michaelwstark thanks for addressing the suggestions!
The VSTS checks are for CI Builds, which are not auto-triggered for forked repo pull requests. I'll manually trigger them for you and if all tests pass, we are good.
The changes in base SDK need to be first merged and published before the changes in this repo can be merged. I will start in base sdk build trigger first.

cijothomas · 2018-05-03T00:00:17Z

@MS-TimothyMothra to ensure this is merged AFTER base 2.7.0-beta1 is published to myget.

updated changelog to reflect that this is expected to go in 2.7 Beta2

TimothyMothra · 2018-05-08T00:51:53Z

Sorry, I misunderstood and prep-ed this for Beta2.
Reverted my change.

michaelwstark · 2018-05-25T18:20:59Z

@MS-TimothyMothra has the Beta1 of the core SDK been published to myget? When do we expect this PR to merge? Thanks in advance.

TimothyMothra · 2018-05-25T18:35:47Z

Sorry @michaelwstark, the 2.7 Beta1 got delayed to June 1st because we're working on hotfixes for 2.6 Stable.
Feel free to contact me directly if you need more information

TimothyMothra · 2018-06-05T17:54:20Z

@michaelwstark It looks like some of your new tests are failing.

TestZeroAndNonZeroContentResponseDiagnosticSource
TestBasicDependencyCollectionDiagnosticSourceLegacyHeaders

Will you have time to look at these today?

michaelwstark · 2018-06-05T17:57:17Z

@MS-TimothyMothra. Yup. I'll be able to take a look today.

lmolkova · 2018-06-05T18:14:09Z

I've added these two recently:

TestZeroAndNonZeroContentResponseDiagnosticSource
TestBasicDependencyCollectionDiagnosticSourceLegacyHeaders

Probably failures are result of auto-merge and new tests are missing something.

michaelwstark · 2018-06-05T18:27:31Z

One test is a negative case for response, and the validate call requires hint not to validate response data. The other leveraged a new Boolean value in the validate pipeline which was not named which conflicted with the one I added. Re-running unit tests after the update and will push shortly if they pass.

…nInsights-dotnet-server into develop

michaelwstark · 2018-06-05T18:34:51Z

@MS-TimothyMothra you should be good to proceed now. Let me know if you hit any more issues.

TimothyMothra · 2018-06-05T18:35:16Z

Thanks @michaelwstark ! Queuing your build now.

michaelwstark added 3 commits April 25, 2018 20:45

Track Operation Details Within DependencyCollector

33c7459

mend

63b7b4e

Merge branch 'develop' of https://github.com/Microsoft/ApplicationIns…

821aa14

…ights-dotnet-server into develop

lmolkova suggested changes Apr 26, 2018

View reviewed changes

Update OperationDetails tracking to align with SDK update

1056f67

lmolkova approved these changes Apr 27, 2018

View reviewed changes

cijothomas suggested changes Apr 27, 2018

View reviewed changes

lmolkova mentioned this pull request May 1, 2018

Add OperationDetails object bag to DependencyTelemtry for Initializers microsoft/ApplicationInsights-dotnet#788

Merged

5 tasks

michaelwstark mentioned this pull request May 1, 2018

Enable Access to Dependency Request Objects in DependencyCollector #900

Closed

michaelwstark added 2 commits May 1, 2018 16:46

Merge remote-tracking branch 'upstream/develop' into develop

cccdb95

Call TrackDependency() Instead of Track()

8ad5a81

michaelwstark added 2 commits May 1, 2018 18:20

Update TestCases to Handle Call to Clear() on Track()

0837053

Capture Sql Commands Uniformly

bfc514a

Update CHANGELOG.md with consolidated issue reference

0574972

cijothomas approved these changes May 2, 2018

View reviewed changes

Merge branch 'develop' into develop

c03d502

TimothyMothra added this to the 2.7-Beta2 milestone May 8, 2018

Update CHANGELOG.md

ab06be3

updated changelog to reflect that this is expected to go in 2.7 Beta2

TimothyMothra modified the milestones: 2.7-Beta2, 2.7-Beta1 May 8, 2018

moving this back to Beta1

e5ed54a

Merge branch 'develop' into develop

8d117ae

Merge branch 'develop' into develop

cc41176

michaelwstark added 2 commits June 5, 2018 11:32

Fix Dependency Operation Unit Test Validation After Upstream Merge

10feb68

Merge branch 'develop' of https://github.com/michaelwstark/Applicatio…

ab427cd

…nInsights-dotnet-server into develop

TimothyMothra merged commit 6308371 into microsoft:develop Jun 5, 2018

IanKemp mentioned this pull request Dec 4, 2019

DependencyTelemetry.TryGetOperationDetail isn't as helpful as it could be microsoft/ApplicationInsights-dotnet#1350

Closed



		// Populate the operation details for intializers
		telemetry.SetOperationDetail(RemoteDependencyConstants.SqlCommandOperationDetailName, command);

Conversation

michaelwstark commented Apr 26, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

michaelwstark commented Apr 26, 2018

Uh oh!

lmolkova left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

lmolkova commented Apr 26, 2018

Uh oh!

cijothomas left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

cijothomas Apr 30, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

cijothomas commented Apr 27, 2018

Uh oh!

michaelwstark commented Apr 27, 2018

Uh oh!

cijothomas commented Apr 30, 2018

Uh oh!

michaelwstark commented Apr 30, 2018

Uh oh!

lmolkova commented May 1, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

lmolkova commented May 1, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

lmolkova commented May 1, 2018

Uh oh!

Dmitry-Matveev commented May 2, 2018

Uh oh!

michaelwstark commented May 2, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

lmolkova commented May 2, 2018

Uh oh!

lmolkova commented May 2, 2018

Uh oh!

Dmitry-Matveev commented May 2, 2018

Uh oh!

michaelwstark commented May 2, 2018

Uh oh!

cijothomas commented May 2, 2018

Uh oh!

cijothomas commented May 3, 2018

Uh oh!

TimothyMothra commented May 8, 2018

Uh oh!

michaelwstark commented Apr 26, 2018 •

edited

Loading

cijothomas left a comment •

edited

Loading

cijothomas Apr 30, 2018 •

edited

Loading

lmolkova commented May 1, 2018 •

edited

Loading

lmolkova commented May 1, 2018 •

edited

Loading

michaelwstark commented May 2, 2018 •

edited

Loading