At a reader’s request, I wrote this post describing a quirk (or feature) of the Windows 10 Creators Update.
The symptom
While testing DebugView++ on Windows 10 1703 Creators Update, build 15063.413 (the latest version at the time), one of my users found that the application hung at startup for about 20 seconds before continuing. After that, it worked normally.
The bug was reported here. On the previous version, Windows 10 1607 build 14393.1358, the problem did not occur. DebugView++ is a bit special in that it listens to a ‘debugger’ API in order to receive OutputDebugString messages. For those of you not familiar with this API: it is a Win32 facility to output debug messages (as the name suggests).
Normally DebugView++ receives these messages from another process. The mechanism that delivers them is quite primitive: it is a fixed 4096-byte buffer, and the caller of OutputDebugString can briefly be blocked if messages are not read immediately by the debug application.
I’ve optimized DebugView++ to read messages as fast as possible and to unblock the traced application as soon as possible. So what could be causing DebugView++ itself to block for 20 seconds? The 20 seconds were curious in themselves, because the OutputDebugString API has a 10-second timeout, so it looked awfully like two message timeouts. Could I have made a mistake and accidentally be calling OutputDebugString from within DebugView++? That would be problematic, as it could potentially cause infinite recursion.
After some investigation, it turned out that DebugView++ itself was not sending any messages, at least not from its own code, but the Win32 libraries that were loaded implicitly (specifically oleaut32.dll) can now call into the OutputDebugString API.
So the problem was introduced because in Windows 10 1703 the Win32 API itself started using OutputDebugString internally. Below is a stack dump of the process while it was hanging (created using Task Manager’s ‘Create dump file’ feature).
Once I found out why it was happening, I was also able to do a small redesign of the flow for incoming messages, so it no longer matters where the messages come from.
The obscure we see eventually. The completely obvious, it seems, takes longer. — Edward R. Murrow
ntdll.dll!_NtWaitForSingleObject@12�() Unknown
KERNELBASE.dll!WaitForSingleObjectEx() Unknown
KERNELBASE.dll!OutputDebugStringA() Unknown
> KERNELBASE.dll!OutputDebugStringW() Unknown
oleaut32.dll!wil::details::LogFailure(void *,unsigned int,char const *,char const *,char const *,void *,enum wil::FailureType,long,unsigned short const *,bool,unsigned short *,unsigned int,char *,unsigned int,struct wil::FailureInfo *) Unknown
oleaut32.dll!wil::details::ReportFailure(void *,unsigned int,char const *,char const *,char const *,void *,enum wil::FailureType,long,unsigned short const *,enum wil::details::ReportFailureOptions) Unknown
oleaut32.dll!wil::details::ReportFailure_Hr(void *,unsigned int,char const *,char const *,char const *,void *,enum wil::FailureType,long) Unknown
oleaut32.dll!wil::details::in1diag3::Return_Hr_NoOriginate(void *,unsigned int,char const *,long) Unknown
oleaut32.dll!GetTypeInfoOfIIDFwd(struct _GUID const &,struct ITypeInfo * *,int) Unknown
oleaut32.dll!CProxyWrapper::Connect(struct IRpcChannelBuffer *) Unknown
combase.dll!CStdMarshal::ConnectProxyToChannel(tagIPIDEntry * pEntry, OXIDEntry * pOXIDEntry, const _GUID & ipid) Line 3206 C++
[Inline Frame] combase.dll!CStdMarshal::ConnectCliIPIDEntry(tagSTDOBJREF *) Line 3055 C++
combase.dll!CStdMarshal::MakeCliIPIDEntry(const _GUID & riid, tagSTDOBJREF * pStd, OXIDEntry * pOXIDEntry, tagIPIDEntry * * ppEntry) Line 2812 C++
combase.dll!CStdMarshal::UnmarshalIPID(const _GUID & riid, tagSTDOBJREF * pStd, OXIDEntry * pOXIDEntry, void * * ppv) Line 2340 C++
combase.dll!CStdMarshal::UnmarshalObjRef(tagOBJREF & objref, void * * ppv) Line 2208 C++
combase.dll!UnmarshalSwitch(void * pv) Line 1843 C++
combase.dll!UnmarshalObjRef(tagOBJREF & objref, EffectiveUnmarshalingPolicy policy, void * * ppv, int fBypassActLock, CStdMarshal * * ppStdMarshal) Line 1985 C++
combase.dll!_CoUnmarshalInterface(IStream * pStm, bool bForceStrongPolicy, const _GUID & riid, void * * ppv) Line 1730 C++
combase.dll!CoUnmarshalInterface(IStream * pStm, const _GUID & riid, void * * ppv) Line 1773 C++
combase.dll!ActivationPropertiesOut::OutSerializer::UnmarshalAtIndex(unsigned long index, bool bIsWinRTOutofproc) Line 3139 C++
combase.dll!ActivationPropertiesOut::GetObjectInterfaces(unsigned long cIfs, unsigned long actvflags, tagMULTI_QI * pMultiQi) Line 2746 C++
combase.dll!ICoCreateInstanceEx(const _GUID & OriginalClsid, IUnknown * punkOuter, unsigned long dwClsCtx, _COSERVERINFO * pServerInfo, unsigned long dwCount, unsigned long dwActvFlags, tagMULTI_QI * pResults, ActivationPropertiesIn * pActIn) Line 1971 C++
combase.dll!CComActivator::DoCreateInstance(const _GUID & Clsid, IUnknown * punkOuter, unsigned long dwClsCtx, _COSERVERINFO * pServerInfo, unsigned long dwCount, tagMULTI_QI * pResults, ActivationPropertiesIn * pActIn) Line 384 C++
[Inline Frame] combase.dll!CoCreateInstanceEx(const _GUID &) Line 176 C++
combase.dll!CoCreateInstance(const _GUID & rclsid, IUnknown * pUnkOuter, unsigned long dwContext, const _GUID & riid, void * * ppv) Line 120 C++
uiautomationcore.dll!BlockingCoreDispatcher::CreateAndRegisterBlockingCore(void) Unknown
uiautomationcore.dll!BlockingCoreDispatcher::FinalConstruct(void) Unknown
uiautomationcore.dll!ATL::CComCreator<class ATL::CComObject<class CUIAutomation8> >::CreateInstance(void *,struct _GUID const &,void * *) Unknown
uiautomationcore.dll!ATL::CComCreator2<class ATL::CComCreator<class ATL::CComObject<class CUIAutomation8> >,class ATL::CComFailCreator<-2147221232> >::CreateInstance(void *,struct _GUID const &,void * *) Unknown
uiautomationcore.dll!ATL::CComClassFactory::CreateInstance(struct IUnknown *,struct _GUID const &,void * *) Unknown
combase.dll!CServerContextActivator::CreateInstance(IUnknown * pUnkOuter, IActivationPropertiesIn * pInActProperties, IActivationPropertiesOut * * ppOutActProperties) Line 872 C++
combase.dll!ActivationPropertiesIn::DelegateCreateInstance(IUnknown * pUnkOuter, IActivationPropertiesOut * * ppActPropsOut) Line 1931 C++
combase.dll!CApartmentActivator::CreateInstance(IUnknown * pUnkOuter, IActivationPropertiesIn * pInActProperties, IActivationPropertiesOut * * ppOutActProperties) Line 2163 C++
combase.dll!CProcessActivator::CCICallback(unsigned long dwContext, IUnknown * pUnkOuter, ActivationPropertiesIn * pActIn, IActivationPropertiesIn * pInActProperties, IActivationPropertiesOut * * ppOutActProperties) Line 1631 C++
combase.dll!CProcessActivator::AttemptActivation(ActivationPropertiesIn * pActIn, IUnknown * pUnkOuter, IActivationPropertiesIn * pInActProperties, IActivationPropertiesOut * * ppOutActProperties, HRESULT(__stdcallCProcessActivator::*)(unsigned long, IUnknown *, ActivationPropertiesIn *, IActivationPropertiesIn *, IActivationPropertiesOut * *) pfnCtxActCallback, unsigned long dwContext) Line 1518 C++
combase.dll!CProcessActivator::ActivateByContext(ActivationPropertiesIn * pActIn, IUnknown * pUnkOuter, IActivationPropertiesIn * pInActProperties, IActivationPropertiesOut * * ppOutActProperties, HRESULT(__stdcallCProcessActivator::*)(unsigned long, IUnknown *, ActivationPropertiesIn *, IActivationPropertiesIn *, IActivationPropertiesOut * *) pfnCtxActCallback) Line 1384 C++
combase.dll!CProcessActivator::CreateInstance(IUnknown * pUnkOuter, IActivationPropertiesIn * pInActProperties, IActivationPropertiesOut * * ppOutActProperties) Line 1262 C++
combase.dll!ActivationPropertiesIn::DelegateCreateInstance(IUnknown * pUnkOuter, IActivationPropertiesOut * * ppActPropsOut) Line 1931 C++
combase.dll!CClientContextActivator::CreateInstance(IUnknown * pUnkOuter, IActivationPropertiesIn * pInActProperties, IActivationPropertiesOut * * ppOutActProperties) Line 561 C++
combase.dll!ActivationPropertiesIn::DelegateCreateInstance(IUnknown * pUnkOuter, IActivationPropertiesOut * * ppActPropsOut) Line 1983 C++
combase.dll!ICoCreateInstanceEx(const _GUID & OriginalClsid, IUnknown * punkOuter, unsigned long dwClsCtx, _COSERVERINFO * pServerInfo, unsigned long dwCount, unsigned long dwActvFlags, tagMULTI_QI * pResults, ActivationPropertiesIn * pActIn) Line 1915 C++
combase.dll!CComActivator::DoCreateInstance(const _GUID & Clsid, IUnknown * punkOuter, unsigned long dwClsCtx, _COSERVERINFO * pServerInfo, unsigned long dwCount, tagMULTI_QI * pResults, ActivationPropertiesIn * pActIn) Line 384 C++
[Inline Frame] combase.dll!CoCreateInstanceEx(const _GUID &) Line 176 C++
combase.dll!CoCreateInstance(const _GUID & rclsid, IUnknown * pUnkOuter, unsigned long dwContext, const _GUID & riid, void * * ppv) Line 120 C++
tiptsf.dll!CImmersiveFocusTracker::_HandleAutomationEvent(unsigned long,struct HWND__ *,long) Unknown
tiptsf.dll!CImmersiveFocusTracker::HandleAutomationEvent(unsigned long,struct HWND__ *,long) Unknown
tiptsf.dll!TabletMsgWndProc(int,unsigned int,long) Unknown
user32.dll!_DispatchHookW@16�() Unknown
user32.dll!_CallHookWithSEH@16�() Unknown
user32.dll!___fnHkINLPMSG@4�() Unknown
ntdll.dll!_KiUserCallbackDispatcher@12�() Unknown
DebugView++.exe!WTL::CCommandBarCtrlImpl<WTL::CCommandBarCtrl,WTL::CCommandBarCtrlBase,ATL::CWinTraits<1442840576,0> >::MessageHookProc(int nCode, unsigned int wParam, long lParam) Line 2747 C++
user32.dll!_DispatchHookW@16�() Unknown
user32.dll!_CallHookWithSEH@16�() Unknown
user32.dll!___fnHkINLPMSG@4�() Unknown
ntdll.dll!_KiUserCallbackDispatcher@12�() Unknown
DebugView++.exe!WTL::CMessageLoop::Run() Line 1292 C++
[Inline Frame] DebugView++.exe!fusion::debugviewpp::MessageLoop::Run() Line 61 C++
DebugView++.exe!fusion::debugviewpp::Main(HINSTANCE__ * cmdShow, HINSTANCE__ *) Line 156 C++
DebugView++.exe!wWinMain(HINSTANCE__ * hInstance, HINSTANCE__ * hPrevInstance, wchar_t * lpstrCmdLine, int nCmdShow) Line 165 C++
[Inline Frame] DebugView++.exe!invoke_main() Line 118 C++
DebugView++.exe!__scrt_common_main_seh() Line 283 C++
kernel32.dll!75848744() Unknown
[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]
ntdll.dll!__RtlUserThreadStart() Unknown
ntdll.dll!__RtlUserThreadStart@8�() Unknown
Leave a Reply