autofac / Autofac

An addictive .NET IoC container
https://autofac.org
MIT License
4.44k stars 836 forks source link

DiagnosticSource `Event` and `WriteEvent` parameter mismatch #1382

Closed tillig closed 1 year ago

tillig commented 1 year ago

Describe the Bug

It's unclear if this is something Autofac can fix but it seems reasonable to look into.

Based on this StackOverflow question, it appears a WPF app targeting .NET 4.7.2 with diagnostics enabled is throwing an exception with this message whenever Resolve is called:

The parameters to the Event method do not match the parameters to the WriteEvent method. This may cause the event to be displayed incorrectly.

Steps to Reproduce

I'm not sure how to replicate the issue - the original person asking the question can't replicate it outside of this specific app, which may mean there is something hooked to the DiagnosticSource that is executing during that FilterAndTransform stage causing the mismatch.

I know we've also seen trouble in the past with full .NET Framework not being fully netstandard compatible, I wonder if this could be one of those places.

Expected Behavior

Exception with Stack Trace

DiagnosticSourceEventSource.Event() at C:\Users\gael\AppData\Roaming\JetBrains\Rider2023.1\resharper-host\SourcesCache\5525318ba2913ce58be271c55cfb2f2dd9c0982e1f8234fb78d859d7b1d997c\DiagnosticSourceEventSource.cs:line 214
DiagnosticSourceEventSource.FilterAndTransform.<>c__DisplayClass2_1.<.ctor>b__2() at C:\Users\gael\AppData\Roaming\JetBrains\Rider2023.1\resharper-host\SourcesCache\5525318ba2913ce58be271c55cfb2f2dd9c0982e1f8234fb78d859d7b1d997c\DiagnosticSourceEventSource.cs:line 617
DiagnosticSourceEventSource.CallbackObserver<KeyValuePair<string, object>>.OnNext()
DiagnosticListener.Write()
DiagnosticSourceExtensions.OperationStart()
ResolveOperation.ExecuteOperation()
ResolveOperation.Execute()
LifetimeScope.ResolveComponent()
Container.ResolveComponent()
ResolutionExtensions.TryResolveService()
ResolutionExtensions.ResolveService()
ResolutionExtensions.Resolve()

Dependency Versions

Autofac: 7.0.1

Additional Info

Original requestor is @valhentai - unclear if there's more to add here, perhaps some application-specific information about the way diagnostics are set up in the app.

tillig commented 1 year ago

I found the source for DiagnosticSourceEventSource that I think corresponds to System.Diagnostics.DiagnosticSource v4.7.1 (released 5/12/2020), which is what we're referencing in Autofac. There is a lot of interesting conditional code in there. There have been a ton of changes since that drop and it may be worth taking an upgrade in Autofac to ensure a better experience, though I'm not sure if it'd fix this.

@valhentai, does your project specifically reference System.Diagnostics.DiagonosticSource? Can you tell what version you're using?

tillig commented 1 year ago

Per the comment thread in that SO question, there was a listener for HTTP requests running that was somehow also attached to the Autofac diagnostic source, trying to output both event types. Without more info on the setup I can't suggest a concrete fix, but the gist here is that the wrong listener was subscribed to Autofac events.

I'm going to close this as not an Autofac problem. Is someone comes up with a specific bug and repro, open a new issue and include the repro so we can look into it.

sakennedy commented 7 months ago

I have also documented the same issue here: https://stackoverflow.com/questions/75993176/asp-net-site-generates-hundreds-duplicate-messages-the-parameters-to-the-event

The problem for my team is that the call to the 'DiagnosticSourceEventSource.FilterAndTransform' originates from an 'EtwCommand' of some unknown origin. I cannot see the call stack passed this method and many of the arguments are not visible from the debugger (though not sure if that would even help). At this time we have no idea why this call is triggered.

This single call however results in a severe drop in performance as every Autofac interaction results in a call to the 'DiagnosticSourceEventSource' which synchronously writes the same message to 'Debug.Log'.

From our point of view Autofac is the only consumer of the 'DiagnosticSourceEventSource'. It would be great if there was an option to opt-out of 'Autofac' using 'DiagnosticSourceEventSource'.

At the moment we must use the following hack to work around:

`var diagnosticsLib = Assembly.Load("System.Diagnostics.DiagnosticSource, Version=4.0.5.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51"); var diagnosticSourceEventSourceType = diagnosticsLib.GetType("System.Diagnostics.DiagnosticSourceEventSource"); object diagnosticSourceEventSource = diagnosticSourceEventSourceType.InvokeMember("Logger", BindingFlags.Static | BindingFlags.GetField | BindingFlags.Public, null, null, null);

if (diagnosticSourceEventSource is IDisposable disposable) disposable.Dispose();`

fubar-coder commented 7 months ago

For System.Diagnostics.DiagnosticSource 8.0.0, you have to change the code from:

var diagnosticsLib = Assembly.Load("System.Diagnostics.DiagnosticSource, Version=4.0.5.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51");
var diagnosticSourceEventSourceType = diagnosticsLib.GetType("System.Diagnostics.DiagnosticSourceEventSource");
object diagnosticSourceEventSource = diagnosticSourceEventSourceType.InvokeMember("Logger", BindingFlags.Static | BindingFlags.GetField | BindingFlags.Public, null, null, null);

if (diagnosticSourceEventSource is IDisposable disposable) disposable.Dispose();

to:

var diagnosticsLib = Assembly.Load("System.Diagnostics.DiagnosticSource, Version=8.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51");
var diagnosticSourceEventSourceType = diagnosticsLib.GetType("System.Diagnostics.DiagnosticSourceEventSource");
object diagnosticSourceEventSource = diagnosticSourceEventSourceType.InvokeMember("Log", BindingFlags.Static | BindingFlags.GetField | BindingFlags.Public, null, null, null);

if (diagnosticSourceEventSource is IDisposable disposable) disposable.Dispose();

The assembly version changed and the internal field was renamed from Logger to Log.

SeanWilliamson2004 commented 5 months ago

I work with Rider and for the last 12 months or so I've been battling slow container building or resolution when debugging that seemed to be around a resource mapping exception in the Debugger.Log call in

private void LogEventArgsMismatches(ParameterInfo[] infos, object[] args) { bool flag = args.Length == infos.Length; for (int index = 0; flag && index < args.Length; ++index) { Type parameterType = infos[index].ParameterType; if (args[index] != null && args[index].GetType() != parameterType || args[index] == null && (!parameterType.IsGenericType || !(parameterType.GetGenericTypeDefinition() == typeof (Nullable<>)))) { flag = false; break; } } if (flag) return; Debugger.Log(0, (string) null, Environment.GetResourceString("EventSource_VarArgsParameterMismatch") + "\r\n"); }

This morning, I noticed a flood of messages in my Debug Output: "The parameters to the Event method do not match the parameters to the WriteEvent method. This may cause the event to be displayed incorrectly." akennedy's workaround seems to get rid of this message, and I think it's dealt with the container loading issue as well, so thanks for that. I use Autofac 6.4. I think I can't move to 7 or above, but I would have to revisit the reasons why.