A customer had a bunch of crash dumps that showed that their code had caught an exception but then crashed anyway while trying to log the exception.<\/p>\n
Here is the stack trace at the point the crash dump was captured:<\/p>\n
00 KERNELBASE!RaiseFailFastException+0x152\r\n01 contoso!wil::details::WilDynamicLoadRaiseFailFastException+0x49\r\n02 contoso!wil::details::WilRaiseFailFastException+0x18\r\n03 contoso!wil::details::WilFailFast+0xa8\r\n04 contoso!wil::details::ReportFailure_NoReturn<3>+0x7e\r\n05 contoso!wil::details::ReportFailure_Base<3,0>+0x30\r\n06 contoso!wil::details::ReportFailure_CaughtExceptionCommon<2>+0x11c\r\n07 contoso!wil::details::ReportFailure_CaughtException<2>+0x52\r\n08 contoso!wil::details::in1diag3::Log_CaughtException+0x13\r\n09 contoso!`Contoso::SpeechRecognition::Initialize'::`1'::catch$258+0x3f\r\n0a VCRUNTIME140_1_APP!_CallSettingFrame_LookupContinuationIndex+0x20\r\n0b VCRUNTIME140_1_APP!__FrameHandler4::CxxCallCatchBlock+0x115\r\n0c ntdll!RcFrameConsolidation+0x6\r\n0d contoso!Contoso::SpeechRecognition::Initialize+0x64\r\n...\r\n<\/pre>\nReading the stack trace from the bottom up gives us the timeline.<\/p>\n
We are running the function
Speech\u00adRecognition::Initialize<\/code>. We must have encountered an exception because we reached CxxCallCatchBlock<\/code>, which is a C++ runtime function whose job is to, well, call thecatch<\/code> block.<\/p>\nWe are inside the
catch<\/code> block, which is named after the function, adding acatch<\/code> suffix.<\/p>\nThe
catch<\/code> block is trying to log the caught exception, and that’s where we ran into trouble. Here’s the code for theInitialize<\/code> method:<\/p>\nbool SpeechRecognition::Initialize()\r\n{\r\n \u27e6 ... \u27e7\r\n try\r\n {\r\n \u27e6 ... lots of code ... \u27e7\r\n return true;\r\n }\r\n catch (...)\r\n {\r\n LOG_CAUGHT_EXCEPTION();<\/span>\r\n return false;\r\n }\r\n}\r\n<\/pre>\nWe are crashing at the
LOG_CAUGHT_ EXCEPTION()<\/code> macro that is part of the Windows Implementation Library<\/a> (WIL). We learned that WIL fails fast if asked to handle an unrecognized exception<\/a>. Is that what happened here?<\/p>\n Let’s find out by looking at what was thrown.<\/p>\n
0:008> .frame b\r\n0b VCRUNTIME140_1_APP!__FrameHandler4::CxxCallCatchBlock+0x115\r\n0:008> dv\r\n pExcept = 0x00000011`cd17ba40\r\ncontinuationAddresses = void *[2]\r\n TranslatedCatch = 0n0\r\n pForeignException = 0x00000000`00000000\r\n rethrow = 0n0\r\n FrameInfo = struct FrameInfo\r\n HandlerSearchState = 0n111\r\n pSaveException = 0x00000000`00000000\r\n continuationAddress = 0x00000000`00000000\r\n pEstablisherFrame = 0x00000011`cd17bba8\r\n pSaveContext = 0x00000000`00000000\r\n pFrameInfo = 0x00000011`cd17ad18\r\n handlerAddress = 0x00007fff`486d1eeb\r\n FuncInfo = struct FH4::FuncInfo4\r\n pContext = 0x00000011`cd17c670\r\n UnwindTryState = 0n7\r\n pThisException = 0x00000011`cd17ce30\r\n<\/pre>\nNow we have to play a guessing game: Find the exception!<\/p>\n
You would think that
pExcept<\/code> would be the exception. But it doesn’t seem to be:<\/p>\n0:008> ?? pExcept\r\nstruct _EXCEPTION_RECORD * 0x00000011`cd17ba40\r\n +0x000 ExceptionCode : 0x80000029\r\n +0x004 ExceptionFlags : 0x22\r\n +0x008 ExceptionRecord : (null)\r\n +0x010 ExceptionAddress : (null)\r\n +0x018 NumberParameters : 0xf\r\n +0x020 ExceptionInformation : [15] 0x00007fff`52af2590\r\n<\/pre>\nException code
0x80000029<\/code> isSTATUS_UNWIND_ CONSOLIDATE<\/code>, which isn’t interesting to us. That’s telling us that we are unwinding due to a caught exception, but we knew that already. We really want to find the exception that triggered the unwinding.<\/p>\n Maybe
pThisException<\/code> will tell us.<\/p>\n0:008> ?? pThisException\r\nstruct EHExceptionRecord * 0x00000011`cd17ce30\r\n +0x000 ExceptionCode : 0xe06d7363\r\n +0x004 ExceptionFlags : 0x81\r\n +0x008 ExceptionRecord : (null)\r\n +0x010 ExceptionAddress : 0x00007fff`6d2b520c Void\r\n +0x018 NumberParameters : 4\r\n +0x020 params : EHExceptionRecord::EHParameters\r\n0:008> .exr 0x00000011`cd17ce30\r\nExceptionAddress: 00007fff6d2b520c (KERNELBASE!RaiseException+0x000000000000006c)\r\n ExceptionCode: e06d7363 (C++ EH exception)\r\n ExceptionFlags: 00000081\r\nNumberParameters: 4\r\n Parameter[0]: 0000000019930520\r\n Parameter[1]: 00000011cd17cf70\r\n Parameter[2]: 00007fff486fb558\r\n Parameter[3]: 00007fff48670000\r\n pExceptionObject: 00000011cd17cf70\r\n _s_ThrowInfo : 00007fff486fb558\r\n<\/pre>\nOkay, this looks a lot more like it. The exception code is
0xe06d7363<\/code>, which is the magic value used by Visual C++ for C++ exceptions. And the debugger kindly extracted the thing that was thrown, thepExceptionObject<\/code>. But first, we want to find out what the type is, because that’s the thing that WIL was unable to recognize.<\/p>\nWe can follow the cookbook for decoding the parameters of a thrown exception<\/a>.<\/p>\n
0:008> * dump the fourth DWORD at the _s_ThrowInfo\r\n0:008> dc 00007fff486fb558 L4\r\n00007fff`486fb558 00000000 00000000 00000000 0008b548 ............H...\r\n0:008> * Add that to Parameter[3] and dump the second DWORD\r\n0:008> dc 00007fff48670000+0008b548 L2\r\n00007fff`486fb548 00000001 0008b520 .... ...\r\n0:008> * Add that to Parameter[3] and dump the second DWORD (again)\r\n0:008> dc 00007fff48670000+0008b520 L2\r\n00007fff`486fb520 00000001 000920f0 ..... ..\r\n0:008> * Add that to Parameter[3] and dump the string at offset 0x10\r\n0:008> dc 00007fff48670000+000920f0+10\r\n00007fff`48702100 004b5f2e 00000000 486db370 00007fff ._K.....p.mH....\r\n<\/pre>\nHuh, the type name is
._K<\/code>. That’s weird.<\/p>\nMy guess is that this is a primitive type, because C++ name mangling uses special short names for primitive types.\u00b9<\/p>\n
Let’s see what was thrown.<\/p>\n
0:008> dps 00000011cd17cf70\r\n00000011`cd17cf70 00000000`00000003\r\n00000011`cd17cf78 00000000`00000003\r\n00000011`cd17cf80 00000000`00000003\r\n<\/pre>\nIt’s the number three.<\/p>\n
Just the number three.<\/p>\n
We can see more about the code that threw the exception by using the
pContext<\/code>:<\/p>\n0:008> .cxr 0x00000011`cd17c670\r\nrax=00007fff3a9ab31d rbx=00007fff486fb558 rcx=00000011cd17c750\r\nrdx=00007fff3a951de6 rsi=00000011cd17cf70 rdi=0000000019930520\r\nrip=00007fff6d2b520c rsp=00000011cd17ce10 rbp=000001fef78d2308\r\n r8=00007fff3aa5bf64 r9=00007fff3aae3c50 r10=00007fff3aa5cb31\r\nr11=00000011cd17c7d0 r12=000001fef78d2298 r13=000001fef78d2278\r\nr14=000001fef78d22f8 r15=00000000000000ea\r\niopl=0 nv up ei pl nz na po nc\r\ncs=0033 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000206\r\nKERNELBASE!RaiseException+0x6c:\r\n00007fff`6d2b520c 0f1f440000 nop dword ptr [rax+rax]\r\n0:008> kn\r\n *** Stack trace for last set context - .thread\/.cxr resets it\r\n # Call Site\r\n00 KERNELBASE!RaiseException+0x6c\r\n01 VCRUNTIME140_APP!_CxxThrowException+0x90\r\n02 contoso!__azac_handle_native_ex+0x50\r\n03 contoso!__azac_rethrow+0x8\r\n04 contoso!Microsoft::CognitiveServices::Speech::Intent::IntentRecognizer::FromConfig+0xaa\r\n05 contoso!Contoso::SpeechRecognition::Initialize+0x64\r\n...\r\n<\/pre>\nThe exception hasn’t unwound yet, so we can still access the stack of the
throw<\/code>.<\/p>\n0:008> * This is the C++ runtime support for throwing an exception\r\n0:008> .frame 1\r\n01 VCRUNTIME140_APP!_CxxThrowException+0x90\r\n0:008> dv\r\npExceptionObject = 0x00000011`cd17cf70\r\n pThrowInfo = <value unavailable>\r\n magicNumber = 0x19930520\r\n parameters = unsigned int64 [4]\r\n pTI = 0x00007fff`486fb558\r\n throwImageBase = 0x00007fff`48670000\r\n pWei = <value unavailable>\r\n ppWei = <value unavailable>\r\n0:008> * And here comes the function that did the throwing\r\n0:008> .frame 2\r\n02 contoso!__azac_handle_native_ex+0x50\r\n0:008> dv\r\n hr = 3\r\n error = 0\r\n errorMsg = class std::basic_string<char,std::char_traits<char>,std::allocator<char> >\r\n callstack = <value unavailable>\r\n what = <value unavailable>\r\nUnimplemented error for throwException\r\n<\/pre>\nHere’s the code<\/a> from IntentRecognizer:<\/p>\n
class IntentRecognizer :\r\n public AsyncRecognizer<\r\n IntentRecognitionResult,\r\n IntentRecognitionEventArgs,\r\n IntentRecognitionCanceledEventArgs>\r\n{\r\n \u27e6 ... \u27e7\r\n\r\n static std::shared_ptr<IntentRecognizer>\r\n FromConfig(\r\n std::shared_ptr<SpeechConfig> speechConfig,\r\n std::shared_ptr<Audio::AudioConfig> audioInput = nullptr)\r\n {\r\n SPXRECOHANDLE hreco;\r\n SPX_THROW_ON_FAIL(::recognizer_create_intent_recognizer_from_config( <\/span>\r\n &hreco, <\/span>\r\n HandleOrInvalid<SPXSPEECHCONFIGHANDLE, SpeechConfig>(speechConfig), <\/span>\r\n HandleOrInvalid<SPXAUDIOCONFIGHANDLE, Audio::AudioConfig>(audioInput)));<\/span>\r\n return std::make_shared<IntentRecognizer>(hreco);\r\n }\r\n\r\n \u27e6 ... \u27e7\r\n};\r\n<\/pre>\nThe
recognizer_create_ intent_ recognizer_ from_ config<\/code> function failed, and the SPX_THROW_ ON_ FAIL<\/code> macro threw an exception. But what is SPX_THROW_ ON_ FAIL<\/code>? We find it in spxdebug.h<\/code><\/a>:<\/p>\n#define SPX_THROW_ON_FAIL(hr) __SPX_THROW_ON_FAIL(hr)\r\n<\/pre>\nwhich is in turn defined as<\/a>:<\/p>\n
#define __SPX_THROW_ON_FAIL(hr) \\\r\n __AZAC_THROW_ON_FAIL(hr)\r\n<\/pre>\nwhich we then chase into
azac_debug.h<\/code><\/a>:<\/p>\n#define __AZAC_THROW_ON_FAIL(hr) \\\r\n do { \\\r\n AZACHR x = hr; \\\r\n if (AZAC_FAILED(x)) { \\\r\n __AZAC_THROW_HR(x); \\\r\n } } while (0)\r\n<\/pre>\nAnd
__AZAC_THROW_ HR<\/code> is<\/a><\/p>\n #ifndef __AZAC_THROW_HR\r\n#define __AZAC_THROW_HR(hr) __AZAC_THROW_HR_IMPL(hr)\r\n#endif\r\n<\/pre>\nKeep chasing<\/a>:<\/p>\n
#ifndef __AZAC_THROW_HR_IMPL\r\n#define __AZAC_THROW_HR_IMPL(hr) __azac_rethrow(hr)\r\n#endif\r\n<\/pre>\nJust a little further<\/a>:<\/p>\n
inline void __azac_rethrow(AZACHR hr)\r\n{\r\n __azac_handle_native_ex(hr, true);\r\n}\r\n<\/pre>\nAnd finally, we reach the code that throws something<\/a>.<\/p>\n
inline void __azac_handle_native_ex(AZACHR hr, bool throwException)\r\n{\r\n AZAC_TRACE_SCOPE(__FUNCTION__, __FUNCTION__);\r\n\r\n auto handle = reinterpret_cast<AZAC_HANDLE>(hr);\r\n auto error = error_get_error_code(handle);\r\n if (error == AZAC_ERR_NONE)\r\n {\r\n if (throwException)\r\n {\r\n throw hr;<\/span>\r\n }\r\n \u27e6 ... \u27e7\r\n }\r\n \u27e6 ... \u27e7\r\n}\r\n<\/pre>\nIf we look at the disassembly, we can see the mysterious
_K<\/code>.<\/p>\n00007fff`486913b3 lea rdx,[contoso!TI1_K<\/span> (00007fff`486fb558)]\r\n00007fff`486913ba lea rcx,[rsp+20h]\r\n00007fff`486913bf call contoso!CxxThrowException (00007fff`48692524)\r\n00007fff`486913c4 int 3\r\n<\/pre>\nAnd we can look up what a
AZACHR<\/code> is<\/a>:<\/p>\ntypedef uintptr_t AZACHR;\r\n<\/pre>\n