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?

https://blogs.technet.com/b/askcore/archive/2009/06/12/why-is-my-2008-failover-clustering-node-blue-screening-with-a-stop-0x0000009e.aspx