Troubleshooting Básico de Bug Check 0x9E (USER_MODE_HEALTH_MONITOR)
Autor: Denis Passos / Revisão: Marcelo Fontes
Não é incomum recebermos Dumps para análise de Bug Check 9E gerados numa situação onde a máquina/componentes estão parcialmente ou totalmente travados.
Windows Server 2008 Failover Cluster usa o mecanismo de controle Watchdog para identificar se o Cluster está operacional periodicamente, via heartbeat. Caso o componente não responda em um intervalo de 60 segundos (default), o componente é considerado como “Inoperante ou Travado”e uma das ações configuradas na propriedade HangRecoveryAction será executada:
0 = Desabilita mecanismo de heartbeat e monitoramento
1 = Registra um evento no log System do Event Viewer.
2 = Finaliza o serviço de cluster
3 = Causa um Stop Error (Bugcheck 9E) no Cluster node (Este opção é defaut para Windows Server 2008)
Veja links de referência , no final do Blog, para mais informações sobre o mecanismo e modificações.
O Dump abaixo foi gerado em um cenário onde intermitentemente 7 nodes de um cluster falhavam intermitentemente várias vezes ao dia com bugcheck 9E
O objetivo da análise é identificar o processo que não respondeu ao heartbeat, dentro do tempo esperado (60 segundos), e por qual motivo.
6: kd> !analyze -v
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************
USER_MODE_HEALTH_MONITOR (9e)
One or more critical user mode components failed to satisfy a health check.
Hardware mechanisms such as watchdog timers can detect that basic kernel
services are not executing. However, resource starvation issues, including
memory leaks, lock contention, and scheduling priority misconfiguration,
may block critical user mode components without blocking DPCs or
draining the nonpaged pool.
Kernel components can extend watchdog timer functionality to user mode
by periodically monitoring critical applications. This bugcheck indicates
that a user mode health check failed in a manner such that graceful
shutdown is unlikely to succeed. It restores critical services by
rebooting and/or allowing application failover to other servers.
Arguments:
Arg1: fffffa8032824b30, Process that failed to satisfy a health check within the
configured timeout
Arg2: 00000000000004b0, Health monitoring timeout (seconds)
Arg3: 0000000000000000
Arg4: 0000000000000000
O próximo passo é exibir mais informações do processo fffffa8032824b30 usando o comando !process
6: kd> !process fffffa8032824b30
PROCESS fffffa8032824b30
SessionId: 0 Cid: 0e18 Peb: 7fffffd7000 ParentCid: 032c
DirBase: 8196f7000 ObjectTable: fffff8a0066740d0 HandleCount: 422.
Image: rhs.exe
VadRoot fffffa807076c100 Vads 236 Clone 0 Private 1843. Modified 2. Locked 0.
DeviceMap fffff8a0000088c0
Token fffff8a006ae5060
ElapsedTime 00:24:58.939
UserTime 00:00:00.312
KernelTime 00:00:01.107
QuotaPoolUsage[PagedPool] 0
QuotaPoolUsage[NonPagedPool] 0
Working Set Sizes (now,min,max) (3107, 50, 345) (12428KB, 200KB, 1380KB)
PeakWorkingSetSize 3110
VirtualSize 81 Mb
PeakVirtualSize 82 Mb
PageFaultCount 3195
MemoryPriority BACKGROUND
BasePriority 13
CommitCharge 2154
THREAD fffffa8032518b60 Cid 0e18.0dd8 Teb: 000007fffff7a000 Win32Thread: 0000000000000000 WAIT: (Executive) KernelMode Non-Alertable
fffff880073b7a80 NotificationEvent
IRP List:
fffffa8070683910: (0006,03a0) Flags: 00060030 Mdl: 00000000
Not impersonating
DeviceMap fffff8a0000088c0
Owning Process fffffa8032824b30 Image: rhs.exe
Attached Process N/A Image: N/A
Wait Start TickCount 58882 Ticks: 76853 (0:00:19:58.914)
Context Switch Count 79
UserTime 00:00:00.000
KernelTime 00:00:00.015
Win32 Start Address 0x00000000777bfbc0
Stack Init fffff880073b8db0 Current fffff880073b7780
Base fffff880073b9000 Limit fffff880073b3000 Call 0
Neste ponto identificamos que o processo RHS.exe (Resource Hosting Subsystem) não respondeu ao heartbeat dentro do intervalo default de 60 segundos.
O próximo passo será identificar o motivo pelo qual o processo rhs.exe não conseguiu responder ao heartbeat.
Notamos acima que o processo RHS possui uma IRP aberta (solicitação de I/O em andamento) que potencialmente está em execução por vários minutos (0:00:19:58.914).
A seguir mais informações sobre esta IRP com o comando !irp:
6: kd> !irp fffffa8070683910
Irp is active with 6 stacks 3 is current (= 0xfffffa8070683a70)
No Mdl: System buffer=fffffa807068b7c0: Thread fffffa8032518b60: Irp stack trace.
cmd flg cl Device File Completion-Context
[ 0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
[ 0, 0] 0 0 00000000 00000000 00000000-00000000
Args: 00000000 00000000 00000000 00000000
>[ e, 0] 5 e0 fffffa8031eaa060 fffffa803288e0f0 fffff88001236dd0-fffff880073b7bd0 Success Error Cancel
\Driver\<3º party driver>
Args: 00000000 00000008 002d5014 fffffa80321cd680
[ e, 0] 5 e1 fffffa80321a4060 fffffa803288e0f0 fffff880014e2dec-fffff880073b8370 Success Error Cancel pending
\Driver\mpio
Args: 00000000 00000008 002d5014 fffffa80321cd680
[ e, 0] 5 0 fffffa80321c1ca0 fffffa803288e0f0 00000000-00000000
\Driver\<3º party driver>
Args: 00000000 00000008 002d5014 00000000
[ e, 0] 5 0 fffffa80321dc060 fffffa803288e0f0 00000000-00000000
\Driver\Disk
Args: 00000000 00000008 002d5014 00000000
O Sinal > identificado acima indica o driver atualmente que processa a solicitação de I/O (IRP).
Neste ponto precisamos levantar mais evidências para saber se a IRP fffffa8070683910 está travada no driver <3º party driver>, o que não significa necessariamente que este driver é o causador, pois o processamento da IRP pode continuar por vários layers.
Neste caso a IRP estava travada num driver de 3º responsável por passar informações para HBA, o fabricante do driver foi envolvido e identificou que a versão do driver instalado recentemente não era compatível com o firmware da storage.
Ao instalar a versão correta do driver o problema foi resolvido.
Existem diversas causas que podem causar travamento de um componente sendo monitorado pelo Watchdog como: falta de memória, contenção de disco, alta CPU, problemas de sincronização, etc... Porém, o cenário acima é um dos mais frequentes onde o processo sendo monitorado não responde ao heartbeat, visto que está aguardando a resposta de I/O (IRP) ou travado no driver apontado pelo sinal >
É possível investigar mais adiante detalhes da extensão do dispositivo apontado, assim como o modelo, fabricante e qual o status do dispositivo.
No próximo blog iremos analisar mais informações sobre IRPs para certificar qual driver ou drivers potencialmente travando a solicitação de I/O.
Referências:
HangRecoveryAction
https://msdn.microsoft.com/en-us/library/windows/desktop/aa369104(v=vs.85).aspx
IRP
https://msdn.microsoft.com/en-us/library/windows/hardware/ff550694(v=vs.85).aspx
Why is my 2008 Failover Clustering node blue screening with a Stop 0x0000009E?