{"id":108146,"date":"2023-05-05T07:00:00","date_gmt":"2023-05-05T14:00:00","guid":{"rendered":"https:\/\/devblogs.microsoft.com\/oldnewthing\/?p=108146"},"modified":"2023-05-05T06:56:54","modified_gmt":"2023-05-05T13:56:54","slug":"20230505-00","status":"publish","type":"post","link":"https:\/\/devblogs.microsoft.com\/oldnewthing\/20230505-00\/?p=108146","title":{"rendered":"The case of the crash in a C++\/WinRT coroutine: Unpeeling the onion"},"content":{"rendered":"

A customer had a mysterious crash in a C++\/WinRT coroutine, and they were having trouble identifying the cause. The stack of the crash looked like this:<\/p>\n

Contoso!winrt::impl::consume_Contoso_IWidgetWatcher<winrt::Contoso::IWidgetWatcher>::NotifyChange+0x3\r\nContoso!winrt::Contoso::implementation::WidgetController::SaveWidget+0x16\r\nContoso!winrt::impl::produce<winrt::Contoso::implementation::WidgetController,winrt::Contoso::IWidgetController>::SaveWidget+0x1d\r\nContoso!winrt::impl::consume_Contoso_IWidgetController<winrt::Contoso::IWidgetController>::SaveWidget+0xd\r\nContoso!winrt::Contoso::implementation::Widget::OnSettingsChanged$_ResumeCoro$1+0x31f\r\nContoso!std::experimental::coroutine_handle<void>::resume+0xc\r\nContoso!winrt::impl::await_adapter<winrt::Windows::Foundation::IAsyncAction>::await_suspend+0x15e\r\nContoso!winrt::Contoso::implementation::Widget::OnSettingsChanged$_ResumeCoro$1+0x11a\r\nContoso!winrt::Contoso::implementation::Widget::OnSettingsChanged$_InitCoro$2+0x6a\r\nContoso!winrt::Contoso::implementation::Widget::OnSettingsChanged+0x5c\r\nContoso!winrt::Windows::Foundation::TypedEventHandler<winrt::Contoso::Widget,winrt::Windows::Foundation::IInspectable>::<lambda_a7902c7784a1de3d47473a11e43d997c>::operator()+0x5b\r\nContoso!winrt::impl::delegate<winrt::Windows::Foundation::TypedEventHandler<winrt::Contoso::Widget,winrt::Windows::Foundation::IInspectable>,<lambda_a7902c7784a1de3d47473a11e43d997c> >::Invoke+0x6d\r\nrpcrt4!Invoke+0x73\r\nrpcrt4!Ndr64StubWorker+0xb8a\r\nrpcrt4!NdrStubCall3+0xd3\r\ncombase!CStdStubBuffer_Invoke+0x6f\r\ncombase!InvokeStubWithExceptionPolicyAndTracing::__l6::<lambda_c9f3956a20c9da92a64affc24fdd69ec>::operator()+0x22\r\ncombase!ObjectMethodExceptionHandlingAction<<lambda_c9f3956a20c9da92a64affc24fdd69ec> >+0x4d\r\ncombase!InvokeStubWithExceptionPolicyAndTracing+0xe1\r\ncombase!DefaultStubInvoke+0x268\r\ncombase!SyncServerCall::StubInvoke+0x41\r\ncombase!StubInvoke+0xf6\r\ncombase!ServerCall::ContextInvoke+0x366\r\ncombase!ComInvokeWithLockAndIPID+0x9aa\r\ncombase!ThreadInvokeReturnHresult+0x17b\r\ncombase!ThreadInvoke+0x193\r\nrpcrt4!DispatchToStubInCNoAvrf+0x22\r\nrpcrt4!RPC_INTERFACE::DispatchToStubWorker+0x1b4\r\nrpcrt4!RPC_INTERFACE::DispatchToStub+0xb3\r\nrpcrt4!RPC_INTERFACE::DispatchToStubWithObject+0x188\r\nrpcrt4!LRPC_SBINDING::DispatchToStubWithObject+0x23\r\nrpcrt4!LRPC_SCALL::QueueOrDispatchCall+0x253\r\nrpcrt4!LRPC_SCALL::HandleRequest+0x996\r\nrpcrt4!LRPC_SASSOCIATION::HandleRequest+0x2c3\r\nrpcrt4!LRPC_ADDRESS::HandleRequest+0x17c\r\nrpcrt4!LRPC_ADDRESS::ProcessIO+0x939\r\nrpcrt4!LrpcIoComplete+0x109\r\nntdll!TppAlpcpExecuteCallback+0x157\r\nntdll!TppWorkerThread+0x72c\r\nkernel32!BaseThreadInitThunk+0x1d\r\nntdll!RtlUserThreadStart+0x28\r\n\r\nContoso!winrt::impl::consume_Contoso_IWidgetWatcher<winrt::Contoso::IWidgetWatcher>::NotifyChange+0x3:\r\n00007ffd`ab49749d mov     rax,qword ptr [rcx] ds:00000000`00000000=????????????????\r\n<\/pre>\n
This is a big, ugly stack, but we can simplify it:<\/p>\n
Contoso!winrt::impl::consume_IWidgetWatcher::NotifyChange+0x3\r\nContoso!winrt::WidgetController::SaveWidget+0x16\r\nContoso!winrt::impl::produce<IWidgetController>::SaveWidget+0x1d\r\nContoso!winrt::impl::consume_IWidgetController::SaveWidget+0xd\r\nContoso!winrt::Widget::OnSettingsChanged$_ResumeCoro$1+0x31f\r\nContoso!std::experimental::coroutine_handle<void>::resume+0xc\r\nContoso!winrt::impl::await_adapter::await_suspend+0x15e\r\nContoso!winrt::Widget::OnSettingsChanged$_ResumeCoro$1+0x11a\r\nContoso!winrt::Widget::OnSettingsChanged$_InitCoro$2+0x6a\r\nContoso!winrt::Widget::OnSettingsChanged+0x5c\r\nContoso!winrt::TypedEventHandler::<lambda_...>::operator()+0x5b\r\nContoso!winrt::impl::delegate::Invoke+0x6d\r\n(external event machinery)\r\n<\/pre>\n
Reading from the bottom up, we start with a bunch of external event machinery, which led to the invocation of an event handler, evidently the On\u00adSettings\u00adChanged<\/code> handler.<\/p>\n
This handler is a coroutine, and it awaited something, and then upon resumption it called the WidgetController::SaveWidget<\/code> method, which called WidgetWatcher::NotifyChange<\/code>, but it crashed trying to make that call because the widget watcher is null. (We know this because rcx<\/code> is null, and we’re trying to read its vtable.)<\/p>\n
The customer’s On\u00adSettings\u00adChanged<\/code> handler looked like this:<\/p>\n
fire_and_forget Widget::OnSettingsChanged(\r\n    const SettingsManager&, const IInspectable&)\r\n{\r\n    co_await ApplySettingsAsync();\r\n    m_widgetController.SaveWidget(*this);\r\n}\r\n<\/pre>\n
The customer saw this code and smacked their forehead. “Of course, the problem is that I forgot to hold a strong reference to the widget across the co_await<\/code>.”<\/p>\n
winrt::fire_and_forget Widget::OnSettingsChanged(\r\n    const winrt::SettingsManager&, const winrt::IInspectable&)\r\n{\r\n    auto lifetime = get_strong();<\/span>\r\n    co_await ApplySettingsAsync();\r\n    m_widgetController.SaveWidget(*this);\r\n}\r\n<\/pre>\n
But their fix didn’t help. The crashes kept coming.<\/p>\n
Let’s look at that crash stack again:<\/p>\n
Contoso!winrt::Widget::OnSettingChanged$_ResumeCoro$1+0x31f\r\nContoso!std::experimental::coroutine_handle<void>::resume+0xc\r\nContoso!winrt::impl::await_adapter::await_suspend+0x15e\r\nContoso!winrt::Widget::OnSettingChanged$_ResumeCoro$1+0x11a\r\n<\/pre>\n
Reading upward, the coroutine was executing, and then decided to co_await<\/code> something. The coroutine machinery called await_suspend<\/code>, and the await_suspend<\/code> immediately resumed the coroutine, causing OnSettingChanged$_ResumeCoro$1<\/code> to be re-entered.<\/p>\n
So the coroutine never really suspended. Adding a strong reference wouldn’t have helped here, since the strong reference’s job is to keep the object alive across a suspension, which hasn’t happened. (I mean, the strong reference is still required in the case where the co_await<\/code> does suspend. I’m just saying that this particular crash didn’t involve a suspension.)<\/p>\n
Another way to observe that there was no suspension is that the stack trace leads all the way back to the external event machinery. We are still in the synchronous portion of the event handler. Nothing has suspended yet.<\/p>\n
I looked at how the event was registered:<\/p>\n
struct Widget : WidgetT<Widget>\r\n{\r\n    \/\/ other constructor parameters elided for expository purposes\r\n    Widget::Widget(const WidgetController& controller)\r\n        : m_weakController{ controller }\r\n    {\r\n        m_SettingChangedRevoker =\r\n             m_settingsWatcher.SettingChanged(winrt::auto_revoke,\r\n                { this, &Widget::OnSettingChanged })<\/span>;\r\n    }\r\n\r\nprivate:\r\n    fire_and_forget OnSettingChanged(\r\n        const SettingsManager&, const IInspectable&);\r\n\r\n    const weak_ref<WidgetController> m_weakWidgetController;\r\n    const SettingsWatcher m_settingsWatcher;\r\n    SettingsWatcher::SettingChanged_revoker m_SettingChangedRevoker;\r\n\r\n    \/\/ other members elided for expository purposes\r\n};\r\n<\/pre>\n
Notice that the event handler is registered with a raw this<\/code> pointer.<\/p>\n
Registering with a raw this<\/code> pointer means that you are taking full responsibility for ensuring that the object is alive at the time the event is received. This is manageable for events that are raised synchronously (such as UI events), since you can make sure to unregister the event handler from the thread that will raise the event, avoid the race condition where you unregister the event handler while the handler is running (or is irrevocably committed to running).<\/p>\n\n\n\n\n\n\n\n
Thread 1<\/th>\nThread 2<\/th>\n<\/tr>\n
event triggered<\/td>\n\u00a0<\/td>\n<\/tr>\n
handler()<\/td>\n\u00a0<\/td>\n<\/tr>\n
\u00a0<\/td>\nunregister handler<\/td>\n<\/tr>\n
handler still running!<\/td>\n\u00a0<\/td>\n<\/tr>\n<\/tbody>\n<\/table>\n
We can see from the stack that the Settings\u00adWatcher<\/code> object raises events from a background thread, so a raw this<\/code> capture is not safe. If the event is unregistered while a callback is in progress (or is irrevocably committed to running), the handler will have the object destructed out from under it (or possibly even have it destructed before it can execute a single instruction).<\/p>\n
In this case, the registration of the handler should be done with a weak reference.<\/p>\n
        m_SettingChangedRevoker =\r\n             m_settingsWatcher.SettingChanged(winrt::auto_revoke,\r\n                { get_weak()<\/span>, &Widget::OnSettingChanged });\r\n<\/pre>\n
The C++\/WinRT weak reference event handler pattern goes like this:<\/p>\n
auto strong = weak.get():\r\nif (strong) { (strong->*handler)(); }\r\n<\/pre>\n
C++\/WinRT tries to upgrade the weak reference to a strong reference, and if successful, it calls the event handler with the strong reference active. When the handler returns, the strong reference is released.\u00b9<\/p>\n
This particular race condition is between the event handler and the revocation of the event. This particular object doesn’t revoke the event until it destructs, and the way the program uses the Widget, we don’t expect it to be destroyed until the program shuts down, and there’s no evidence that the program is shutting down.<\/p>\n
The “object got destructed before your handler run” scenario also doesn’t seem to match the crash dump:<\/p>\n
0:019> ?? ((winrt::Contoso::implementation::WidgetController*) 0x00000262`1b9ce810)\r\nstruct winrt::Contoso::implementation::WidgetController * 0x00000262`1b9ce810\r\n   +0x010 vtable           : ...\r\n   +0x018 vtable           : ...\r\n   +0x000 __VFN_table : 0x00007ffd`ab59d940\r\n   +0x008 m_references     : std::atomic<unsigned __int64>\r\n    ...\r\n   +0x0a0 m_widgetWatcher : winrt::Contoso::WidgetWatcher\r\n\r\n0:019> ?? ((winrt::Contoso::implementation::WidgetController*) 0x00000262`1b9ce810)->m_references._Storage\r\nstruct std::_Atomic_padded<unsigned __int64>\r\n   +0x000 _Value           : 0x80000131`0e28d450\r\n\r\n0:019> dps 0x80000131`0e28d450*2\r\n00000262`1c51a8a0  00007ffd`ab5998d8 Contoso!winrt::impl::weak_ref<1,1>::`vftable'\r\n00000262`1c51a8a8  00007ffd`ab5998b8 Contoso!winrt::impl::weak_source<1,1>::`vftable'\r\n00000262`1c51a8b0  00000262`1b9ce820 \/\/ m_object - pointer to original object (matches)\r\n00000262`1c51a8b8  0000002e`00000006 \/\/ weak + strong references\r\n<\/pre>\n
The weak reference control block seems to be valid, and it shows a reasonable non-zero number of strong references, so it doesn’t seem that we’re in the “Object destructed while handler is running” scenario.<\/p>\n
So we found another bug, but not the bug that caused this crash.<\/p>\n
The crash is at the call to m_widgetWatcher.SaveWidget()<\/code>, so let’s look at that m_widgetWatcher<\/code>.<\/p>\n
0:019> ?? ((winrt::Contoso::implementation::WidgetController*) 0x00000262`1b9ce810)->m_widgetWatcher\r\nstruct winrt::Contoso::WidgetWatcher\r\n   +0x000 m_ptr            : 0x00000262`1b86ec60\r\n0:019> dps 0x00000262`1b86ec60 L2\r\n00000262`1b86ec60  00007ffd`ab5a1728 Contoso!winrt::impl::produce<WidgetWatcher,IWidgetWatcher>::`vftable'\r\n00000262`1b86ec68  00000000`00000000\r\n<\/pre>\n
Wait a second, the crash dump says that we crashed because the m_widgetWatcher<\/code> is null, but in the dump, the m_widgetWatcher<\/code> is non-null. This suggests to me that we encountered a race condition, where the m_widgetWatcher<\/code> was null at the time of the crash, but  in the time it took to create the crash dump, the value was updated<\/a>.<\/p>\n
This helped focus the next step of the investigation: Let’s look at the WidgetController<\/code> and how it initializes the WidgetWatcher<\/code>.<\/p>\n
struct WidgetController : WidgetControllerT<WidgetController>\r\n{\r\n    \/\/ constructor parameters elided for expository purposes\r\n    WidgetController(const WidgetWatcher& watcher) :\r\n        m_widget{ make<Widget>(*this) },\r\n        m_widgetWatcher{ watcher }\r\n    {\r\n    }\r\n\r\n    void SaveWidget(const Widget&);\r\n\r\nprivate:\r\n    const Widget m_widget;\r\n    const WidgetWatcher m_widgetWatcher;\r\n\r\n    \/\/ other members elided for expository purposes\r\n};\r\n<\/pre>\n
Now the story comes into focus.<\/p>\n
The non-static data members of C++ objects are constructed in order of declaration in the class.\u00b2 In this case, we construct the Widget<\/code> before we copy the WidgetWatcher<\/code>.<\/p>\n
If a setting change occurs immediately after the Widget<\/code> is constructed, then we have a race between the event callback thread (which will call back into the Widget\u00adController<\/code>) and the construction of the Widget\u00adController<\/code>‘s m_widgetWatcher<\/code>. If the event callback thread wins the race, then it will see a not-yet-constructed m_widgetWatcher<\/code> and crash.<\/p>\n
That is the race condition that we hit. The event callback thread tried to use a not-yet-constructed object.<\/p>\n
Therefore, the final step of the fix is to force the m_widget\u00adWatcher<\/code> to construct first:<\/p>\n
struct WidgetController : WidgetControllerT<WidgetController>\r\n{\r\n    \/\/ constructor parameters elided for expository purposes\r\n    WidgetController(const WidgetWatcher& watcher) :\r\n        m_widget{ make<Widget>(*this) },\r\n        m_widgetWatcher{ watcher }\r\n    {\r\n    }\r\n\r\n    void SaveWidget(const Widget&);\r\n\r\nprivate:\r\n    \/\/ Order of declaration is important:\r\n    \/\/ WidgetWatcher must construct before the Widget,\r\n    \/\/ because the Widget may call into the WidgetWatcher.\r\n    const WidgetWatcher m_widgetWatcher;\r\n    const Widget m_widget;<\/span>\r\n\r\n    \/\/ other members elided for expository purposes\r\n};\r\n<\/pre>\n
This was a rather long investigation, with two red herrings! I don’t know whether you enjoyed it, but you can’t get that time back now.<\/p>\n
\u00b9 Note that if the handler is a coroutine, the handler “returns” at the point the coroutine first suspends, not when the coroutine runs to completion. That’s why we need the get_strong()<\/code> inside the coroutine body: To keep the object alive through to completion.<\/p>\n
\u00b2 Note that the order in which the initializers are given in the constructor are irrelevant. It is the order of declaration in the class that controls the order of construction.<\/p>\n
struct Example\r\n{\r\n    Example() : b{ 1 }, a{ 2 } {}\r\n\r\n    Thing1 a;\r\n    Thing2 b;\r\n};\r\n<\/pre>\n
In this example class, the a<\/code> member is constructed first, and then the b<\/code> member is constructed second. You might think that b<\/code> is constructed first because it is listed first in the constructor, but that’s not the case.<\/p>\n
If construction occurred in order of initialization, and two constructors initialized the members in different orders, then the destructor would be unable to follow the rule that objects are destructed in the same order of construction, because the destructor doesn’t know which constructor was used.\u00b3<\/p>\n
\u00b3 I guess you could solve this problem by adding a hidden member variable that keeps track of which order the members were constructed, but this adds runtime costs and would likely be surprising to programmers that it’s possible that adding a constructor to a class, even one that is never called, can change its size.<\/p>\n","protected":false},"excerpt":{"rendered":"
Digging deeper and deeper.<\/p>\n","protected":false},"author":1069,"featured_media":111744,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[1],"tags":[25],"class_list":["post-108146","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-oldnewthing","tag-code"],"acf":[],"blog_post_summary":"
Digging deeper and deeper.<\/p>\n","_links":{"self":[{"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/posts\/108146","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/users\/1069"}],"replies":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/comments?post=108146"}],"version-history":[{"count":0,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/posts\/108146\/revisions"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/media\/111744"}],"wp:attachment":[{"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/media?parent=108146"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/categories?post=108146"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/tags?post=108146"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}