Monday, November 16, 2020

COM Access Violation (AV) Crashes Relating to Unloaded DLLs

My team uses a broadly used WinRT API.  Basically, all apps that have a device-related scenario use it.  This means buggy apps that crash will sometimes have our component featured in their Watson dumps.  Based on certain metrics, Watson will turn buckets turn into code bugs, so we have to triage them.  Aside: in case you were wondering, bugs from WER (Windows Error Reporting) service and dumps, do generate bugs and get fixed, so WER is useful.

A number of AV crash bugs we see are related to our device watcher calling back into the app's handlers for the device events, which almost always means a lifetime management bug in the app.  

You can check the memory allocations to see if they are busy or free.  This applies more to the component that owns the object's memory.  I think I covered that before.  That will let you know if the object has already been released.  A lot of times you can still see the object's state after it has been freed, but the important part is that it has been released/freed already, so the object is not being ref counted correctly.  AppVerif has a handy COM set of checks which might help if you think you may have this problem in your code.  With smart pointers, it can be a little harder to see what is happening with the object's references.  If the object model is not too complicated, you can just find the bug with code inspection.

A super common reason for AVs like this is the DLL is unloaded.  COM aggressively unloads DLLs not being used by calling DllCanUnloadNow.  If the implementation has a bug, the DLL will get unloaded while objects and other COM operations are in flight.  Eventually, when COM tries to CoUnitialize an object that belongs to that DLL, it will AV.  This also applies to other COM things like when COM tries to marshal between apartments, etc.

 We see crashes like this fairly often:

0:049> .excr
rax=00007ff8f305cf70 rbx=0000026dfc5cc900 rcx=0000026dfc5cc900
rdx=0000000000012f06 rsi=0000026dfa091b00 rdi=0000026dfa091ae0
rip=00007ff990c9094d rsp=000000b92deff490 rbp=00000000800401fd
 r8=00007ff970a0b370  r9=000000b92deff5d0 r10=dee01e7974d59970
r11=000000b92deff5e0 r12=0000000000012f06 r13=00007ff970a0b370
r14=000000b92deff5d0 r15=00007ff8f305cf70
iopl=0         nv up ei pl nz na pe nc
cs=0033  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00010202
combase!CGIPTable::GetRequestedInterface+0x22 [inlined in combase!CGIPTable::GetInterfaceFromGlobal+0x1ed]:
00007ff9`90c9094d 488b00          mov     rax,qword ptr [rax] ds:00007ff8`f305cf70=????????????????
0:049> k
  *** Stack trace for last set context - .thread/.cxr resets it
 # Child-SP          RetAddr               Call Site
