Introduce EventSource #3539

sungam3r · 2023-02-19T13:33:08Z

Helps with #3467
fixes #3540

https://learn.microsoft.com/en-us/dotnet/core/diagnostics/eventsource-getting-started

No ifdefs, no additional dependencies. Supported by all TFMs. Lightweight and cross-platform.

Trace (actually events) captured by dotnet-trace collect --providers GraphQL -p 22316:

src/GraphQL/GraphQLEventSource.cs

sungam3r · 2023-02-19T14:08:28Z

@Shane32 I think EventSource may be a sort of base tool to instrument GraphQL.NET. It's like logs (MEL) but more for more specific use cases - profiling.

sungam3r · 2023-02-19T14:10:00Z

Also by design it's 100% internal thing, so we can change everything.

Shane32 · 2023-02-19T17:24:43Z

I need to review this PR in more detail and read up on EventSource, etc.

sungam3r · 2023-02-19T17:37:05Z

For me, this is a new topic as well, I postponed the reading for a long time. The first thing to do - think about those events that we want to emit.

Shane32 · 2023-02-19T17:41:42Z

At the moment, I'm not sure I want ANY events written to my Windows Event Log, which I believe would be the default behavior. I have not tested it yet.

sungam3r · 2023-02-19T17:50:23Z

I think Windows Event Log does not work without some additional settings. EventSource is an abstraction for emitting events to any consumer.

Quick search results - https://stackoverflow.com/questions/53791076/eventsource-doesnt-write-logs-in-windows-event-viewer

Shane32 · 2023-02-19T18:13:31Z

https://learn.microsoft.com/en-us/dotnet/core/diagnostics/logging-tracing#net-logging-apis

sungam3r · 2023-02-20T07:16:56Z

Yes.

EventSource is excellent if you want tighter control over ETW or EventPipe integration

but for general purpose logging, ILogger is more flexible and easier to use

My intent here is not general purpose logging but something more focused on metrics/counters. Moreover I see that MS/others use EventSource in OTel related code.

sungam3r · 2023-02-20T11:30:42Z

I updated PR, making it closer to real needs.

sungam3r · 2023-02-20T11:33:08Z

src/GraphQL/GraphQLEventSource.cs

+/// <summary>
+/// EventSource events emitted from the project.
+/// </summary>
+[EventSource(Name = "GraphQL-NET")]


GraphQL-NET naming is from here https://learn.microsoft.com/en-us/dotnet/core/diagnostics/eventsource-instrumentation#best-practices

sungam3r · 2023-02-20T11:35:36Z

src/GraphQL/GraphQLEventSource.cs

