Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Using EventListener to listen on TplEventSource can result in a deadlock #45571

Closed
sywhang opened this issue Dec 3, 2020 · 2 comments
Closed

Using EventListener to listen on TplEventSource can result in a deadlock #45571

sywhang opened this issue Dec 3, 2020 · 2 comments
Assignees
@sywhang
Labels
area-Tracing-coreclr bug
Projects
.NET Core Diagnostics
Milestone
6.0.0

Comments

@sywhang
Copy link
Contributor

sywhang commented Dec 3, 2020

EventListener and TplEventSource with managed threadpool doesn't seem to play nicely together.

When an EventListener tries to enable TplEventSource while TplEventSource is being created, it's possible for that to deadlock with EventListnersLock + a lock within the runtime / user-defined lock in EventListener instance.

For example, a thread can try to initialize TplEventSource (which tries to grab the EventListener lock in EventSource ctor) while holding the AppDomain class init lock while another thread that's enabling EventListener for TplEventSource tries to start the Task for dispatching the events to EventListeners which then tries to get the AppDomain class init lock while holding the EventListener lock.

An example of this can be seen in the callstack below:

Thread 1:

06 00000034`41f7b910 00007ff8`04c33d01     coreclr!CrstBase::Enter+0x26b [F:\workspace\_work\1\s\src\coreclr\src\vm\crst.cpp @ 327] 
07 00000034`41f7b980 00007ff8`04d941e0     coreclr!ListLockEntryBase<void *>::FinishDeadlockAwareEnter+0x21 [F:\workspace\_work\1\s\src\coreclr\src\vm\listlock.h @ 209] 
08 (Inline Function) --------`--------     coreclr!ListLockEntryBase<void *>::LockHolder::DeadlockAwareAcquire+0x34 [F:\workspace\_work\1\s\src\coreclr\src\vm\listlock.h @ 234] 
09 00000034`41f7b9b0 00007ff8`04d8ff15     coreclr!MethodTable::DoRunClassInitThrowing+0x2f0 [F:\workspace\_work\1\s\src\coreclr\src\vm\methodtable.cpp @ 3316] 
0a 00000034`41f7c5a0 00007ff8`04dd22f4     coreclr!MethodTable::CheckRunClassInitThrowing+0x3b5 [F:\workspace\_work\1\s\src\coreclr\src\vm\methodtable.cpp @ 3481] 
0b 00000034`41f7c6f0 00007ff8`04dd900b     coreclr!DynamicHelperFixup+0xb2c [F:\workspace\_work\1\s\src\coreclr\src\vm\prestub.cpp @ 3234] 
0c 00000034`41f7ca90 00007ff8`0527e8da     coreclr!DynamicHelperWorker+0x1ab [F:\workspace\_work\1\s\src\coreclr\src\vm\prestub.cpp @ 3542] 
0d 00000034`41f7cc70 00007ff8`0475719a     coreclr!DelayLoad_Helper+0x7a
0e 00000034`41f7cd30 00007ff8`04756a11     System_Private_CoreLib!System.Threading.Tasks.Task.ScheduleAndStart(Boolean)+0xea [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs @ 1671] 
0f 00000034`41f7cd90 00007ff8`04863e77     System_Private_CoreLib!System.Threading.Tasks.Task.InternalStartNew(System.Threading.Tasks.Task, System.Delegate, System.Object, System.Threading.CancellationToken, System.Threading.Tasks.TaskScheduler, System.Threading.Tasks.TaskCreationOptions, System.Threading.Tasks.InternalTaskOptions)+0x71 [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs @ 1148] 
10 00000034`41f7ce10 00007ff8`04863d11     System_Private_CoreLib!System.Diagnostics.Tracing.EventPipeEventDispatcher.StartDispatchTask()+0x127 [/_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventPipeEventDispatcher.cs @ 148] 
11 00000034`41f7cf00 00007ff8`048639e6     System_Private_CoreLib!System.Diagnostics.Tracing.EventPipeEventDispatcher.CommitDispatchConfiguration()+0x1e1 [/_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventPipeEventDispatcher.cs @ 135] 
12 00000034`41f7d000 00007ff8`04873e5c     System_Private_CoreLib!System.Diagnostics.Tracing.EventPipeEventDispatcher.SendCommand(System.Diagnostics.Tracing.EventListener, System.Diagnostics.Tracing.EventCommand, Boolean, System.Diagnostics.Tracing.EventLevel, System.Diagnostics.Tracing.EventKeywords)+0xc6 [/_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventPipeEventDispatcher.cs @ 59] 
13 00000034`41f7d060 00007ff8`04873dc1     System_Private_CoreLib!System.Diagnostics.Tracing.EventListener.EnableEvents(System.Diagnostics.Tracing.EventSource, System.Diagnostics.Tracing.EventLevel, System.Diagnostics.Tracing.EventKeywords, System.Collections.Generic.IDictionary`2<System.String,System.String>)+0x8c [/_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs @ 3881] 
14 00000034`41f7d0e0 00007ff7`a5827f01     System_Private_CoreLib!System.Diagnostics.Tracing.EventListener.EnableEvents(System.Diagnostics.Tracing.EventSource, System.Diagnostics.Tracing.EventLevel, System.Diagnostics.Tracing.EventKeywords)+0x11 [/_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs @ 3853] 
15 00000034`41f7d110 000001d3`d53d9ce0     BinderTracingTest_ResolutionFlow!Unknown+0x61

Thread 2:

09 00000034`42a3ce80 00007ff8`04fa7a3b     coreclr!AwareLock::Enter+0x20f [F:\workspace\_work\1\s\src\coreclr\src\vm\syncblk.cpp @ 2403] 
0a (Inline Function) --------`--------     coreclr!Object::EnterObjMonitor+0x9 [F:\workspace\_work\1\s\src\coreclr\src\vm\object.h @ 277] 
0b 00000034`42a3cf70 00007ff8`04fae250     coreclr!JIT_MonEnter_Helper+0x157 [F:\workspace\_work\1\s\src\coreclr\src\vm\jithelpers.cpp @ 3665] 
0c 00000034`42a3d190 00007ff8`0486bb41     coreclr!JIT_MonReliableEnter_Portable+0x560 [F:\workspace\_work\1\s\src\coreclr\src\vm\jithelpers.cpp @ 3713] 
0d 00000034`42a3d3d0 00007ff8`04767385     System_Private_CoreLib!System.Diagnostics.Tracing.EventSource.Initialize(System.Guid, System.String, System.String[])+0x201 [/_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs @ 1490] 
0e 00000034`42a3d470 00007ff8`04768127     System_Private_CoreLib!System.Threading.Tasks.TplEventSource..ctor()+0xd5 [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/TplEventSource.cs @ 51] 
0f 00000034`42a3d4e0 00007ff8`0527d503     System_Private_CoreLib!System.Threading.Tasks.TplEventSource..cctor()+0x17 [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/TplEventSource.cs @ 48] 
10 00000034`42a3d510 00007ff8`04e8a447     coreclr!CallDescrWorkerInternal+0x83
11 00000034`42a3d550 00007ff8`04e89f48     coreclr!`DispatchCallDebuggerWrapper'::`6'::__Body::Run+0x7b [F:\workspace\_work\1\s\src\coreclr\src\vm\callhelpers.cpp @ 160] 
12 00000034`42a3d5a0 00007ff8`04e8a0e0     coreclr!DispatchCallDebuggerWrapper+0x20 [F:\workspace\_work\1\s\src\coreclr\src\vm\callhelpers.cpp @ 164] 
13 00000034`42a3d600 00007ff8`04da64a7     coreclr!DispatchCallSimple+0x148 [F:\workspace\_work\1\s\src\coreclr\src\vm\callhelpers.cpp @ 222] 
14 00000034`42a3d730 00007ff8`04d942b7     coreclr!MethodTable::RunClassInitEx+0x483 [F:\workspace\_work\1\s\src\coreclr\src\vm\methodtable.cpp @ 3154] 
15 00000034`42a3d990 00007ff8`04d8ff15     coreclr!MethodTable::DoRunClassInitThrowing+0x3c7 [F:\workspace\_work\1\s\src\coreclr\src\vm\methodtable.cpp @ 3341] 
16 00000034`42a3e580 00007ff8`04dd22f4     coreclr!MethodTable::CheckRunClassInitThrowing+0x3b5 [F:\workspace\_work\1\s\src\coreclr\src\vm\methodtable.cpp @ 3481] 
17 00000034`42a3e6d0 00007ff8`04dd900b     coreclr!DynamicHelperFixup+0xb2c [F:\workspace\_work\1\s\src\coreclr\src\vm\prestub.cpp @ 3234] 
18 00000034`42a3ea70 00007ff8`0527e8da     coreclr!DynamicHelperWorker+0x1ab [F:\workspace\_work\1\s\src\coreclr\src\vm\prestub.cpp @ 3542] 
19 00000034`42a3ec50 00007ff8`0485f30e     coreclr!DelayLoad_Helper+0x7a
1a 00000034`42a3ed10 00007ff8`0486b08f     System_Private_CoreLib!System.Diagnostics.Tracing.ActivityTracker.OnStart(System.String, System.String, Int32, System.Guid ByRef, System.Guid ByRef, System.Diagnostics.Tracing.EventActivityOptions, Boolean)+0x6e [/_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/ActivityTracker.cs @ 64] 
1b 00000034`42a3edc0 00007ff8`0474ca15     System_Private_CoreLib!System.Diagnostics.Tracing.EventSource.WriteEventWithRelatedActivityIdCore(Int32, System.Guid*, Int32, EventData*)+0x17f [/_/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs @ 1231] 
1c 00000034`42a3eef0 00007ff8`0474bdf0     System_Private_CoreLib!System.Threading.PortableThreadPoolEventSource.WriteThreadEvent(Int32, UInt32)+0x95 [/_/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPoolEventSource.cs @ 103] 
1d 00000034`42a3ef70 00007ff8`0472cdf1     System_Private_CoreLib!System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()+0x90 [/_/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.WorkerThread.cs @ 42] 
1e 00000034`42a3eff0 00007ff8`04738ed0     System_Private_CoreLib!System.Threading.ThreadHelper.ThreadStart_Context(System.Object)+0xa1 [/_/src/coreclr/src/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 49] 
1f 00000034`42a3f030 00007ff8`0472cf58     System_Private_CoreLib!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+0x80 [/_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs @ 188] 
20 00000034`42a3f0a0 00007ff8`0527d503     System_Private_CoreLib!System.Threading.ThreadHelper.ThreadStart()+0x58 [/_/src/coreclr/src/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 99] 
21 00000034`42a3f0e0 00007ff8`04e89e74     coreclr!CallDescrWorkerInternal+0x83
@Dotnet-GitSync-Bot Dotnet-GitSync-Bot added area-Tracing-coreclr untriaged New issue has not been triaged by the area owner labels Dec 3, 2020
@sywhang sywhang self-assigned this Dec 3, 2020
@sywhang sywhang removed the untriaged New issue has not been triaged by the area owner label Dec 3, 2020
@sywhang sywhang added this to the 6.0.0 milestone Dec 3, 2020
@sywhang sywhang added the bug label Dec 3, 2020
@sywhang sywhang added this to On Deck in .NET Core Diagnostics Dec 3, 2020
@sywhang sywhang mentioned this issue Dec 3, 2020
Merged
@tommcdon
Copy link
Member

related to #45384

@sywhang
Copy link
Contributor Author

sywhang commented Feb 22, 2021

This can be closed since ThreadPool no longer uses EventSource to write its events as of #47829.

@sywhang sywhang closed this as completed Feb 22, 2021
.NET Core Diagnostics automation moved this from On Deck to Done Feb 22, 2021
@ghost ghost locked as resolved and limited conversation to collaborators Mar 24, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@sywhang sywhang

Labels
area-Tracing-coreclr bug
Projects
.NET Core Diagnostics
  
Done
Milestone
6.0.0
Development

No branches or pull requests
3 participants
@tommcdon @sywhang @Dotnet-GitSync-Bot