28 April, 2012

Stack walker для CLR x64

Сразу оговорюсь, что в принципе можно не использовать DoStackSnapshot() вообще для платформы x64 так как в наличии есть RtlLookupFunctionEntry() и RtlVirtualUnwind(). Но, я бы не рекомендовал так делать (хотя некоторые могут со мной не согласиться), потому что во время вызова DoStackSnapshot() происходят дополнительные проверки и синхронизации, которые вы не сможете сделать другими средствами. А как же GetFunctionFromIP() скажете вы? Отвечаю, что это очень простой по устройству метод, который просто не делает весь спектр необходимых проверок.

Ну начнем с простого. CLR v4.0 x64 не позволяет нам нормально ходить по стеку в асихронном режиме (основной режим для sampling профайлера), если исследуемый тред был остановлен когда он занимаелся обработкой exception или вызывал API операционеной системы. За это отвечают флаги поля ContextFlags структуры CONTEXT:

#define CONTEXT_EXCEPTION_ACTIVE    0x08000000
#define CONTEXT_SERVICE_ACTIVE      0x10000000
#define CONTEXT_EXCEPTION_REQUEST   0x40000000
#define CONTEXT_EXCEPTION_REPORTING 0x80000000
Метод DoStackSnapshot() сам вызывает clr!EEGetThreadContext и сам проверяет эти флаги, при наличии CONTEXT_EXCEPTION_ACTIVE или CONTEXT_SERVICE_ACTIVE мы гарантированно получаем ошибку. Помешать мы этому не можем и в результате нам достаются только порядка 5%-10% от реального количества managed стеков. Что делает sampling слегка бессмысленным. Ниже приведен метод clr!Thread::GetSafelyRedirectableThreadContext в котором собственно CLR и производит эту всем мешающую проверку:
000007fe`eb416868 mov  qword ptr [rsp+8],rbx
000007fe`eb41686d mov  qword ptr [rsp+10h],rsi
000007fe`eb416872 push rdi
000007fe`eb416873 sub  rsp,30h
000007fe`eb416877 cmp  qword ptr [rcx+3C8h],0
000007fe`eb41687f jne  clr!Thread::GetSafelyRedirectableThreadContext+0xb3 (000007fe`eb42db2b)
000007fe`eb416885 mov  rsi,r9
000007fe`eb416888 mov  rbx,r8
000007fe`eb41688b mov  rdi,rcx
000007fe`eb41688e test dl,2
000007fe`eb416891 je   clr!Thread::GetSafelyRedirectableThreadContext+0x38 (000007fe`eb4168a0)
000007fe`eb416893 call clr!CORDebuggerAttached (000007fe`eb2a39f4)
000007fe`eb416898 test al,al
000007fe`eb41689a jne  clr! ?? ::FNODOBFM::`string'+0x5b280 (000007fe`eb658c1b)
000007fe`eb4168a0 mov  edx,4D0h
000007fe`eb4168a5 mov  rcx,rbx
000007fe`eb4168a8 call clr!ZeroMemory (000007fe`eb2a3bf0)
000007fe`eb4168ad mov  rdx,rbx
000007fe`eb4168b0 mov  rcx,rdi
000007fe`eb4168b3 mov  dword ptr [rbx+30h],4010000Bh
000007fe`eb4168ba call qword ptr [clr!EEGetThreadContext (000007fe`ebb5d6d8)]
000007fe`eb4168c0 test eax,eax
000007fe`eb4168c2 je   clr!Thread::GetSafelyRedirectableThreadContext+0xb3 (000007fe`eb42db2b)
000007fe`eb4168c8 test dword ptr [rbx+30h],80000000h
000007fe`eb4168cf je   clr!Thread::GetSafelyRedirectableThreadContext+0x6e (000007fe`eb4168de)
000007fe`eb4168d1 test dword ptr [rbx+30h],18000000h ; <--- Искомая проверка тут
000007fe`eb4168d8 jne  clr!Thread::GetSafelyRedirectableThreadContext+0x9e (000007fe`eb42db16)
000007fe`eb4168de mov  edx,0BE0h
000007fe`eb4168e3 mov  rcx,rsi
000007fe`eb4168e6 call clr!ZeroMemory (000007fe`eb2a3bf0)
000007fe`eb4168eb xor  r8d,r8d
000007fe`eb4168ee mov  rdx,rbx
000007fe`eb4168f1 mov  rcx,rsi
000007fe`eb4168f4 call clr!FillRegDisplay (000007fe`eb355400)
000007fe`eb4168f9 mov  eax,1
000007fe`eb4168fe mov  rbx,qword ptr [rsp+40h]
000007fe`eb416903 mov  rsi,qword ptr [rsp+48h]
000007fe`eb416908 add  rsp,30h
000007fe`eb41690c pop  rdi
000007fe`eb41690d ret
Попробуйте эту проверку убрать, под WinDbg например, и метод DoStackSnapshot() заработает на полную катушку без побочных эффектов. На лицо просто бага. Которая исчезала в CLR v4.5.

Более сложно дела обстоят с CLR v2.0 x64. С флагами тут проблем нет, но попытка использрвать RtlLookupFunctionEntry() для того чтобы найти первую managed функцию на стеке в конце концов приводит к accesss violation в mscorwks!EEJitManager::GetFunctionEntry:

000007fe`f974dc34 mov  rax,qword ptr [rdx+8]
000007fe`f974dc38 mov  rcx,qword ptr [rax] ; <--- Тут падаем, так как rax ноль
000007fe`f974dc3b mov  r9d,dword ptr [rcx+20h]
000007fe`f974dc3f test r9d,r9d
000007fe`f974dc42 je   mscorwks!EEJitManager::GetFunctionEntry+0x31 (000007fe`f974dc65)
000007fe`f974dc44 mov  r8d,dword ptr [rdx+20h]
000007fe`f974dc48 lea  rax,[rcx+24h]
000007fe`f974dc4c add  r8d,dword ptr [rax]
000007fe`f974dc4f xor  edx,edx
000007fe`f974dc51 cmp  dword ptr [rax],r8d
000007fe`f974dc54 ja   mscorwks! ?? ::FNODOBFM::`string'+0x6fe0 (000007fe`f9a0b3a0)
000007fe`f974dc5a cmp  r8d,dword ptr [rax+4]
000007fe`f974dc5e jae  mscorwks! ?? ::FNODOBFM::`string'+0x6fe0 (000007fe`f9a0b3a0)
000007fe`f974dc64 ret
000007fe`f974dc65 xor  eax,eax
000007fe`f974dc67 ret
Стек исследующего выглядит вот так:
#  Child-SP          RetAddr           Call Site
00 00000000`03abd4a8 000007fe`f9c6d8b9 KERNELBASE!DebugBreak+0x2
01 00000000`03abd4b0 000007fe`f9c6dcde mscorwks!EEPolicy::LogFatalError+0x1e9
02 00000000`03abdc30 000007fe`f97b7849 mscorwks!EEPolicy::HandleFatalError+0x6e
03 00000000`03abdc80 000007fe`f96bd988 mscorwks!CLRVectoredExceptionHandlerPhase3+0xcd
04 00000000`03abdcc0 000007fe`f96bdb8f mscorwks!CLRVectoredExceptionHandlerPhase2+0x30
05 00000000`03abdd30 000007fe`f97b810e mscorwks!CLRVectoredExceptionHandler+0xff
06 00000000`03abddb0 00000000`77aaa59f mscorwks!CLRVectoredExceptionHandlerShim+0x42
07 00000000`03abddf0 00000000`77aa8e42 ntdll!RtlpCallVectoredHandlers+0xa8
08 00000000`03abde60 00000000`77ae1278 ntdll!RtlDispatchException+0x22
09 00000000`03abe540 000007fe`f974dc38 ntdll!KiUserExceptionDispatcher+0x2e
0a 00000000`03abec78 000007fe`f9783c82 mscorwks!EEJitManager::GetFunctionEntry+0x4
0b 00000000`03abec80 00000000`77b17cf9 mscorwks!GetRuntimeFunctionCallback+0x72
0c 00000000`03abed10 00000000`77aee34a ntdll!RtlpLookupDynamicFunctionEntry+0xb9
0d 00000000`03abed40 000007fe`f3b7ee6a ntdll!RtlLookupFunctionEntry+0xa3
...
Стек исследуемого треда:
Child-SP          RetAddr           Call Site
00000000`23e4b9a8 00000000`77ab9d0d 0x7ff`00e60092
00000000`23e4b9b0 00000000`77aa91af ntdll!RtlpExecuteHandlerForException+0xd
00000000`23e4b9e0 00000000`77ae1278 ntdll!RtlDispatchException+0x45a
00000000`23e4c0c0 000007fe`fe23cacd ntdll!KiUserExceptionDispatcher+0x2e
00000000`23e4c7f0 000007fe`f977923f KERNELBASE!RaiseException+0x39
00000000`23e4c8c0 000007fe`f9cb3300 mscorwks!RaiseTheExceptionInternalOnly+0x2ff
00000000`23e4c9b0 000007ff`00e7be5d mscorwks!JIT_Throw+0x130
00000000`23e4cb60 000007ff`00e7b666 0x7ff`00e7be5d
00000000`23e4cbf0 000007ff`00e9ba90 0x7ff`00e7b666
00000000`23e4ccb0 000007ff`00ffe0f4 0x7ff`00e9ba90
...
И собственно функция на которой спотыкается mscorwks:
000007ff`00e60088 mov rax,offset mscorwks!ProcessCLRException (000007fe`f96e7520)
000007ff`00e60092 jmp rax ; <--- Споткнулись тут, а могли и на строчку выше
Ситуация стабильна и возникает довольно редко (примерно раз в минуту на моем тестовом примере), но обязательно при условии когда CONTEXT_EXCEPTION_ACTIVE и CONTEXT_SERVICE_ACTIVE не установлены. Кстати делать просто проверку на эти флаги не рекомендую теряется 5%-10% важных managed стеков. Если добавить проверку на ноль для rax, то опять же все заработает на полную катушку. И естественно бага исправлена в CLR v4.0.

No comments: