Does locking for EventSource.DoCommand need to be a global lock?

[benaadams]

On startup FrameworkEventSource and RuntimeEventSource; while running on different threads, contend on EventSource.Initialize waiting for the DoCommand of the other to complete, so run sequentially (intermixed), also PortableThreadPoolEventSource and ArrayPoolEventSource:

/cc @stephentoub

Related to #44598

[Dotnet-GitSync-Bot]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[benaadams]

Also PortableThreadPoolEventSource and ArrayPoolEventSource can collide forcing sequential initialization and waits on alternative threads

[benaadams]

[benaadams]

InitializeProviderMetadata and CreateManifestAndDescriptors look to be the problematic methods called under a global lock as they are very reflection heavy

[josalem]

To be clear, you're talking about the EventListenerLock?

runtime/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs

Lines 1488 to 1493 in 78adc93

	// Register the provider with EventPipe
	var eventPipeProvider = new OverideEventProvider(this, EventProviderType.EventPipe);
	lock (EventListener.EventListenersLock)
	{
	eventPipeProvider.Register(this);
	}

runtime/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs

Lines 1536 to 1548 in 78adc93

	lock (EventListener.EventListenersLock)
	{
	// If there are any deferred commands, we can do them now.
	// This is the most likely place for exceptions to happen.
	// Note that we are NOT resetting m_deferredCommands to NULL here,
	// We are giving for EventHandler<EventCommandEventArgs> that will be attached later
	EventCommandEventArgs? deferredCommands = m_deferredCommands;
	while (deferredCommands != null)
	{
	DoCommand(deferredCommands); // This can never throw, it catches them and reports the errors.
	deferredCommands = deferredCommands.nextCommand;
	}
	}

The lock is used for registration of providers with the EventPipe, EventListener, and EventSource infrastructure. The generation of the manifest and descriptors isn't concurrency sensitive as far as I can recall. Theoretically, we could always separate that generation step from the registration to minimize time under the lock. The issue is that we shouldn't attempt to do that generation until we know the source is going to be used, which is what leads to it being done on registration.

runtime/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs

Line 2603 in 78adc93

EnsureDescriptorsInitialized();

The generation logic seems like a prime candidate for source generation at compile time.

That being said, there should only be deferred commands for an EventSource (the trigger for calling DoCommand under a lock in Initialize) if it is requested to be enabled before Initialize in its constructor is called. If you don't enable those providers, you shouldn't pay the penalty for generating their manifest/descriptors on construction or get into this serialization situation. Are you enabling those providers when you collect this data?

CC @sywhang @noahfalk

[benaadams]

PortableThreadPoolEventSource always seems to have a couple updates to send (on Windows) even if I'm just running at command line (added a Console.WriteLine to check) /cc @kouvel

That causes the manifest to be generated; and its generation uses ArrayPool, which calls ArrayPoolEventSource.Log to check if its enabled which then causes initialization of the ArrayPoolEventSource which blocks because it needs the same EventListenersLock lock that the DoCommands in the other Initalize is using which is what you see here:

EventSource.Initalize does grab and release the global EventListenersLock lock 3 times:

1. For eventPipeProvider.Register(this);
2. Inside EventListener.AddEventSource(this);
3. For handling the deferredCommands (which then triggers the lengthy Manifest generation)

[josalem]

Cases 1 and 2 shouldn't be too expensive, but 3 certainly can be due to the reflection required to generate the data.

I find it curious that these providers have deferred commands without being explicitly enabled. Do you observe this on non-Windows platforms? I'm wondering if ETW requests the manifest for all providers that register themselves. That would cause case 3 to fire every time for every EventSource on Windows even if the source isn't enabled by the user.

[josalem]

Another thought: That UI looks like dotTrace. It's possible that dotTrace specifically uses the ThreadPool event source.