00 (Inline Function) --------`--------     combase!CGIPTable::GetRequestedInterface+0x22 [onecore\com\combase\dcomrem\giptbl.cxx @ 1615] 
01 000000b9`2deff490 00007ff9`7097515b     combase!CGIPTable::GetInterfaceFromGlobal+0x1ed [onecore\com\combase\dcomrem\giptbl.cxx @ 1660] 
02 000000b9`2deff560 00007ff9`70977823     Windows_Devices_Enumeration!Gip<Windows::Foundation::ITypedEventHandler<Windows::Devices::Enumeration::DeviceWatcher *,Windows::Devices::Enumeration::DeviceInformation *> >::Localize+0x6b [onecore\private\base\inc\devices\Git.h @ 167] 
03 (Inline Function) --------`--------     Windows_Devices_Enumeration!GitDelegate2<Windows::Foundation::ITypedEventHandler<Windows::Devices::Enumeration::DeviceWatcher *,Windows::Devices::Enumeration::DeviceInformation *>,Windows::Devices::Enumeration::IDeviceWatcher *,Windows::Devices::Enumeration::IDeviceInformation *>::GetHandler+0x11 [onecoreuap\base\devices\rtenum\dllsrv\GitDelegate.h @ 254] 
04 000000b9`2deff5a0 00007ff9`70976d95     Windows_Devices_Enumeration!GitDelegate2<Windows::Foundation::ITypedEventHandler<Windows::Devices::Enumeration::DeviceWatcher *,Windows::Devices::Enumeration::DeviceInformation *>,Windows::Devices::Enumeration::IDeviceWatcher *,Windows::Devices::Enumeration::IDeviceInformation *>::Invoke+0x23 [onecoreuap\base\devices\rtenum\dllsrv\GitDelegate.h @ 303] 
05 (Inline Function) --------`--------     Windows_Devices_Enumeration!Microsoft::WRL::EventSource<Windows::Foundation::ITypedEventHandler<Windows::Devices::Enumeration::DeviceWatcher *,Windows::Devices::Enumeration::DeviceInformation *>,Microsoft::WRL::InvokeModeOptions<-2> >::InvokeAll::__l2::<lambda_00d1300cb6cb75d6b2b5344e37267964>::operator()+0x36 [onecore\external\sdk\inc\wrl\event.h @ 964] 
06 000000b9`2deff5d0 00007ff9`70976cf4     Windows_Devices_Enumeration!Microsoft::WRL::InvokeTraits<-2>::InvokeDelegates<<lambda_00d1300cb6cb75d6b2b5344e37267964>,Windows::Foundation::ITypedEventHandler<Windows::Devices::Enumeration::DeviceWatcher *,Windows::Devices::Enumeration::DeviceInformation *> >+0x79 [onecore\internal\sdk\inc\wrl\internalevent.h @ 121] 
07 000000b9`2deff630 00007ff9`70981d3d     Windows_Devices_Enumeration!Microsoft::WRL::EventSource<Windows::Foundation::ITypedEventHandler<Windows::Devices::Enumeration::DeviceWatcher *,Windows::Devices::Enumeration::DeviceInformation *>,Microsoft::WRL::InvokeModeOptions<-2> >::DoInvoke<<lambda_00d1300cb6cb75d6b2b5344e37267964> >+0x78 [onecore\external\sdk\inc\wrl\event.h @ 954] 
08 (Inline Function) --------`--------     Windows_Devices_Enumeration!Microsoft::WRL::EventSource<Windows::Foundation::ITypedEventHandler<Windows::Devices::Enumeration::DeviceWatcher *,Windows::Devices::Enumeration::DeviceInformation *>,Microsoft::WRL::InvokeModeOptions<-2> >::InvokeAll+0x19 [onecore\external\sdk\inc\wrl\event.h @ 964] 
09 000000b9`2deff670 00007ff9`8ee2d946     Windows_Devices_Enumeration!Watcher<Windows::Devices::Enumeration::DeviceWatcher,Windows::Devices::Enumeration::IDeviceWatcher,Windows::Devices::Enumeration::IDeviceWatcher2,Windows::Devices::Enumeration::DeviceInformation,Windows::Devices::Enumeration::IDeviceInformation,Windows::Devices::Enumeration::IDeviceInformation2,DeviceInformationServer,Windows::Devices::Enumeration::DeviceInformationUpdate,Windows::Devices::Enumeration::IDeviceInformationUpdate,DeviceInformationUpdateServer,&RuntimeClass_Windows_Devices_Enumeration_DeviceWatcher>::Impl::DevQueryCallback+0x3ad [onecoreuap\base\devices\rtenum\dllsrv\Watcher.h @ 889] 
0a 000000b9`2deff710 00007ff9`91b9b0ea     cfgmgr32!TQuery::ServiceActionQueue+0xe2 [onecore\base\pnp\devquery\lib\query.cpp @ 245] 
0b 000000b9`2deff7a0 00007ff9`91b3ec06     ntdll!TppWorkpExecuteCallback+0x13a [minkernel\threadpool\ntdll\work.c @ 671] 
0c 000000b9`2deff7f0 00007ff9`8ff94ede     ntdll!TppWorkerThread+0x686 [minkernel\threadpool\ntdll\worker.c @ 1109] 
0d 000000b9`2deffae0 00007ff9`91b87c6b     kernel32!BaseThreadInitThunk+0x1e [clientcore\base\win32\client\thread.c @ 70] 
0e 000000b9`2deffb10 00000000`00000000     ntdll!RtlUserThreadStart+0x2b [minkernel\ntdll\rtlstrt.c @ 1152] 
0:049> .frame 0n0;dv /t /v
00 (Inline Function) --------`--------     combase!CGIPTable::GetRequestedInterface+0x22 [onecore\com\combase\dcomrem\giptbl.cxx @ 1615] 
@rbx              struct IUnknown * pUnk = 0x0000026d`fc5cc900
@r15              void * pVtableAddress = 0x00007ff8`f305cf70
<unavailable>     HRESULT hr = <value unavailable>
0:049> dps 0x0000026d`fc5cc900
0000026d`fc5cc900  00007ff8`f305cf70 <Unloaded_xxxxxxxxx.dll>+0xc2cf70
0000026d`fc5cc908  00000001`00000000
0000026d`fc5cc910  0000026d`fbdc9af0
0000026d`fc5cc918  00080000`00000000
0000026d`fc5cc920  00000000`00000008
0000026d`fc5cc928  00000008`4d454d4c
0000026d`fc5cc930  0000026d`fc4d3bf8
You can see that the handler's dll is already unloaded.
// or another example ///
:000> k
combase!CStdMarshal::DisconnectSrvIPIDs::__l29::<lambda_2a3a7b5175b0a5e47c77e1d8eff078e5>::operator()+0x7
combase!ObjectMethodExceptionHandlingAction<<lambda_2a3a7b5175b0a5e47c77e1d8eff078e5> >+0x24
combase!CStdMarshal::DisconnectSrvIPIDs+0x30d
combase!CStdMarshal::DisconnectWorker_ReleasesLock+0x2d7
combase!CStdMarshal::DisconnectSwitch_ReleasesLock+0x1c
combase!CStdMarshal::DisconnectAndReleaseWorker_ReleasesLock+0x32
combase!COIDTable::ThreadCleanup+0x117
combase!FinishShutdown::__l2::<lambda_3d4acc620ec77839d81caec938b15158>::operator()+0x5
combase!ObjectMethodExceptionHandlingAction<<lambda_3d4acc620ec77839d81caec938b15158> >+0x9
combase!FinishShutdown+0x78
combase!ApartmentUninitialize+0xc9
combase!wCoUninitialize+0x17d
combase!CoUninitialize+0xea
wuaueng!UHRunRemoteHandlerServer+0x25e
...
0:000> .exr -1
ExceptionAddress: 00007ffe8571a510 (combase!CStdMarshal::DisconnectSrvIPIDs::__l29::<lambda_2a3a7b5175b0a5e47c77e1d8eff078e5>::operator()+0x0000000000000007)
   ExceptionCode: c0000005 (Access violation)
  ExceptionFlags: 00000000
