Software Diagnostics Library

In addition to inline function optimization of unmanaged and native code we can see similar approach to JIT-compiled code:

public class ClassMain
{
    public bool time2stop = false;
   
    public static void Main(string[] args)
    {
        new ClassMain().Main();
    }

    public void Main()
    {
        while (!time2stop)
        {
            DoWork();
        } 
    }

    volatile int inSensor, outSensor;

    void DoWork()
    {
        outSensor ^= inSensor;
    }
}

0:000> kL
ChildEBP RetAddr 
WARNING: Frame IP not in any known module. Following frames may be wrong.
001fefa0 79e7c6cc 0×3200a4
001ff020 79e7c8e1 mscorwks!CallDescrWorkerWithHandler+0xa3
001ff160 79e7c783 mscorwks!MethodDesc::CallDescr+0×19c
001ff17c 79e7c90d mscorwks!MethodDesc::CallTargetWorker+0×1f
001ff190 79eefb9e mscorwks!MethodDescCallSite::Call_RetArgSlot+0×18
001ff2f4 79eef830 mscorwks!ClassLoader::RunMain+0×263
001ff55c 79ef01da mscorwks!Assembly::ExecuteMainMethod+0xa6
001ffa2c 79fb9793 mscorwks!SystemDomain::ExecuteMainMethod+0×43f
001ffa7c 79fb96df mscorwks!ExecuteEXE+0×59
001ffac4 736455ab mscorwks!_CorExeMain+0×15c
001ffad0 73747f16 mscoreei!_CorExeMain+0×38
001ffae0 73744de3 mscoree!ShellShim__CorExeMain+0×99
001ffae8 76573833 mscoree!_CorExeMain_Exported+0×8
001ffaf4 77c1a9bd kernel32!BaseThreadInitThunk+0xe
001ffb34 00000000 ntdll!_RtlUserThreadStart+0×23

0:000> r
eax=00000000 ebx=001fefbc ecx=015316e0 edx=0037a238 esi=0037a238 edi=00000000
eip=003200a4 esp=001fef90 ebp=001fefa0 iopl=0  nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000      efl=00000246
003200a4 80790c00   cmp     byte ptr [ecx+0Ch],0   ds:0023:015316ec=00

0:000> !IP2MD 003200a4
MethodDesc: 000d3048
Method Name: ClassMain.Main()
Class: 000d1180
MethodTable: 000d3060
mdToken: 06000002
Module: 000d2c3c
IsJitted: yes
m_CodeOrIL: 00320098

0:000> .asm no_code_bytes
Assembly options: no_code_bytes

0:000> !U 003200a4
Normal JIT generated code
ClassMain.Main()
Begin 00320098, size 13
00320098 cmp     byte ptr [ecx+0Ch],0
0032009c jne     003200aa
0032009e mov     eax,dword ptr [ecx+4]
003200a1 xor     dword ptr [ecx+8],eax
>>> 003200a4 cmp     byte ptr [ecx+0Ch],0
003200a8 je      0032009e
003200aa ret

We see that DoWork code was inlined into Main function code.

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

I noticed this pattern when analyzing the output of !DumpStack WinDbg SOS extension command:

0:011> !DumpStack
OS Thread Id: 0xac (11)
[...]
ChildEBP RetAddr  Caller, Callee
[…]
0b73f65c 77c416dc ntdll!RtlAllocateHeap+0×17c, calling ntdll!RtlpLowFragHeapAllocFromContext
0b73f688 77c486cd ntdll!RtlAllocateHeap+0×193, calling ntdll!memset
0b73f6b0 7653a467 kernel32!TlsSetValue+0×4c, calling ntdll!RtlAllocateHeap
0b73f6cc 77a01c48 urlmon!CUrlMkTls::TLSAllocData+0×3f, calling kernel32!TlsSetValue
0b73f6dc 77a0198d urlmon!CUrlMkTls::CUrlMkTls+0×29, calling urlmon!CUrlMkTls::TLSAllocData
0b73f6e8 77a01be5 urlmon!TlsDllMain+0×100, calling urlmon!EnsureFeatureCache
0b73f6f4 6d016a21 mshtml!DllMain+0×10, calling kernel32!GetCurrentThreadId
0b73f704 6d016b6c mshtml!_CRT_INIT+0×281, calling mshtml!DllMain
0b73f71c 7239133e msimtf!_CRT_INIT+0×281, calling msimtf!DllMain
0b73f728 72391375 msimtf!_CRT_INIT+0×3e7, calling msimtf!_SEH_epilog4
0b73f764 6d016ad0 mshtml!_DllMainStartup+0×56, calling mshtml!_DllMainCRTStartup
0b73f778 72391375 msimtf!_CRT_INIT+0×3e7, calling msimtf!_SEH_epilog4
0b73f77c 77c4a604 ntdll!LdrpCallInitRoutine+0×14
0b73f7a4 77c1ab6c ntdll!LdrpInitializeThread+0×1e9, calling ntdll!RtlLeaveCriticalSection
0b73f7ac 77c1a9ea ntdll!LdrpInitializeThread+0×1cd, calling ntdll!_SEH_epilog4
0b73f800 77c1ab15 ntdll!LdrpInitializeThread+0×11f, calling ntdll!RtlActivateActivationContextUnsafeFast
0b73f804 77c1ab53 ntdll!LdrpInitializeThread+0×167, calling ntdll!RtlDeactivateActivationContextUnsafeFast
0b73f838 77c1a9ea ntdll!LdrpInitializeThread+0×1cd, calling ntdll!_SEH_epilog4
0b73f83c 77c405a0 ntdll!NtTestAlert+0xc
0b73f840 77c1a968 ntdll!_LdrpInitialize+0×29c, calling ntdll!_SEH_epilog4
0b73f8a0 77c3f3d0 ntdll!NtContinue+0xc
0b73f8a4 77c1a98a ntdll!LdrInitializeThunk+0×1a, calling ntdll!NtContinue
0b73fb30 6afd59f6 clr!Thread::intermediateThreadProc+0×39, calling clr!_alloca_probe_16
0b73fb44 76573833 kernel32!BaseThreadInitThunk+0xe
0b73fb50 77c1a9bd ntdll!_RtlUserThreadStart+0×23

Obviously the command collected “call-type” execution residue from the raw stack. The “calling” part wasn’t found in the nearby region:

0:011> dps 0b73f7a4-20 0b73f7a4+20
0b73f784  72390000 msimtf!_imp__RegOpenKeyW <PERF> (msimtf+0×0)
0b73f788  00000002
0b73f78c  00000000
0b73f790  00000001
0b73f794  0b73f80c
0b73f798  0b73f80c
0b73f79c  00000001
0b73f7a0  05636578
0b73f7a4  0b73f83c
0b73f7a8  77c1ab6c ntdll!LdrpInitializeThread+0×1e9
0b73f7ac  77ca5340 ntdll!LdrpLoaderLock
0b73f7b0  77c1a9ea ntdll!LdrpInitializeThread+0×1cd
0b73f7b4  0b7321f2
0b73f7b8  7ff4e000
0b73f7bc  7ffdf000
0b73f7c0  77ca51f4 ntdll!LdrpProcessInitialized
0b73f7c4  00000000

I tried to disassemble backwards the addresses and found the callees:

0:011> ub 77c1ab6c
ntdll!LdrpInitializeThread+0×16b:
77c1ab57 90              nop
77c1ab58 90              nop
77c1ab59 90              nop
77c1ab5a 90              nop
77c1ab5b 90              nop
77c1ab5c ff054452ca77    inc     dword ptr [ntdll!LdrpActiveThreadCount (77ca5244)]
77c1ab62 684053ca77      push    offset ntdll!LdrpLoaderLock (77ca5340)
77c1ab67 e8bd820000      call    ntdll!RtlLeaveCriticalSection (77c22e29)

0:011> ub 77a01be5
urlmon!TlsDllMain+0×2f:
77a01bce 8d4510          lea     eax,[ebp+10h]
77a01bd1 50              push    eax
77a01bd2 8d4d0c          lea     ecx,[ebp+0Ch]
77a01bd5 e88efdffff      call    urlmon!CUrlMkTls::CUrlMkTls (77a01968)
77a01bda 397d10          cmp     dword ptr [ebp+10h],edi
77a01bdd 7c09            jl      urlmon!TlsDllMain+0×103 (77a01be8)
77a01bdf 56              push    esi
77a01be0 e887fcffff      call    urlmon!EnsureFeatureCache (77a0186c)

In the past I was frequently referencing this pattern especially when discussing coincidental symbolic information but didn’t name it. Now it’s time to do that: Caller-n-Callee.

We can also run !DumpStack command against every thread (including nonmanaged) to get the summary of the call-type execution residue:

0:011> ~4s
eax=76573821 ebx=00000002 ecx=00000000 edx=74d01909 esi=00000000 edi=00000000
eip=77c40f34 esp=0478f8a0 ebp=0478f93c iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
ntdll!KiFastSystemCallRet:
77c40f34 c3 ret

0:004> k
ChildEBP RetAddr 
0478f89c 77c40690 ntdll!KiFastSystemCallRet
0478f8a0 76577e09 ntdll!ZwWaitForMultipleObjects+0xc
0478f93c 7674c4af kernel32!WaitForMultipleObjectsEx+0x11d
0478f990 76748b7b user32!RealMsgWaitForMultipleObjectsEx+0x13c
0478f9ac 74d01965 user32!MsgWaitForMultipleObjects+0x1f
0478f9f8 76573833 GdiPlus!BackgroundThreadProc+0x59
0478fa04 77c1a9bd kernel32!BaseThreadInitThunk+0xe
0478fa44 00000000 ntdll!_RtlUserThreadStart+0x23

0:004> !DumpStack
OS Thread Id: 0x950 (4)
Current frame: ntdll!KiFastSystemCallRet
ChildEBP RetAddr  Caller, Callee
0478f89c 77c40690 ntdll!ZwWaitForMultipleObjects+0xc
0478f8a0 76577e09 kernel32!WaitForMultipleObjectsEx+0x11d, calling ntdll!NtWaitForMultipleObjects
0478f914 76751a91 user32!UserCallWinProcCheckWow+0x5c, calling ntdll!RtlActivateActivationContextUnsafeFast
0478f918 76751b41 user32!UserCallWinProcCheckWow+0x16a, calling ntdll!RtlDeactivateActivationContextUnsafeFast
0478f93c 7674c4af user32!RealMsgWaitForMultipleObjectsEx+0x13c, calling kernel32!WaitForMultipleObjectsEx
0478f968 76752a65 user32!DispatchMessageWorker+0x396, calling user32!_SEH_epilog4
0478f980 76743c64 user32!PeekMessageA+0x129, calling user32!_PeekMessage
0478f990 76748b7b user32!MsgWaitForMultipleObjects+0x1f, calling user32!MsgWaitForMultipleObjectsEx
0478f9ac 74d01965 GdiPlus!BackgroundThreadProc+0x59, calling user32!MsgWaitForMultipleObjects
0478f9f8 76573833 kernel32!BaseThreadInitThunk+0xe
0478fa04 77c1a9bd ntdll!_RtlUserThreadStart+0x23

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

When looking at process memory dumps and seeing CLR threads we can find fragments of JIT-ed code return addresses on the unmanaged stack trace:

0:011> kL
ChildEBP RetAddr 
WARNING: Frame IP not in any known module. Following frames may be wrong.
0b73e120 057223e2 0×572240f
0b73e134 6af44a2a 0×57223e2
0b73e1b0 6af44bcc clr!CallDescrWorkerWithHandler+0×8e
0b73e2f0 6af44c01 clr!MethodDesc::CallDescr+0×194
0b73e30c 6af44c21 clr!MethodDesc::CallTargetWorker+0×21
0b73e324 6afb7856 clr!MethodDescCallSite::Call+0×1c
0b73e4e8 6afb7ba3 clr!CallWithValueTypes_RetArgSlotWrapper+0×5c
0b73e7b4 6afb7d65 clr!InvokeImpl+0×621
0b73e880 6963d689 clr!RuntimeMethodHandle::InvokeMethodFast+0×180
0b73e8d4 6963d3d0 mscorlib_ni+0×2bd689
0b73e90c 6963bfed mscorlib_ni+0×2bd3d0
0b73e934 69643284 mscorlib_ni+0×2bbfed
0b73e958 6af3de7e mscorlib_ni+0×2c3284
0b73eb64 05720988 clr!ListLockEntry::Release+0×68
0b73ebc0 6962ae5b 0×5720988
0b73ebd0 695b7ff4 mscorlib_ni+0×2aae5b
0b73ebec 695b7f34 mscorlib_ni+0×237ff4
0b73ec0c 6962ade8 mscorlib_ni+0×237f34
0b73ec24 6af221db mscorlib_ni+0×2aade8
0b73ec34 6af44a2a clr!CallDescrWorker+0×33
0b73ecb0 6af44bcc clr!CallDescrWorkerWithHandler+0×8e
0b73ede8 6af44c01 clr!MethodDesc::CallDescr+0×194
0b73ee04 6b0bb512 clr!MethodDesc::CallTargetWorker+0×21
0b73f010 6afd5c05 clr!ThreadNative::KickOffThread_Worker+0×1e1
0b73f024 6afd5c87 clr!Thread::DoExtraWorkForFinalizer+0×114
0b73f0d4 6afd5d42 clr!Thread::ShouldChangeAbortToUnload+0×101
0b73f134 6afc37a2 clr!Thread::ShouldChangeAbortToUnload+0×399
0b73f140 6b0a6465 clr!Thread::RaiseCrossContextException+0×3f8
0b73f220 6afc37cf clr!Thread::DoADCallBack+0xf0
0b73f240 6afd5c87 clr!Thread::DoExtraWorkForFinalizer+0xfa
0b73f2f0 6afd5d42 clr!Thread::ShouldChangeAbortToUnload+0×101
0b73f350 6afd5dd9 clr!Thread::ShouldChangeAbortToUnload+0×399
0b73f374 6b0bb3e5 clr!Thread::ShouldChangeAbortToUnload+0×43a
0b73f38c 6b0bb2e0 clr!ManagedThreadBase::KickOff+0×15
0b73f424 6afd5a08 clr!ThreadNative::KickOffThread+0×23e
0b73fb44 76573833 clr!Thread::intermediateThreadProc+0×4b
0b73fb50 77c1a9bd kernel32!BaseThreadInitThunk+0xe

