{"id":110257,"date":"2024-09-13T07:00:00","date_gmt":"2024-09-13T14:00:00","guid":{"rendered":"https:\/\/devblogs.microsoft.com\/oldnewthing\/?p=110257"},"modified":"2024-09-13T09:13:11","modified_gmt":"2024-09-13T16:13:11","slug":"20240913-00","status":"publish","type":"post","link":"https:\/\/devblogs.microsoft.com\/oldnewthing\/20240913-00\/?p=110257","title":{"rendered":"The case of the fail-fast crashes coming from the power management system"},"content":{"rendered":"

A customer reported that they were seeing around four thousand crashes a day from an internal function Rtlp\u00adHandle\u00adInvalid\u00adUser\u00adCall\u00adTarget<\/code>. Here’s one of their crash dumps:<\/p>\n

Child-SP          RetAddr               Call Site\r\n0000009b`c5bfefc8 00007ffd`e32ed7ad     ntdll!RtlFailFast2\r\n0000009b`c5bfefd0 00007ffd`e327c798     ntdll!RtlpHandleInvalidUserCallTarget+0x5d\r\n0000009b`c5bff000 00007ffd`dfdf2dee     ntdll!LdrpHandleInvalidUserCallTarget+0x38\r\n(Inline Function) --------`--------     powrprof!PowerpNotifyCallbackSafe+0x13\r\n<\/pre>\n
The Rtlp\u00adHandle\u00adInvalid\u00adUser\u00adCall\u00adTarget<\/code> function is used by  Control Flow Guard<\/a> when it detects that somebody is trying to call an invalid function pointer. So what is the invalid pointer?<\/p>\n
Since debugging is an exercise in optimism, let’s hope that the pointer is still in one of the registers.<\/p>\n
0:103> r\r\nrax=0000000000000000 rbx=00007ffd5fe8be40<\/span> rcx=000000000000000a\r\nrdx=00007ffd5fe8be40<\/span> rsi=0000000000000004 rdi=0000000000000000\r\nrip=00007ffde3292350 rsp=0000009bc5bfefc8 rbp=0000000000000000\r\n r8=0000000000000000  r9=0000000000000003 r10=0000000000000001\r\nr11=0000000000000000 r12=0000000000000000 r13=0000000000000000\r\nr14=0000009bc5bffa98 r15=000000007ffe03b0\r\nntdll!RtlFailFast2:\r\n0:103>\r\n<\/pre>\n
There are only two things that look like possible function pointers,\u00b9 and they are both equal, so let’s see if we’re lucky.<\/p>\n
0:103> u @rbx L1\r\n<Unloaded_ContosoVirtualCamera.dll>+0x7be40:\r\n00007ffd`5fe8be40 ??              ???\r\n<\/pre>\n
Bingo. Got it in one.<\/p>\n
It kind of makes sense that we’d find the function pointer in the rdx<\/code> register, since that holds the second function parameter. (The first function parameter is rcx<\/code>, which holds the fail-fast code 0x0000000A<\/code>:<\/p>\n
#define FAST_FAIL_GUARD_ICALL_CHECK_FAILURE         10\r\n<\/pre>\n
which tells us that we have a CFG failure. So it’s not too surprising that the second parameter is the pointer that failed validation.)<\/p>\n
If we wanted to be more methodical about it, we could look where the function pointer got saved. Let’s look at the code in Rtlp\u00adHandle\u00adInvalid\u00adUser\u00adCall\u00adTarget<\/code> up to the point where it called Rtl\u00adFail\u00adFast2<\/code> and see if we can follow where the function pointer went. The goal is to find a path from the start of the function to the Rtl\u00adFail\u00adFast2<\/code>, so I’ll highlight that path and de-emphasize the rest.<\/p>\n
ntdll!RtlpHandleInvalidUserCallTarget:\r\n    push    rbx                           <\/span>\r\n    sub     rsp,20h                       <\/span>\r\n    cmp     byte ptr [00007ffd`e33712a2],0<\/span>\r\n    mov     rbx,rcx \u2190 saved rcx in rbx    <\/span>\r\n    je      00007ffd`e32ed77f             <\/span>\r\n    call    ntdll!RtlpGuardIsSuppressedAddress (00007ffd`e32ed720)<\/span>\r\n    test    al,al<\/span>\r\n    je      00007ffd`e32ed77f<\/span>\r\n    mov     edx,1<\/span>\r\n    mov     rcx,rbx<\/span>\r\n    call    ntdll!RtlpGuardGrantSuppressedCallAccess (00007ffd`e32375b8)<\/span>\r\n00007ffd`e32ed778:<\/span>\r\n    add     rsp,20h<\/span>\r\n    pop     rbx<\/span>\r\n    ret<\/span>\r\n    int     3<\/span>\r\n00007ffd`e32ed77f:\r\n    call    ntdll!LdrControlFlowGuardEnforcedWithExportSuppression (00007ffd`e32234e8)<\/span>\r\n    test    eax,eax                                                                   <\/span>\r\n    je      00007ffd`e32ed7a0                                                         <\/span>\r\n    mov     rcx,rbx<\/span>\r\n    call    ntdll!RtlGuardIsExportSuppressedAddress (00007ffd`e323765c)<\/span>\r\n    test    al,al<\/span>\r\n    je      00007ffd`e32ed7a0<\/span>\r\n    mov     rcx,rbx<\/span>\r\n    call    ntdll!RtlpUnsuppressForwardReferencingCallTarget (00007ffd`e32ed7b4)<\/span>\r\n    test    eax,eax<\/span>\r\n    jns     00007ffd`e32ed778<\/span>\r\n00007ffd`e32ed7a0:\r\n    mov     rdx,rbx \u2190 rbx moved to rdx            <\/span>\r\n    mov     ecx,0Ah                               <\/span>\r\n    call    ntdll!RtlFailFast2 (00007ffd`e3292350)<\/span>\r\n<\/pre>\n
By following the flow, we see that the inbound rcx<\/code> was saved in rbx<\/code>, and then copied back to rdx<\/code> for the fail-fast. So that’s where the function pointer is, and that also explains why we see the same value in both rbx<\/code> and rdx<\/code>.<\/p>\n
The conclusion, therefore, is that the Contoso virtual camera driver registered a power management callback (hard to tell which one, but it’s going to be Power\u00adRegister\u00adSuspend\u00adResume\u00adNotification<\/code> or something like that), and they forgot to unregister it before their DLL unloaded. And then the power event occurred, and the power management system calls a callback that points to an unloaded DLL.<\/p>\n
So the next step here is to reach out to Contoso and let them know about the crashing bug in their virtual camera driver. Meanwhile, the customer can put the buggy versions of the Contoso virtual camera driver on their “do not use” list.<\/p>\n
\u00b9 Well, three if you count rip<\/code>, but that’s not interesting because that’s the current instruction pointer!<\/p>\n","protected":false},"excerpt":{"rendered":"
Understanding why it decided to fail fast.<\/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-110257","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-oldnewthing","tag-code"],"acf":[],"blog_post_summary":"
Understanding why it decided to fail fast.<\/p>\n","_links":{"self":[{"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/posts\/110257","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=110257"}],"version-history":[{"count":0,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/posts\/110257\/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=110257"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/categories?post=110257"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/tags?post=110257"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}