+    {
+        if (IsEnabled(EventLevel.Error, EventKeywords.All))
+        {
+            RequestFilterException(ex.ToInvariantString());


Call IsEnabled() before performing any resource intensive work related to firing an event, such as computing an expensive event argument that won't be needed if the event is disabled.

ex.ToInvariantString() is considered as intensive work.

See OpenTelemetry.Instrumentation.AspNetCore.Implementation.AspNetCoreInstrumentationEventSource

src/GraphQL/Telemetry/GraphQLTelemetryProvider.cs

+        catch (Exception ex)
+        {
+            GraphQLEventSource.Log.RequestFilterException(ex);
            return await next(options).ConfigureAwait(false);
+        }


sungam3r · 2023-02-20T11:37:45Z

src/GraphQL/Telemetry/GraphQLTelemetryProvider.cs

-        if (!_telemetryOptions.Filter(options))
+        try
+        {
+            if (_telemetryOptions.Filter?.Invoke(options) == false)


The same approach here as in OpenTelemetry.Instrumentation.AspNetCore.Implementation.HttpInListener

Shane32 · 2023-02-20T13:21:05Z

https://learn.microsoft.com/en-us/dotnet/core/diagnostics/compare-metric-apis

Shane32 · 2023-02-20T13:31:06Z

Just a quick thought: I think we have to consider the fact that the current implementation within MS's libraries are based on older technology simply because their library is older. This does not necessarily mean it is currently recommended.

Secondly: I think we should try to prevent overlap if possible. No need to write to every historical logger / metric codebase solely because it exists, especially if the code is on-by-default.

Let's consider what would be desired for a modern library today and go from that angle. Note: these are just some initial thoughts; I still need to read up on this stuff.

Shane32 · 2023-02-20T13:41:05Z

I updated PR, making it closer to real needs.

How so? All it tracks are schema created and initialized events, which typically only occur once per application lifecycle! So far this PR seems pointless.

My intent here is not general purpose logging but something more focused on metrics/counters.

Those events are certainly not metrics.

Shane32 · 2023-02-20T13:44:09Z

Also this is not configurable as designed. Within #3467 we implemented it as opt-in so it can be configured or left disabled. Here it's built-in. Why the difference?

sungam3r · 2023-02-21T16:20:13Z

How so? All it tracks are schema created and initialized events, which typically only occur once per application lifecycle

Did you see filtering events?

sungam3r · 2023-02-21T16:24:15Z

Just a quick thought: I think we have to consider the fact that the current implementation within MS's libraries are based on older technology simply because their library is older. This does not necessarily mean it is currently recommended.

Secondly: I think we should try to prevent overlap if possible. No need to write to every historical logger / metric codebase solely because it exists, especially if the code is on-by-default.

Let's consider what would be desired for a modern library today and go from that angle. Note: these are just some initial thoughts; I still need to read up on this stuff.

I'm fine either way. In case of modern lib it will cost us one additional conditional dependency. In case of "old" EventSource it costs nothing.

Shane32 · 2023-02-21T16:25:12Z

I don't get it. Perhaps in the PR description you should state what this PR's intent is and/or what it does. I certainly would not add EventSource just to log exceptions from bad code within UseTelemetry options...????

Shane32 · 2023-02-21T16:26:21Z

I'm so pressed for time I may not have read this PR fully.

sungam3r · 2023-02-23T16:28:41Z

Also this is not configurable as designed. Within #3467 we implemented it as opt-in so it can be configured or left disabled. Here it's built-in. Why the difference?

Yes. I look at EventSource as a built-in feature. This is a more general API than OpenTelemetry and does not require additional dependencies and overhead.

I would like GraphQL.NET to provide event counters out of the box. For example, see how it was done here rabbitmq/rabbitmq-dotnet-client#1027 . To implement counters EventSource first should be created so I went this way. In addition, as you have seen, EventSource can come in handy for sending events (something like a ILogger, but not so general-purpose) in case of exceptional situations around OTel filtering and other stuff.

I found dotnet-counters tool rather usefull (and other .NET monitoring tools too) so the overall plan is:

Add EventSource as an internal entity into GrpahQL.NET
Fill it with events (1-5-10). It will take time. For now I see single event for filtration in GraphQLTelemetryProvider. Of course we can find more cases over time.
Fill it with counters. For example:
- total resolvers executed
- current executions
- total dataloaders executed
- current dataloaders
- ExecutionNode creation rate
- whatever else we want to count!

I would say that I don't look at EventSource/EventCounters as an "old" API that should be avoided. It just works and it costs nothing in terms of performance.

I certainly would not add EventSource just to log exceptions from bad code within UseTelemetry options..

Yep. Not just to log exceptions. It so happened that I presented not the main application of this tool. Its main application for me is counters. I can continue working on counters in this PR or in new one - I'm fine either way.

So the questions so far are:

Are you OK with such a feature as counters as a built-in feature of the whole lib?
Are you OK with EventSource/EventCounters as implementation?

sungam3r · 2023-02-23T16:38:40Z

@Shane32 Just googled it, see this https://github.com/dotnet/runtime/search?q=PollingCounter for reference. These are examples of counters/events in .NET runtime.

sungam3r · 2023-04-07T11:42:22Z

@Shane32 I enabled this setting

and now there are such options

codecov-commenter · 2023-04-27T15:18:01Z

Codecov Report

Merging #3539 (cf6cd75) into master (1ae26bf) will increase coverage by 0.05%.
The diff coverage is 97.05%.

📣 This organization is not using Codecov’s GitHub App Integration. We recommend you install it so Codecov can continue to function properly for your repositories. Learn more

@@            Coverage Diff             @@
##           master    #3539      +/-   ##
==========================================
+ Coverage   83.91%   83.97%   +0.05%     
==========================================
  Files         381      382       +1     
  Lines       16876    16935      +59     
  Branches     2715     2720       +5     
==========================================
+ Hits        14162    14221      +59     
  Misses       2068     2068              
  Partials      646      646

Impacted Files	Coverage Δ
src/GraphQL/BoolBox.cs	`53.84% <ø> (ø)`
src/GraphQL/Extensions/AuthorizationExtensions.cs	`59.63% <ø> (ø)`
src/GraphQL/Extensions/GraphQLExtensions.cs	`76.55% <ø> (ø)`
src/GraphQL/Introspection/ISchemaComparer.cs	`75.00% <ø> (ø)`
src/GraphQL/Resolvers/NameFieldResolver.cs	`96.77% <ø> (ø)`
...s/Composite/AutoRegisteringInputObjectGraphType.cs	`100.00% <ø> (ø)`
...pes/Composite/AutoRegisteringInterfaceGraphType.cs	`97.36% <ø> (ø)`
.../Types/Composite/AutoRegisteringObjectGraphType.cs	`100.00% <ø> (ø)`
.../Types/Scalars/Enumeration/EnumerationGraphType.cs	`94.54% <ø> (ø)`
src/GraphQL/Utilities/SchemaPrinter.cs	`85.26% <ø> (ø)`
... and 5 more

Shane32 · 2023-06-03T14:24:53Z

If we want built-in counters and etc, perhaps we should consider adding a dependency on System.Diagnostics.DiagnosticSource for v8 and using the most modern framework rather than using an outdated pattern.

sungam3r added 5 commits February 13, 2023 09:13

Introduce GraphQLEventSource

8a7b7c5

xml

feefef2

1

6fb62fa

1

788ba3f

fix

48248bc

sungam3r commented Feb 19, 2023

View reviewed changes

src/GraphQL/GraphQLEventSource.cs Show resolved Hide resolved

sungam3r requested a review from Shane32 February 19, 2023 14:03

sungam3r mentioned this pull request Feb 19, 2023

Add API for OpenTelemetry #3467

Merged

sungam3r added the enhancement New feature or request label Feb 19, 2023

sungam3r mentioned this pull request Feb 19, 2023

Catch exceptions for telemetry #3540

Open

sungam3r added 3 commits February 20, 2023 13:59

more

3fb6088

Merge branch 'master' into eventsource

2f9352a

Handle exceptions from filter

24895c4

1

3b73cc1

sungam3r commented Feb 20, 2023

View reviewed changes

github-advanced-security bot found potential problems Feb 20, 2023

View reviewed changes

src/GraphQL/Telemetry/GraphQLTelemetryProvider.cs

Comment on lines +61 to +65

catch (Exception ex)

{

GraphQLEventSource.Log.RequestFilterException(ex);

return await next(options).ConfigureAwait(false);

}

Check notice

Code scanning / CodeQL

Generic catch clause

Generic catch clause.

sungam3r commented Feb 20, 2023

View reviewed changes

sungam3r added 2 commits April 7, 2023 15:06

Merge branch 'master' into eventsource

41c51fa

Merge branch 'master' into eventsource

cf6cd75

gao-artur mentioned this pull request Dec 24, 2023

Update the GraphQLTelemetryOptions.Filter delegate to not create any downstream traces when false #3850

Merged

Uh oh!

Introduce EventSource #3539

Are you sure you want to change the base?

Introduce EventSource #3539

Uh oh!

Conversation

sungam3r commented Feb 19, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

sungam3r commented Feb 19, 2023

Uh oh!

sungam3r commented Feb 19, 2023

Uh oh!

Shane32 commented Feb 19, 2023

Uh oh!

sungam3r commented Feb 19, 2023

Uh oh!

Shane32 commented Feb 19, 2023

Uh oh!

sungam3r commented Feb 19, 2023

Uh oh!

Shane32 commented Feb 19, 2023

Uh oh!

sungam3r commented Feb 20, 2023

Uh oh!

sungam3r commented Feb 20, 2023

Uh oh!

sungam3r Feb 20, 2023

Choose a reason for hiding this comment

Uh oh!

sungam3r Feb 20, 2023

Choose a reason for hiding this comment

Uh oh!

sungam3r Feb 20, 2023

Choose a reason for hiding this comment

Uh oh!

Check notice

sungam3r Feb 20, 2023

Choose a reason for hiding this comment

Uh oh!

Shane32 commented Feb 20, 2023

Uh oh!

Shane32 commented Feb 20, 2023

Uh oh!

Shane32 commented Feb 20, 2023

Uh oh!

Shane32 commented Feb 20, 2023

Uh oh!

sungam3r commented Feb 21, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

sungam3r commented Feb 21, 2023

Uh oh!

Shane32 commented Feb 21, 2023

Uh oh!

Shane32 commented Feb 21, 2023

Uh oh!

sungam3r commented Feb 23, 2023

Uh oh!

sungam3r commented Feb 23, 2023

Uh oh!

sungam3r commented Apr 7, 2023

Uh oh!

codecov-commenter commented Apr 27, 2023

Codecov Report

Uh oh!

Shane32 commented Jun 3, 2023

Uh oh!

Uh oh!

sungam3r commented Feb 19, 2023 •

edited

Loading

sungam3r commented Feb 21, 2023 •

edited

Loading