Listener for events from SqlClient for .Net Framework #704
Conversation
There was a problem hiding this comment.
Thanks @vhatsura, great progress here!
I merged the net46 PR into the Elastic.Apm.Test project, so you can rebase this PR on master, with that the Elastic.Apm.SqlClient.Tests test should also compile.
try to enable instrumentation engine and check SQL command text
I think the situation here is that Application Insights has a feature that is based on byte code instrumentation and they simply inject code into the SqlClient library to access the CommandText - so I assume it's not like they turn on anything, so the SqlClient and related classes emit more diagnostic data, instead they inject byte code into the library to access the data.
Unfortunately, it's not possible to capture command text with an event listener.
I saw a couple of fixes around this and I got this working with "Microsoft.Data.SqlClient" Version="1.1.1".
One is this - I assume this will be also included in newer System.Data.SqlClient releases.
| @@ -9,13 +10,20 @@ public class SqlClientDiagnosticSubscriber : IDiagnosticsSubscriber | |||
| public IDisposable Subscribe(IApmAgent agentComponents) | |||
| { | |||
| var retVal = new CompositeDisposable(); | |||
| var initializer = new DiagnosticInitializer(agentComponents.Logger, new[] { new SqlClientDiagnosticListener(agentComponents) }); | |||
| if (PlatformDetection.IsDotNetCore) | |||
There was a problem hiding this comment.
Are we totally sure about this? I tried to research and understand this and this seems to be correct, but is it always the case that on Full Framework all SqlClient versions emit through EventListener and on .NET Core through DiagnosticSource?
Do you know anything about this?
There was a problem hiding this comment.
So, what I see in ApplicationInsights repo. EventListener is used only in net45 target. DiagnosticSource is used in both - net45 and netstandard as well as for HttpClient.
As I understand correctly the comment
// NET45 referencing .net core System.Net.Http supports diagnostic listener
it's possible to reference .Net Core version of HttpClient in .Net Framework. If it's so, it can be also possible to do it with SqlClient. In such case, we need to listen DiagnosticSource in .Net Framework too. I've played around it a little bit but without any success. Maybe you have any clue how it's possible.
There was a problem hiding this comment.
I see, thanks for the info.
Well, to me that comment in the AI code is a but cryptic :) I know that HttpClient was updated outside the framework with a NuGet pacakge - maybe that's what they mean by "referencing .NET Core System.Net.Http" - I suspect that package was built from the prior CoreFX repo - same for .NET Core.
There isn't really such thing for SqlClient (unless you manually copy assemblies) - or actually Microsoft.Data.SqlClient would be similar, but that seems to use EventListener on Full Framework - which surprised me - I though it'd use DiagnosticSource on both.
Is that maybe why Application Insights subscribe to DiagnosticSource on both? I was unable to get DiagnosticSource out of this on Full Framework.
Nevertheless this is I'd say a minor thing. I think the current code is fine - if someone runs into a situation where we don't turn on the right stuff we can easily find that this is the root cause and we can adapt this part of the code.
What do you think? Keep it as it is?
There was a problem hiding this comment.
I know that HttpClient was updated outside the framework with a NuGet pacakge - maybe that's what they mean by "referencing .NET Core System.Net.Http"
I also thought so, however, when I tried to do it, there was loaded usual NetFx version of HttpClient.
I though it'd use DiagnosticSource on both
As I understand correctly, DiagnoticSource is built-in in .Net Core runtime, and as for .Net Framework, it can be added only from the NuGet package. It seems it's one of the main reasons, why DiagnosticSource isn't widely used in .Net Framework.
What do you think? Keep it as it is?
I suggest keeping it as is, at least for now.
test/Elastic.Apm.SqlClient.Tests/Elastic.Apm.SqlClient.Tests.csproj
Outdated
Show resolved
Hide resolved
|
|
||
| protected override void OnEventSourceCreated(EventSource eventSource) | ||
| { | ||
| if (eventSource != null && eventSource.Name == "Microsoft-AdoNet-SystemData") |
There was a problem hiding this comment.
I saw some strange behavior around here. The OnEventSourceCreated method got triggered twice for me resulting with the following Paylaod in the OnEventWritten method:
[0] = "ERROR: Exception in Command Processing for EventSource Microsoft-AdoNet-SystemData: An instance of EventSource with Guid 6a4dfe53-eb50-5332-8473-7b7e10a94fd1 already exists."
So, in the OnEventWritten we never did anything since the payload was not something we expect there.
My hack to make that work was to disable the eventsource and enable it again - I don't know why this happens and I don't really like this code - I'm not sure what should be the solution here.
if (eventSource != null && eventSource.Name == "Microsoft-AdoNet-SystemData")
{
if (_eventSource != null)
{
DisableEvents(_eventSource);
_eventSource.Dispose();
}
EnableEvents(eventSource, EventLevel.Informational, (EventKeywords)1);
_eventSource = eventSource;
}
(_eventSource is a field on SqlEventListener)
One suspect is that both System.Data and Microsoft.Data triggers this.
There was a problem hiding this comment.
Thanks for your findings. I'll look deeper into it.
There was a problem hiding this comment.
@gregkalapos, your assumption is right. There are 2 event sources with the same GUIDs (GUID is generated based on event source name), one from System.Data.SqlClient and another one from Microsoft.Data.SqlClient.
This is the exact place where the exception is thrown: https://github.com/microsoft/referencesource/blob/08b84d13e81cfdbd769a557b368539aac6a9cb30/mscorlib/system/diagnostics/eventing/eventsource.cs#L3029-L3033
With this place, it's understandable why disposing of previous event source help to solve the issue, however, it's quite unstable, sometimes it doesn't help.
I've created an issue in Microsoft.Data.SqlClient repo. Will look, maybe they have a proper solution.
For now, I suggest keeping it as is with small hacking for our tests because I don't think that a lot of people use both libraries in one application (maybe I'm wrong). WDYT?
There was a problem hiding this comment.
I suggest keeping it as is with small hacking for our tests because I don't think that a lot of people use both libraries in one application
Yes, I agree that the point of this discussion is not a very "real world" scenario - I don't think either people would have both in 1 app.
On the other hand - what's the small hack for the tests? Did you already push something for this? 🤔 Currently the tests on full framework fail to me due to this problem.
There was a problem hiding this comment.
Yes, I haven't committed the hack yet. An idea is pretty simple. As SqlEventSource initializes statically the only one possible approach is to have three solutions. One with a base abstract class which will have test definitions, another one with referencing System.Data.SqlClient and the last one with Microsoft.Data.SqlClient.
I know, it's not a very good solution, but we will have it until version 2.0.0 released with a fix for event source name
There was a problem hiding this comment.
@gregkalapos, I tried to implement solution with 3 projects but it also doesn't work. The issue is the SqlEventSource for System.Data.SqlClient is situated in the System.Data assembly. It means that SqlEventSource is always instantiated even if we don't reference System.Data.SqlClient.
So, my final suggestion (I believe) is to skip instrumentation for Microsoft.Data.SqlClient in .Net Framework. WDYT?
There was a problem hiding this comment.
So, my final suggestion (I believe) is to skip instrumentation for Microsoft.Data.SqlClient in .Net Framework. WDYT?
Ok, fine by me.
Overall, I think having 3 projects wouldn't even be a hack, more like a legitimate solution - it's unfortunate that it does not work.
Anyways, let's skip it for Full Framework and see if someone needs it in the future.
Thanks for opening the issue in the SqClient repo.
Nice to have the response there, but having yet another name in the future (as the comment says) makes this thing super complicated - anyways this is outside our control, so we use whatever they offer...
There was a problem hiding this comment.
but having yet another name in the future (as the comment says) makes this thing super complicated
Yes, if it had added from the first release of Microsoft.Data.SqlClient, it would have been simpler to integrate with it as it was done for SQL clients in .Net Core. I want to believe the contracts for events between two SQL clients will be the same
|
|
||
| protected override void OnEventSourceCreated(EventSource eventSource) | ||
| { | ||
| if (eventSource != null && eventSource.Name == "Microsoft-AdoNet-SystemData") |
There was a problem hiding this comment.
I suggest keeping it as is with small hacking for our tests because I don't think that a lot of people use both libraries in one application
Yes, I agree that the point of this discussion is not a very "real world" scenario - I don't think either people would have both in 1 app.
On the other hand - what's the small hack for the tests? Did you already push something for this? 🤔 Currently the tests on full framework fail to me due to this problem.
|
Oh, and I think we'll also need |
I moved reference to |
Cool, nice 👍 . We have new test fails in CI: Also, I'm not totally sure this project properly runs in |
Yes, I see that only tests from
I finally found the place, where I can see test failures. I tried to fix it but I need to restart CI from you |
I'll make sure the CI runs for your changes now - I'll take a look at the remaining stuff later. |
solves #700
documentation will be added in scope of #702
What needs to be done:
System.Data.SQLiteandMicrosoft.Data.Sqlitedon't spread events via EventSource, however, does it means that other providers also don't do it? Can we setSubtypeproperty of span tomssql?Unfortunately, it's not possible to capture command text with an event listener. It's possible to do it with instrumentation engine, however, it seems in such case command text is captured from another place (I've checked command text in the payload with enabled instrumentation engine and hosting in IIS, no luck):
Capture span representation:
{ "_index": "apm-7.5.2-span-000001", "_type": "_doc", "_id": "n25DJnABZF4_3hDy4m6U", "_version": 1, "_score": null, "_source": { "parent": { "id": "128e06672de0f0bb" }, "observer": { "hostname": "ad6e0ae55174", "id": "a6272462-6b0f-4b04-9081-08f05f8037dc", "type": "apm-server", "ephemeral_id": "4ea50d25-d305-4afb-a034-3a903da8bbd4", "version": "7.5.2", "version_major": 7 }, "agent": { "name": "dotnet", "version": "1.2" }, "trace": { "id": "4ed85f88e65ae40377fc1161cb094ebe" }, "@timestamp": "2020-02-08T19:25:38.752Z", "ecs": { "version": "1.1.0" }, "service": { "name": "WebApplication1" }, "processor": { "name": "transaction", "event": "span" }, "transaction": { "id": "128e06672de0f0bb" }, "timestamp": { "us": 1581189938752426 }, "span": { "duration": { "us": 92956 }, "name": "model", "id": "a5d61d8d6c16b1e5", "type": "db", "db": { "instance": "model", "statement": "", "type": "sql" } } }, "fields": { "@timestamp": [ "2020-02-08T19:25:38.752Z" ] }, "highlight": { "span.id": [ "@kibana-highlighted-field@a5d61d8d6c16b1e5@/kibana-highlighted-field@" ] }, "sort": [ 1581189938752 ] }