With the correct CLR version extension loaded we can inspect these addresses and get their method names, module and class addresses using !IP2MD WinDbg SOS extension command:

0:011> !IP2MD 0x572240f
MethodDesc:   057420e8
Method Name:  UserQuery+ClassMain.Main()
Class:        057341d8
MethodTable:  05742108
mdToken:      06000004
Module:       05741048
IsJitted:     yes
CodeAddr:     05722400
Transparency: Critical

0:011> !IP2MD 0x57223e2
MethodDesc:   0574204c
Method Name:  UserQuery.RunUserAuthoredQuery()
Class:        057340a4
MethodTable:  0574206c
mdToken:      06000001
Module:       05741048
IsJitted:     yes
CodeAddr:     057223d0
Transparency: Critical

0:011> !IP2MD 0x5720988
MethodDesc:   056e601c
Method Name:  LINQPad.ExecutionModel.Server.StartClrQuery()
Class:        0571f6e4
MethodTable:  056e60e4
mdToken:      06000c59
Module:       056e336c
IsJitted:     yes
CodeAddr:     05720910
Transparency: Critical

These method calls can also be seen on managed stack trace:

0:011> !CLRStack
OS Thread Id: 0xac (11)
Child SP IP       Call Site
0b73e120 0572240f UserQuery+ClassMain.Main()
0b73e128 057223e2 UserQuery.RunUserAuthoredQuery()
0b73e674 6af221db [DebuggerU2MCatchHandlerFrame: 0b73e674]
0b73e640 6af221db [CustomGCFrame: 0b73e640]
0b73e614 6af221db [GCFrame: 0b73e614]
0b73e5f8 6af221db [GCFrame: 0b73e5f8]
0b73e81c 6af221db [HelperMethodFrame_PROTECTOBJ: 0b73e81c] System.RuntimeMethodHandle._InvokeMethodFast(System.IRuntimeMethodInfo, System.Object, System.Object[], System.SignatureStruct ByRef, System.Reflection.MethodAttributes, System.RuntimeType)
0b73e898 6963d689 System.RuntimeMethodHandle.InvokeMethodFast(System.IRuntimeMethodInfo, System.Object, System.Object[], System.Signature, System.Reflection.MethodAttributes, System.RuntimeType)
0b73e8ec 6963d3d0 System.Reflection.RuntimeMethodInfo.Invoke(System.Object, System.Reflection.BindingFlags, System.Reflection.Binder, System.Object[], System.Globalization.CultureInfo, Boolean)
0b73e928 6963bfed System.Reflection.RuntimeMethodInfo.Invoke(System.Object, System.Reflection.BindingFlags, System.Reflection.Binder, System.Object[], System.Globalization.CultureInfo)
0b73e94c 69643284 System.Reflection.MethodBase.Invoke(System.Object, System.Object[])
0b73e958 0572134c LINQPad.ExecutionModel.Server.RunClrQuery()
0b73eb6c 05720988 LINQPad.ExecutionModel.Server.StartClrQuery()
0b73ebc8 6962ae5b System.Threading.ThreadHelper.ThreadStart_Context(System.Object)
0b73ebd8 695b7ff4 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
0b73ebfc 695b7f34 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
0b73ec18 6962ade8 System.Threading.ThreadHelper.ThreadStart()
0b73ee30 6af221db [GCFrame: 0b73ee30]
0b73f0f4 6af221db [DebuggerU2MCatchHandlerFrame: 0b73f0f4]
0b73f18c 6af221db [ContextTransitionFrame: 0b73f18c]
0b73f310 6af221db [DebuggerU2MCatchHandlerFrame: 0b73f310]

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -