Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Deadlock when writing to Console StreamWriter

Edit1: Simplified question: How do I find out what is the current (native) stack waiting on?:

 # Child-SP          RetAddr           Call Site
00 000000bb`62e6de78 00007fff`e7b07489 ntdll!NtWriteFile+0x14
01 000000bb`62e6de80 00007fff`a6bfb526 KERNELBASE!WriteFile+0x79
02 000000bb`62e6def0 00007fff`a6b3d802 mscorlib_ni!DomainNeutralILStubClass.IL_STUB_PInvoke(System.Runtime.CompilerServices.StackCrawlMarkHandle, System.Runtime.CompilerServices.ObjectHandleOnStack)$##6000000+0x246
03 000000bb`62e6dfd0 00007fff`a6b3d77b mscorlib_ni!System.IO.__ConsoleStream.WriteFileNative(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Int32, Boolean)$##600166A+0x72

(without the private symbols and sources for ntdll of course :-/)

I know it's not progressing (the output it's trying to push to console never appeared and it was in this same stack for long minutes). Interestingly it shows supsend count 0:

0:019> ~19
. 19  Id: 3bac.1fd8 Suspend: 0 Teb: 000000bb`6059d000 Unfrozen
      Start: clr!Thread::intermediateThreadProc (00007fff`b456cad0)
      Priority: 0  Priority class: 32  Affinity: ff

Original question (and full context):

I'm investigating a dump of deadlocked application, where thread is stuck within following stack:

0:019> !clrstack
The version of SOS does not match the version of CLR you are debugging.  Please
load the matching version of SOS for the version of CLR you are debugging.
CLR Version: 4.7.3101.0
SOS Version: 4.7.2563.0
OS Thread Id: 0x1fd8 (19)
        Child SP               IP Call Site
000000bb62e6df28 00007fffeb79a094 [InlinedCallFrame: 000000bb62e6df28] Microsoft.Win32.Win32Native.WriteFile(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte*, Int32, Int32 ByRef, IntPtr)
000000bb62e6df28 00007fffa6bfb526 [InlinedCallFrame: 000000bb62e6df28] Microsoft.Win32.Win32Native.WriteFile(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte*, Int32, Int32 ByRef, IntPtr)
000000bb62e6def0 00007fffa6bfb526 DomainNeutralILStubClass.IL_STUB_PInvoke(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte*, Int32, Int32 ByRef, IntPtr)
000000bb62e6dfd0 00007fffa6b3d802 System.IO.__ConsoleStream.WriteFileNative(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Int32, Boolean)
000000bb62e6e040 00007fffa6b3d77b System.IO.__ConsoleStream.Write(Byte[], Int32, Int32)
000000bb62e6e080 00007fffa6b3b458 System.IO.StreamWriter.Flush(Boolean, Boolean)
000000bb62e6e0e0 00007fffa6b3d727 System.IO.StreamWriter.Write(Char[], Int32, Int32)
000000bb62e6e140 00007fffa6b3d612 System.IO.TextWriter+SyncTextWriter.WriteLine(System.String)

The code resulting to this stack is writing text to TextWriter that was captured earlier as:

public static readonly TextWriter OriginalConsoleWriter = Console.Out;

Different thread in same application domain was earlier able to write to same StreamWriter (output is in concole and from log we can see that the thread progressed to other functions). There is no other thread in same application domain reading/writing from/to console There is a thread in different ('main') application domain that is waiting on Console.ReadLine():

Child-SP         RetAddr          Caller, Callee
000000bb6193e7e0 00007fffe7b079c6 KERNELBASE!ReadFile+0x76, calling ntdll!NtReadFile
000000bb6193e7f8 00007fffb4566a8f clr!SafeHandle::DangerousAddRef+0x6f, calling clr!LazyMachStateCaptureState
000000bb6193e860 00007fffa6bfb526 (MethodDesc 00007fffa6783f60 +0xc6 DomainNeutralILStubClass.IL_STUB_PInvoke(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte*, Int32, Int32 ByRef, IntPtr))
000000bb6193e8c8 00007fffa6bfb526 (MethodDesc 00007fffa6783f60 +0xc6 DomainNeutralILStubClass.IL_STUB_PInvoke(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte*, Int32, Int32 ByRef, IntPtr))
000000bb6193e940 00007fffa742779a (MethodDesc 00007fffa6898440 +0xba System.IO.__ConsoleStream.ReadFileNative(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Int32, Boolean, Boolean, Int32 ByRef)), calling 00007fffa6aae778 (stub for Microsoft.Win32.Win32Native.ReadFile(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte*, Int32, Int32 ByRef, IntPtr))
000000bb6193e9d0 00007fffa74276a4 (MethodDesc 00007fffa6898420 +0x64 System.IO.__ConsoleStream.Read(Byte[], Int32, Int32)), calling (MethodDesc 00007fffa6898440 +0 System.IO.__ConsoleStream.ReadFileNative(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Int32, Boolean, Boolean, Int32 ByRef))
000000bb6193ea30 00007fffa6b98024 (MethodDesc 00007fffa676cc38 +0x44 System.IO.StreamReader.ReadBuffer())
000000bb6193ea80 00007fffa6b985be (MethodDesc 00007fffa676cc50 +0x15e System.IO.StreamReader.ReadLine())
000000bb6193eae0 00007fffa75dd03c (MethodDesc 00007fffa689fc50 +0x3c System.IO.TextReader+SyncTextReader.ReadLine())
000000bb6193eb00 00007fffb4564595 clr!ThePreStub+0x55, calling clr!PreStubWorker
000000bb6193eb40 00007fffa73c17a3 (MethodDesc 00007fffa6753220 +0x23 System.Console.ReadLine())

I cannot however detect any deadlock or blocking from the managed stacks in dump, neither can the !dlk command:

0:019> !dlk
Examining SyncBlocks...
Scanning for ReaderWriterLock instances...
Scanning for holders of ReaderWriterLock locks...
Scanning for ReaderWriterLockSlim instances...
Scanning for holders of ReaderWriterLockSlim locks...
Examining CriticalSections...
No deadlocks detected.

Where/How else should I examine what could be blocking within Microsoft.Win32.Win32Native.WriteFile (ntdll!NtWriteFile) call?

like image 463
Jan Avatar asked Nov 23 '25 00:11

Jan


1 Answers

This was most likely caused by quick-edit or mark/select mode of console. When trying on my machine - breaking into simple console app that is spewing to console and currently blocked during select - I see this on top of the stack:

# Child-SP          RetAddr           Call Site
00 00000028`48bde818 00007fff`c33a1cbc ntdll!NtWriteFile+0xa
01 00000028`48bde820 00007fff`81c4c0c6 KERNELBASE!WriteFile+0x88

Which is very similar to top of the stack from our incident (offsets are bit moved; however it's a different OS - so that's possible; I already don't have access to the machine from incident).

This was legacy app, so we resolved it by hosting the process and redirecting input/output to host process console, that is already handling Console interaction in appropriate asynchronous way.

like image 112
Jan Avatar answered Nov 24 '25 14:11

Jan



Donate For Us

If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!