Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Windbg native call stack trace does not make sense

Tags:

windbg

sos

I have a simple test program causing an infinite wait on lock.

public class SyncBlock
{

}

class Program
{
    public static SyncBlock sync = new SyncBlock();

    private static void ThreadProc()
    {
        try
        {
            Monitor.Enter(sync);


       }
        catch (Exception)
        {
            //Monitor.Exit(sync);
            Console.WriteLine("3rd party code threw an exception");
        }
    }
    static void Main(string[] args)
    {
        Thread newThread = new Thread(ThreadProc);
        newThread.Start();


        Console.WriteLine("Acquiring lock");
        Monitor.Enter(sync);

        Console.WriteLine("Releasing lock");
        Monitor.Exit(sync);

    }
}

So the main thread is basically get locked when it tries to do Monitor.Enter(sync). If I looked at !clrStack on main thread, its output basically show it which make sense but when I try to see native side of stack, I am expecting to see some Wait on single/multiple object type of call but I don't see it. Can anyone explain it. Thanks

0:000> !CLRStack  

PDB symbol for mscorwks.dll not loaded
OS Thread Id: 0x1e8 (0)
ESP EIP
0012f0a8 77455e74 [GCFrame: 0012f0a8]
0012f178 77455e74 [HelperMethodFrame_1OBJ: 0012f178] System.Threading.Monitor.Enter (System.Object) 0012f1d0 00a40177 ConsoleApplication1.Program.Main(System.String[])
0012f400 70fc1b4c [GCFrame: 0012f400]
0:000> kb
ChildEBP RetAddr Args to Child
WARNING: Stack unwind information not available. Following frames may be wrong.
0012eeb4 710afb92 0012ee68 002d6280 00000000 ntdll!KiFastSystemCallRet
0012ef1c 710af7c3 00000001 002d6280 00000000 mscorwks!StrongNameFreeBuffer+0x1b1f2
0012ef3c 710af8cc 00000001 002d6280 00000000 mscorwks!StrongNameFreeBuffer+0x1ae23
0012efc0 710af961 00000001 002d6280 00000000 mscorwks!StrongNameFreeBuffer+0x1af2c
0012f010 710afae1 00000001 002d6280 00000000 mscorwks!StrongNameFreeBuffer+0x1afc1
0012f06c 70fdc5ae ffffffff 00000001 00000000 mscorwks!StrongNameFreeBuffer+0x1b141
0012f080 710df68a ffffffff 00000001 00000000 mscorwks!LogHelp_NoGuiOnAssert+0x10562
0012f10c 710b1154 002aad90 ffffffff 002aad90 mscorwks!StrongNameFreeBuffer+0x4acea
0012f128 710b10d8 42b8b47d 00000000 002aad90 mscorwks!StrongNameFreeBuffer+0x1c7b4
0012f1e0 70fc1b4c 0012f1f0 0012f230 0012f270 mscorwks!StrongNameFreeBuffer+0x1c738
0012f1f0 70fd2219 0012f2c0 00000000 0012f290 mscorwks+0x1b4c
0012f270 70fe6591 0012f2c0 00000000 0012f290 mscorwks!LogHelp_NoGuiOnAssert+0x61cd
0012f3ac 70fe65c4 0023c038 0012f478 0012f444 mscorwks!CoUninitializeEE+0x2ead
0012f3c8 70fe65e2 0023c038 0012f478 0012f444 mscorwks!CoUninitializeEE+0x2ee0
0012f3e0 7103389d 0012f444 42b8b0f1 00000000 mscorwks!CoUninitializeEE+0x2efe
0012f544 710337bd 002332e0 00000001 0012f580 mscorwks!GetPrivateContextsPerfCounters+0xf546
0012f7ac 71033d0d 00000000 42b8b9c9 00000001 mscorwks!GetPrivateContextsPerfCounters+0xf466
0012fc7c 71033ef7 00ce0000 00000000 42b8979 mscorwks!GetPrivateContextsPerfCounters+0xf9b6
0012fccc 71033e27 00ce0000 42b8b8a1 00000000 mscorwks!CorExeMain+0x168
* ERROR: Symbol file could not be found. Defaulted to export symbols for C:\Windows\Microsoft.NET\Framework\v4.0.30319\mscoreei.dll - 0012fd14 71cf55ab 71033d8f 0012fd30 71f37f16 mscorwks!CorExeMain+0x98
*
ERROR: Symbol file could not be found. Defaulted to export symbols for C:\Windows\system32\mscoree.dll -
0012fd20 71f37f16 00000000 71cf0000 0012fd44 mscoreei!CorExeMain+0x38
0012fd30 71f34de3 00000000 7723d0e9 7ffd8000 mscoree!CreateConfigStream+0x13f
0012fd44 774319bb 7ffd8000 084952f9 00000000 mscoree!CorExeMain+0x8
0012fd84 7743198e 71f34ddb 7ffd8000 00000000 ntdll!RtlInitializeExceptionChain+0x63
0012fd9c 00000000 71f34ddb 7ffd8000 00000000 ntdll!RtlInitializeExceptionChain+0x36

like image 593
imak Avatar asked Oct 14 '22 22:10

imak


1 Answers

You have to point windbg to the microsoft windows symbols server to get a good stack trace.

type in the following in your windbg command window:

.sympath srv*c:\websymbols*http://msdl.microsoft.com/download/symbols

Also see this:

Using microsoft symbol server to get symbols

Also, to answer your original question about how to debug this, here is the cookbook:

0:000> !clrstack
OS Thread Id: 0x1358 (0)
ESP       EIP     
0012f328 7c90e514 [GCFrame: 0012f328] 
0012f3f8 7c90e514 [HelperMethodFrame_1OBJ: 0012f3f8] System.Threading.Monitor.Enter(System.Object)
0012f450 00d10177 Program.Main(System.String[])
0012f688 79e71b4c [GCFrame: 0012f688] 

In your original program, the background thread was started first. So, it acquired the lock. However it exited without releasing the lock. After that your main thread tried to acquire the lock and it is stuck because the lock is already owned.

How do you find out who owns it? First do a !threads followed by !syncblk.

0:000> !threads
ThreadCount: 3
UnstartedThread: 0
BackgroundThread: 1
PendingThread: 0
DeadThread: 1
Hosted Runtime: no
                                      PreEmptive   GC Alloc           Lock
       ID OSID ThreadOBJ    State     GC       Context       Domain   Count APT Exception
   0    1 1358 0014bb00   200a020 Enabled  00000000:00000000 001540d0     0 MTA
   2    2 1360 0015e320      b220 Enabled  00000000:00000000 001540d0     0 MTA (Finalizer)
XXXX    3    0 00175a98      9820 Enabled  00000000:00000000 001540d0     1 Ukn
0:000> !syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
    2 0017903c            3         1 00175a98     0 XXX   013503cc SyncBlock
-----------------------------
Total           2
CCW             0
RCW             0
ComClassFactory 0
Free            0

As you can see, !syncblk says that the owining thread object is 00175a98. From the !threads output, you can see that thread object 00175a98 is the dead thread that exited while owning the lock.

Hope this helps.

like image 71
feroze Avatar answered Oct 18 '22 02:10

feroze