NumberParameters: 2
Attempt to read from address 00007ffe59d74ee8
0:000> ln 00007ffe59d74ee8
(00007ffe`59d74ee8)   <Unloaded_xxxxxxxxxxx.dll>+0x1b4ee8

Sunday, November 3, 2019

Howto: Enable Application Verifier Within WinDbg

!gflag debugger extention

A quick way to enable AppVerifier settings from the kernel debugger is to use !gflag debugger extension. This extension also enables Heaps, Handles and Locks checks only. Any process that is launched after the settings are enabled will run with these AppVerifier settings.
To enable lite pageheap, Handles and Locks checks on all apps that start from here on:
   kd>!gflag +vrf
To enable full pageheap
   kd>!gflag +hpa
To disable settings:
   kd>!gflag -vrf
   kd>!gflag -hpa

!avrf debugger extention

The !avrf extension controls the settings of Application Verifier and displays a variety of output produced by Application Verifier.
    !avrf
    !avrf -vs { Length | -a Address }
    !avrf -hp { Length | -a Address }
    !avrf -cs { Length | -a Address }
    !avrf -dlls [ Length ]
    !avrf -trm
    !avrf -ex [ Length ] 
    !avrf -threads [ ThreadID ]
    !avrf -tp [ ThreadID ]
    !avrf -srw  [ Address | Address Length ] [ -stats ]
    !avrf -leak  [ -m ModuleName] [ -r ResourceType] [ -a Address ] [ -t ]
    !avrf -trace TraceIndex 
    !avrf -cnt
    !avrf -brk [BreakEventType]  
    !avrf -flt [EventType Probability] 
    !avrf -flt break EventType 
    !avrf -flt stacks Length 
    !avrf -trg [ Start End | dll Module | all ] 
    !avrf -settings 
    !avrf -skp [ Start End | dll Module | all | Time ] 

Parameters

-vs { Length | -a Address }
Displays the virtual space operation log. Length specifies the number of records to display, starting with the most recent. Address specifies the virtual address. Records of the virtual operations that contain this virtual address are displayed.
-hp { Length | -a Address }
Displays the heap operation log. Address specifies the heap address. Records of the heap operations that contain this heap address are displayed.
-cs { Length | -a Address }
Displays the critical section delete log. Length specifies the number of records to display, starting with the most recent. Address specifies the critical section address. Records for the particular critical section are displayed when Address is specified.
-dlls [ Length ]
Displays the DLL load/unload log. Length specifies the number of records to display, starting with the most recent.
-trm
Displays a log of all terminated and suspended threads.
-ex [ Length ]
Displays the exception log. Application Verifier tracks all the exceptions in the application.
-threads [ ThreadID ]
Displays information about threads in the target process. For child threads, the stack size and the CreateThread flags specified by the parent are also displayed. If you provide a thread ID, information for only that thread is displayed.
-tp [ ThreadID ]
Displays the threadpool log. This log contains stack traces for various operations such as changing the thread affinity mask, changing thread priority, posting thread messages, and initializing or uninitializing COM from within the threadpool callback. If you provide a thread ID, information for that thread only is displayed.
-srw [ Address | Address Length ] [ -stats ]
Displays the Slim Reader/Writer (SRW) log. If you specify Address, records for the SRW lock at that address are displayed. If you specify Address and Length, records for SRW locks in that address range are displayed. If you include the -stats option, the SRW lock statistics are displayed.
-leak [ -m ModuleName] [ -r ResourceType] [ -a Address ] [ -t ]
Displays the outstanding resources log. These resources may or may not be leaks at any given point. If you specify Modulename (including the extension), all outstanding resources in the specified module are displayed. If you specify ResourceType, all outstanding resources of that resource type are displayed. If you specify Address, records of outstanding resources with that address are displayed. ResourceType can be one of the following:
Heap: Displays heap allocations using Win32 Heap APIs
Local: Displays Local/Global allocations
CRT: Displays allocations using CRT APIs
Virtual: Displays Virtual reservations
BSTR: Displays BSTR allocations
Registry: Displays Registry key opens
Power: Displays power notification objects
Handle: Displays thread, file, and event handle allocations
-trace TraceIndex Displays a stack trace for the specified trace index. Some structures use this 16-bit index number to identify a stack trace. This index points to a location within the stack trace database.
-cnt Displays a list of global counters.
-brk [ BreakEventType ] Specifies a break event. BreakEventType is the type number of the break event. For a list of possible types, and a list of the current break event settings, enter !avrf -brk.
-flt [ EventType Probability ] Specifies a fault injection. EventType is the type number of the event. Probability is the frequency with which the event will fail. This can be any integer between 0 and 1,000,000 (0xF4240). If you enter !avrf -flt with no additional parameters, the current fault injection settings are displayed.
-flt break EventType Causes Application Verifier to break into the debugger each time this fault, specified by EventType, is injected.
-flt stacks Length Displays Length number of stack traces for the most recent fault-injected operations.
-trg [ Start End | dll Module | all ] Specifies a target range. Start is the beginning address of the target range. End is the ending address of the target range. Module specifies the name (including the .exe or .dll extension, but not including the path) of a module to be targeted. If you enter -trg all, all target ranges are reset. If you enter -trg with no additional parameters, the current target ranges are displayed.
-skp [ Start End | dll Module | all | Time ] Specifies an exclusion range. Start is the beginning address of the exclusion range. End is the ending address of the exclusion range. Module specifies the name of a module to be targeted or excluded. Module specifies the name (including the .exe or .dll extension, but not including the path) of a module to be excluded. If you enter -skp all, all target ranges or exclusion ranges are reset. If you enter aTime value, all faults are suppressed for Time milliseconds after execution resumes.


Wednesday, September 25, 2019

Setting windbg to break in for C++ exceptions

Sometimes unhanded C++ exceptions will crash you program.

It might looks something like this:

(fc0.5204): C++ EH exception - code e06d7363 (first chance)
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
KERNELBASE!RaiseException+0x69:

windbg has gotten a lot better at handling exceptions.  A lot of times, you can just type:

> .excr

And it will reconstituted and set the context to the stack the threw; still, there are other factors that may prevent this from working like you'd want.

If that doesn't work, you can just use the trusty sx to set an exception handler

> sxe eh

Or if you have a specific structured exception number

> sxe number






Wednesday, November 22, 2017

How to Find a loaded Module in Windows

Let's get right into it.  Most of the time it is very easy where to find where a dll or exe is loaded using tlist.exe (aka task list).  In an elevated prompt, type:

> tlist /m module.dll|exe

eg.
C:\Debuggers> tlist /m cfgmgr32.dll
C:\WINDOWS\System32\cfgmgr32.dll -  828 lsass.exe
C:\WINDOWS\System32\cfgmgr32.dll - 1108 svchost.exe
C:\WINDOWS\System32\cfgmgr32.dll - 1132 WUDFHost.exe
C:\WINDOWS\System32\cfgmgr32.dll - 1240 svchost.exe
C:\WINDOWS\System32\cfgmgr32.dll - 1304 svchost.exe
C:\WINDOWS\System32\CFGMGR32.dll - 1556 svchost.exe
C:\WINDOWS\System32\cfgmgr32.dll - 1652 svchost.exe
C:\WINDOWS\System32\cfgmgr32.dll - 1676 dwm.exe           DWM Notification Window
C:\WINDOWS\System32\cfgmgr32.dll - 1940 svchost.exe
C:\WINDOWS\System32\cfgmgr32.dll - 2016 svchost.exe
C:\WINDOWS\System32\cfgmgr32.dll - 1348 svchost.exe
...

I think generally though the idea is that you can use this to find the PID for debugging the component in question.

eg.
C:\Debuggers> tlist /m notepad.exe
C:\WINDOWS\system32\NOTEPAD.EXE - 12900 notepad.exe       remote.txt - Notepad
C:\Debuggers>windbg -p  12900

That is assuming that it is already loaded and running.  What if it isn't loaded?

eg.
C:\Debuggers> tlist /m hotplug.dll
No tasks found using HOTPLUG.DLL

The easiest case is you know where it will be loaded.  For example, you can know that exporer.exe will load it eventually.  Then, you simply need to just attach a debugger to explorer.exe

eg.
C:\Debuggers> tlist explorer.exe
9020 explorer.exe      Program Manager
   CWD:     C:\WINDOWS\system32\
   CmdLine: "C:\WINDOWS\explorer.exe"
   VirtualSize:   2148226416 KB   PeakVirtualSize:   2149576868 KB
...
C:\Debuggers> windbg -p 9020

After that, you can do standard WinDbg stuff like setting a breakpoint:

eg.
> bp hotplug!SomeFunction

Or, if you need to break it before the DLL gets fully loaded, that is a little more work:
> sxe ld hotplug.dll
> bp hotplug!DllMain
> g

What if you have no idea where hotplug.dll gets loaded?  That is where using a KD comes in handy.

Thursday, May 11, 2017

Custom Capabilities for Windows Apps

Here is a little update on what I have been working for the last release of Windows.  As you may know, Windows uses the capability model.  To mark app container apps with privileges to certain capabilities like using location, or a camera.  The basic idea of custom capabilities is to allow 3rd party developers to define their own custom capabilities so that their apps or their partner's apps can similarly be marked.  Ultimately a capability becomes a SID that is stamped on the app's token.  Internal brokered components check those SIDs before letting apps do privileged things out of the app container sand box.   Now 3rd parties can also have services or drivers that can also check for those SIDs before allowing apps to use their privileged resources.

Watch the video below to get a more info:
https://channel9.msdn.com/events/Build/2017/P4086

Friday, February 3, 2017

Powershell Howto: Arrays of Stucts/Objects Using [pscustomobject]

First off, I am not a regular powershell scripter, but I was writing a powershell script to automate some e2e (end to end) testing.  I recently finished a feature in one our DEHes (deployment extension handler used for installing appx packages in Windows), so we needed a test for our nightly test passes.

I wanted to make an array of appx packages that I wanted to test in different scenarios, I also wanted to keep track of other data in the element like expected outcomes for trying to deploy the app in various developer settings.  In C, I would simply define a structure with the data I wanted for each element, and then define a static array of these structs for each appx package.

In powershell, you can use a pscustomobject to make something like a C struct.  Thy syntax is like this:

$obj = [pscustomobject]@{name="good appx";canSideLoad=$true;canInstallDevMode=$true;path="c:\test\packages\test_app_1.1.34.0_good_appx\"}

Now, to make that an array of objects:
$packages = @(
    [pscustomobject]@{name="p1";canInstallDevMode=$true;canDevMode=$true;path="\\path1"},
    [pscustomobject]@{name="p2";canInstallDevMode=$true;canDevMode=$true;path="\\path2"})

Aside: You can use a hash table if you have a two item tuple.  The syntax for a hash table looks like this:
$packagePaths = @{"case1" = "\\path1..."; "case2" = "\\path2...";}

How do you walk the array of [pscustomobject] using a for loop?

for ($i = 0; $i -lt $packages.Count; $i++) {
    $basePath = $packages[$i].path
    ...
}


Thursday, April 14, 2016

How to Find a RPC Server's Clients Via WinDbg

Need to level up your Windows RPC debugging skills?  Read on.

I have been debugging a service stop hang.  The simple conclusion is that my service had RPC clients hanging around.  This is a little how to for how to use windbg to figure out who the offending client is.

The first thing is obvious, the SCM is blocked on thread 0 because my service main has not exited, so let's find that thread.  Obviously it is thread 1. What is that thread blocked on?  It is trying to close out its RPC server interfaces.

What is RPC waiting for?  Normally it is outstanding clients.

==========================================================
0:001> ~* kn

   0  Id: 1668.17fc Suspend: 1 Teb: 00331000 Unfrozen
 # ChildEBP RetAddr
00 0008fc74 775bddba ntdll!KiFastSystemCallRet [d:\rs1\minkernel\ntos\rtl\i386\userdisp.asm @ 818]
01 0008fc78 749533d0 ntdll!NtWaitForSingleObject+0xa [d:\rs1.obj.x86fre\minkernel\ntdll\daytona\objfre\i386\usrstubs.asm @ 217]
WARNING: Stack unwind information not available. Following frames may be wrong.
02 0008fcec 74953312 KERNELBASE!WaitForSingleObjectEx+0xb0
03 0008fd00 76b5214c KERNELBASE!WaitForSingleObject+0x12
04 0008fdc0 76b5deb1 sechost!StartServiceW+0x1dc
05 0008fe70 76b5102c sechost!RpcClientCapabilityCheck+0x851
06 0008feac 00ab32c0 sechost!StartServiceCtrlDispatcherW+0x5c
07 0008fed0 76aba954 myhost+0x32c0
08 0008fee4 7759a16a KERNEL32!BaseThreadInitThunk+0x24
09 0008ff2c 7759a139 ntdll!__RtlUserThreadStart+0x2b [d:\rs1\minkernel\ntdll\rtlstrt.c @ 997]
0a 0008ff3c 00000000 ntdll!_RtlUserThreadStart+0x1b [d:\rs1\minkernel\ntdll\rtlstrt.c @ 914]

   1  Id: 1668.400 Suspend: 1 Teb: 00336000 Unfrozen
 # ChildEBP RetAddr
00 0087f480 775c04ca ntdll!KiFastSystemCallRet [d:\rs1\minkernel\ntos\rtl\i386\userdisp.asm @ 818]
01 0087f484 7495dc38 ntdll!NtDelayExecution+0xa [d:\rs1.obj.x86fre\minkernel\ntdll\daytona\objfre\i386\usrstubs.asm @ 2769]
WARNING: Stack unwind information not available. Following frames may be wrong.
02 0087f4ec 7495db8f KERNELBASE!SleepEx+0x98
03 0087f4fc 76c111d0 KERNELBASE!Sleep+0xf
04 (Inline) -------- RPCRT4!PauseExecution+0xb [d:\rs1\minio\rpc\runtime\mtrt\threads.cxx @ 88]
05 0087f538 76be2609 RPCRT4!RPC_SERVER::UnregisterIf+0x2f996 [d:\rs1\minio\rpc\runtime\mtrt\hndlsvr.cxx @ 4838]
06 0087f574 76be2318 RPCRT4!RPC_SERVER::DeactivateInterfaceGroup+0xf3 [d:\rs1\minio\rpc\runtime\mtrt\hndlsvr.cxx @ 11256]
07 0087f5a0 69d78b0b RPCRT4!RPC_SERVER::CloseInterfaceGroup+0xe5 [d:\rs1\minio\rpc\runtime\mtrt\hndlsvr.cxx @ 10484]
08 0087f5b0 69d7c04d my_svc!DestroyRpcServices+0x1b [s:\epix_dev\onecore\base\devices\my_svc\rpcif.cpp @ 540]
09 0087f658 69d7ca5a my_svc!MySvcStop+0x27d [s:\epix_dev\onecore\base\devices\my_svc\srventry.cpp @ 198]
0a 0087f660 77584eee my_svc!MySvcStopThreadProc+0xa [s:\epix_dev\onecore\base\devices\my_svc\srventry.cpp @ 350]
0b 0087f6c4 77575cc2 ntdll!TppSimplepExecuteCallback+0x6e [d:\rs1\minkernel\threadpool\ntdll\simple.c @ 376]
0c 0087f8c8 76aba954 ntdll!TppWorkerThread+0x902 [d:\rs1\minkernel\threadpool\ntdll\worker.c @ 1075]
0d 0087f8dc 7759a16a KERNEL32!BaseThreadInitThunk+0x24
0e 0087f924 7759a139 ntdll!__RtlUserThreadStart+0x2b [d:\rs1\minkernel\ntdll\rtlstrt.c @ 997]
0f 0087f934 00000000 ntdll!_RtlUserThreadStart+0x1b [d:\rs1\minkernel\ntdll\rtlstrt.c @ 914]

   2  Id: 1668.1118 Suspend: 1 Teb: 00337000 Unfrozen
 # ChildEBP RetAddr
00 008efc68 775bdd9a ntdll!KiFastSystemCallRet [d:\rs1\minkernel\ntos\rtl\i386\userdisp.asm @ 818]
01 008efc6c 77575666 ntdll!NtWaitForWorkViaWorkerFactory+0xa [d:\rs1.obj.x86fre\minkernel\ntdll\daytona\objfre\i386\usrstubs.asm @ 209]
02 008efe7c 76aba954 ntdll!TppWorkerThread+0x2a6 [d:\rs1\minkernel\threadpool\ntdll\worker.c @ 876]
WARNING: Stack unwind information not available. Following frames may be wrong.
03 008efe90 7759a16a KERNEL32!BaseThreadInitThunk+0x24
04 008efed8 7759a139 ntdll!__RtlUserThreadStart+0x2b [d:\rs1\minkernel\ntdll\rtlstrt.c @ 997]
05 008efee8 00000000 ntdll!_RtlUserThreadStart+0x1b [d:\rs1\minkernel\ntdll\rtlstrt.c @ 914]

   3  Id: 1668.dc0 Suspend: 1 Teb: 00338000 Unfrozen
 # ChildEBP RetAddr
...
==========================================================

Lets figure out what is going on with unregistering the interface.  So, we jump to frame 5.  Well it looks like some of the locals are optimized out.

==========================================================

0:001> .frame 5
05 0087f538 76be2609 RPCRT4!RPC_SERVER::UnregisterIf+0x2f996 [d:\rs1\minio\rpc\runtime\mtrt\hndlsvr.cxx @ 4838]
0:001> ?? RpcInterface
class RPC_INTERFACE * 0x00000000
0:001> dv -v
@ebx                                 this = 0x0087f4c8
0087f540          RpcInterfaceInformation = 0x69d22450
@edi                      ManagerTypeUuid = 0x00000000
0087f548           WaitForCallsToComplete = 1
0087f54c                      FromIfGroup = 0x005f4be0
0087f518                           cursor = 0
                  RpcStatus =
@esi                         RpcInterface = 0x00000000
    fNewValidInterfaceFound =
                     Status =
0087f524                         NullUUID = {00000000-0000-0000-0000-000000000000}
                    IfGroup =
                    Address =

==========================================================

But, the stack tells me that thread 1 is sleep spinning, waiting for something.  Let's see what RPC calls are outstanding.

Looks like there is MyIf RPC context hanging out still.

==========================================================

0:001> !rpcexts.listcalls

RPC_SERVER at 0x5e3180
&RpcAddressDictionary(RPC_SIMPLE_DICT) - 0x5e31b4
Printing 1 items in dictionary: 5e31b4 with 4 slots

(0): 0x5f6e60 - LRPC_ADDRESS
Printing 1 items in dictionary: 5f6ee8 with 4 slots

(0): 0x5f8c10 - LRPC_SMYIF_TYPE

0:001> !obj 0x5f8c10
Dumping LRPC_SMYIF...

LpcServerPort(HANDLE)   - 0x174
Address     - 0x5f6e60
&Bindings(LRPC_SBINDING_DICT)  - 0x5f8c34
&MyIfMutex   - 0x5f8c50
&SContextDict    - 0x5f8c68

0:001> dt RPCRT4!LRPC_SMYIF 0x5f8c10 
   +0x000 __VFN_table : 0x76ba9500 
   +0x004 MagicLong        : 0x89abcdef
   +0x008 ObjectType       : 0n32768
   +0x00c RefCount         : INTERLOCKED_INTEGER (0x1)
   +0x010 MyIfID    : 1
   +0x014 CtxCollection    : 0x005f1a80 ContextCollection
   +0x018 TableIndex       : 0
   +0x01c LpcServerPort    : 0x00000174 Void
   +0x020 Address          : 0x005f6e60 LRPC_ADDRESS
   +0x024 Bindings         : LRPC_SBINDING_DICT
   +0x040 MyIfMutex : MUTEX
   +0x058 SContextDict     : LRPC_SCONTEXT_DICT
   +0x078 MsgNumbers       : tagLrpcMessageNumbers
   +0x080 CloseMessageNumber : 4
   +0x084 IoTarget         : tagLRPC_IO_TARGET
   +0x090 BindingsCollectionLock : RPC_SRWLOCK
   +0x094 ActiveCallsListHead : _LIST_ENTRY [ 0x5f89ec - 0x5f89ec ]
   +0x09c CausalFlowsTable : GenericTable
   +0x0e0 CachedCalls      : LRPC_CACHED_SCALLS
   +0x0f0 Flags            :  (0x0)
   +0x0f8 SectionCache     : LRPC_SECTION_CACHE
   +0x158 PipeHistoryData  : (null) 
   +0x15c CancelHistoryInformation : LRPC_CANCEL_HISTORY_INFORMATION
   +0x170 CorrelationId    : 0x1124cb
   +0x174 DisconnectNotificationEvent : (null) 

==========================================================

Lets figure out what outstanding calls there are for that context by looking at the active calls list from above.

Let's take a look at the first one.

==========================================================

0:001> ?0x5f8c10 +94
Evaluate expression: 6261924 = 005f8ca4
0:001> !obj 0x5f89ec
0:001> dt rpcrt4!LRPC_SCALL
   +0x000 __VFN_table : Ptr32
   +0x004 MagicLong        : Uint4B
   +0x008 ObjectType       : Int4B
   +0x00c RefCount         : INTERLOCKED_INTEGER
   +0x010 pAsync           : Ptr32 _RPC_ASYNC_STATE
   +0x014 AsyncStatus      : Int4B
   +0x018 CallingThread    : Ptr32 THREAD
   +0x01c ReservedNotificationsLock : CSpinLock
   +0x020 CachedNotificationInfo : RPC_RESERVED_NOTIFICATION_INFO
   +0x03c CachedNotificationInfoAvailable : Int4B
   +0x04!opj 0 ReservedNotifications : RPC_RESERVED_NOTIFICATION_INFO_DICT2
   +0x06c ActivityID       : _GUID
   +0x07c DispatchBuffer   : Ptr32 Void
   +0x080 Flags            : SCALL_CompositeFlags
   +0x084 SubscribeInfo    : Ptr32 NotificationSubscriptionInformation
   +0x088 ActiveContextHandles : ServerContextHandle_DICT
   +0x0a4 AsyncCallbackState : Ptr32 ASYNC_SEC_CALLBACK_STATE
   +0x0a8 Association      : Ptr32 LRPC_SASSOCIATION
   +0x0ac SBinding         : Ptr32 LRPC_SBINDING
   +0x0b0 DebugCell        : Ptr32 tagDebugCallInfo
   +0x0b4 DebugCellTag     : Int4B
   +0x0b8 RpcMessage       : _RPC_MESSAGE
   +0x0e4 RuntimeInfo      : _RPC_RUNTIME_INFO
   +0x0f0 ClientPrincipalName : Ptr32 Wchar
   +0x0f4 ClientRequest    : Ptr32 _LRPC_REQUEST_MESSAGE
   +0x0f8 Response         : Ptr32 _LRPC_RESPONSE_MESSAGE
   +0x0fc AlpcPortSection  : Ptr32 Void
   +0x100 LargeReplyDataBuffer : Ptr32 Void
   +0x104 LargeRequestDataBuffer : Ptr32 Void
   +0x108 LargeReplyDataSize : Uint4B
   +0x10c LargeReplyViewSize : Uint4B
   +0x110 ClientId         : _CLIENT_ID
   +0x118 ObjectUuidFlag   : Int4B
   +0x11c ObjectUuid       : RPC_UUID
   +0x12c CallId           : Uint4B
   +0x130 SContext         : Ptr32 LRPC_SCONTEXT
   +0x134 ActiveCallsEntry : _LIST_ENTRY
   +0x13c CausalFlowEntry  : _LIST_ENTRY
   +0x144 CallCausalFlowNumber : Uint4B
   +0x148 AdditionalCallData : LRPC_SCALL::
   +0x14c SystemHandles    : LRPC_SYSTEM_HANDLE_DATA
   +0x15c TokenAttributes  : RPCP_ALPC_TOKEN_ATTR
0:001> ?0x5f89ec  -134
Evaluate expression: 6260920 = 005f88b8
0:001> !obj 005f88b8
Dumping LRPC_SCALL ...

AsyncStatus    - 0x0
pAsync     - 0x5f21b0
CallingThread    - 0x0
&ActiveContextHandles(ServerContextHandle_DICT)  - 0x5f8940
DispatchBuffer    - 0x5fff78
pMyIf(LRPC_MYIF)  - 0x5f8c10
pSBinding(LRPC_SBINDING)  - 0x5e9a10
ObjectUuidFlag    - 0x1
ObjectUuid    - 49541cea-a719-4e75-8d58-a3a7bfff960e
CallId     - 0x2
ClientId.UniqueProcess(CLIENT_ID.HANDLE) - 0x730
ClientId.UniqueThread (CLIENT_ID.HANDLE) - 0x1580
RefCount    - 0x1
SContext    - 0x0

==========================================================

That is very useful.  We now know the thread and process ID of the caller.  You can now go crazy with !process and !thread.  You can even use WinDbg to attach and debug the caller directly if you want.

This is also useful.  It tells you which method in your interface it is actually calling.

==========================================================
0:001> !dict 0x5f8940

Printing 1 items in dictionary: 5f8940 with 4 slots

(0): 0x5e0a40

0:001> dt rpcrt4!ServerContextHandle 0x5e0a40
   +0x000 ContextChain     : _LIST_ENTRY [ 0x0 - 0x0 ]
   +0x008 UserContext      : 0x008aad58 Void
   +0x00c UserRunDown      : 0x69d6b930     void  MySvc!HDMYIF_rundown+0
   +0x010 ClientId         : RPC_CLIENT_TRANSPORT_SEC_IDENTIFIER
   +0x018 RpcInterface     : 0x005f6580 RPC_INTERFACE
   +0x01c CtxGuard         : CTXT_HANDLE_INFO
   +0x028 Node             : GenericTable >::NodeType
   +0x04c UserStrict       : 0n0
   +0x050 Lock             : SWMRLock
   +0x064 OwnerSID         : (null)
   +0x068 ReferenceCount   : 0n2
   +0x06c Flags            : 1
   +0x070 DeadlockTag      : 0n0
0:001> !teb
TEB at 00336000
    ExceptionList:        0087f4dc
    StackBase:            00880000
    StackLimit:           0087c000
    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 00336000
    EnvironmentPointer:   00000000
    ClientId:             00001668 . 00000400
    RpcHandle:            00000000
    Tls Storage:          0033602c
    PEB Address:          00330000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0
0:001> dt rpcrt4!LRPC_SCALL 005f88b8
   +0x000 __VFN_table : 0x76ba9150
   +0x004 MagicLong        : 0x89abcdef
   +0x008 ObjectType       : 0n8192
   +0x00c RefCount         : INTERLOCKED_INTEGER (0x1)
   +0x010 pAsync           : 0x005f21b0 _RPC_ASYNC_STATE
   +0x014 AsyncStatus      : 0n0
   +0x018 CallingThread    : (null)
   +0x01c ReservedNotificationsLock : CSpinLock
   +0x020 CachedNotificationInfo : RPC_RESERVED_NOTIFICATION_INFO
   +0x03c CachedNotificationInfoAvailable : 0n1
   +0x040 ReservedNotifications : RPC_RESERVED_NOTIFICATION_INFO_DICT2
   +0x06c ActivityID       : _GUID {00000000-0000-0000-0000-000000000000}
   +0x07c DispatchBuffer   : 0x005fff78 Void
   +0x080 Flags            : AssocClose+0x8000 (0x8800)
   +0x084 SubscribeInfo    : 0x005f5ae8 NotificationSubscriptionInformation
   +0x088 ActiveContextHandles : ServerContextHandle_DICT
   +0x0a4 AsyncCallbackState : (null)
   +0x0a8 Association      : 0x005f8c10 LRPC_SMYIF
   +0x0ac SBinding         : 0x005e9a10 LRPC_SBINDING
   +0x0b0 DebugCell        : (null)
   +0x0b4 DebugCellTag     : 0n0
   +0x0b8 RpcMessage       : _RPC_MESSAGE
   +0x0e4 RuntimeInfo      : _RPC_RUNTIME_INFO
   +0x0f0 ClientPrincipalName : (null)
   +0x0f4 ClientRequest    : 0x005fff20 _LRPC_REQUEST_MESSAGE
   +0x0f8 Response         : 0x005ecd70 _LRPC_RESPONSE_MESSAGE
   +0x0fc AlpcPortSection  : (null)
   +0x100 LargeReplyDataBuffer : (null)
   +0x104 LargeRequestDataBuffer : (null)
   +0x108 LargeReplyDataSize : 0
   +0x10c LargeReplyViewSize : 0
   +0x110 ClientId         : _CLIENT_ID
   +0x118 ObjectUuidFlag   : 0n1
   +0x11c ObjectUuid       : RPC_UUID
   +0x12c CallId           : 2
   +0x130 SContext         : (null)
   +0x134 ActiveCallsEntry : _LIST_ENTRY [ 0x5f8ca4 - 0x5f8ca4 ]
   +0x13c CausalFlowEntry  : _LIST_ENTRY [ 0x0 - 0x0 ]
   +0x144 CallCausalFlowNumber : 1
   +0x148 AdditionalCallData : LRPC_SCALL::
   +0x14c SystemHandles    : LRPC_SYSTEM_HANDLE_DATA
   +0x15c TokenAttributes  : RPCP_ALPC_TOKEN_ATTR
0:001> dx -r1 (*((RPCRT4!_RPC_MESSAGE *)0x5f8970))
(*((RPCRT4!_RPC_MESSAGE *)0x5f8970))                 [Type: _RPC_MESSAGE]
    [+0x000] Handle           : 0x5f88b8 [Type: void *]
    [+0x004] DataRepresentation : 0x10 [Type: unsigned long]
    [+0x008] Buffer           : 0x5fff78 [Type: void *]
    [+0x00c] BufferLength     : 0x1c [Type: unsigned int]
    [+0x010] ProcNum          : 0x2 [Type: unsigned int]
    [+0x014] TransferSyntax   : 0x5f65c4 [Type: _RPC_SYNTAX_IDENTIFIER *]
    [+0x018] RpcInterfaceInformation : 0x5f65ac [Type: void *]
    [+0x01c] ReservedForRuntime : 0x5f899c [Type: void *]
    [+0x020] ManagerEpv       : 0x0 [Type: void *]
    [+0x024] ImportContext    : 0x404 [Type: void *]
    [+0x028] RpcFlags         : 0x9000 [Type: unsigned long]
0:001> dx -r1 (*((RPCRT4!_RPC_SYNTAX_IDENTIFIER *)0x5f65c4))
(*((RPCRT4!_RPC_SYNTAX_IDENTIFIER *)0x5f65c4))                 [Type: _RPC_SYNTAX_IDENTIFIER]
    [+0x000] SyntaxGUID       : {8A885D04-1CEB-11C9-9FE8-08002B104860} [Type: _GUID]
    [+0x010] SyntaxVersion    [Type: _RPC_VERSION]
0:001> dt RPCRT4!RPC_CLIENT_INTERFACE 0x5f65ac
   +0x000 Length           : 0x44
   +0x004 InterfaceId      : _RPC_SYNTAX_IDENTIFIER
   +0x018 TransferSyntax   : _RPC_SYNTAX_IDENTIFIER
   +0x02c DispatchTable    : 0x69d22444 RPC_DISPATCH_TABLE
   +0x030 RpcProtseqEndpointCount : 0
   +0x034 RpcProtseqEndpoint : (null)
   +0x038 Reserved         : 0
   +0x03c InterpreterInfo  : 0x69d22424 Void
   +0x040 Flags            : 0x4000000
0:001> dx -r1 (*((RPCRT4!_RPC_SYNTAX_IDENTIFIER *)0x5f65b0))
(*((RPCRT4!_RPC_SYNTAX_IDENTIFIER *)0x5f65b0))                 [Type: _RPC_SYNTAX_IDENTIFIER]
    [+0x000] SyntaxGUID       : {850CEE52-3038-4277-B9B4-E05DB8B2C35C} [Type: _GUID]
    [+0x010] SyntaxVersion    [Type: _RPC_VERSION]
0:001> dx -r1 (*((RPCRT4!RPC_DISPATCH_TABLE *)0x69d22444))
(*((RPCRT4!RPC_DISPATCH_TABLE *)0x69d22444))                 [Type: RPC_DISPATCH_TABLE]
    [+0x000] DispatchTableCount : 0xe [Type: unsigned int]
    [+0x004] DispatchTable    : 0x69d217bc [Type: void (**)(_RPC_MESSAGE *)]
    [+0x008] Reserved         : 0 [Type: long]