[Articulo] BSOD - PANTALLA AZUL - Cómo analizar el error (Parte 2)

VOLCADO DE MEMORIA (DMP o DUMP). ANALISIS DE LOS ARCHIVOS


Un vez configurado tal y como está descrito anteriormente, procedemos a
abrir el DUMP con windbg, en el menur "File" y la opcion "Open Crash Dump".
Podemos abrir cualquier archivo de dump, estemos o no en la maquina que ha
causado el casque. Incluso puede abrirse en remoto por ADSL, por ejemplo y
aunque el DUMP será de muchas megas, normalmente con solo leer la cabecera y
poco más, estará en disposicion de ver datos. En este caso vamos a abrir el
DUMP desde otra maquina por red.

NOTA 1: la primera vez que analizamos un dump de un determiando sistema
operativo (o con parches especificos), se bajará automaticamente del sistio
de Microsoft los ficheros de simbolos necesarios. Por ello, debemos estar
conectados a internet y puede que esa primera vez tarde unos minutos en
bajarselos.


Este es un "casque" real en un W2003 Server que está actuando como
Controlador de Dominio. Estaba seleccionada la opcion de "kernel dump". EN
la pantalla azul, unicamente informó de MULTIPLE_IRP_COMPLETE_REQUESTS sin
dar mas informacion sobre el modulo causante del fallo.

Lo primero que debemos fijarnos en un DUMP es si en las lineas de cabecera
cabecera nos indica si está "corrupto". Si lo etuviese, no no vale para
nada.

NOTA 2: Un dump puede estar corrupto, si tenemos la opcion de DUMP completo
de memoria y el fichero de paginacion reside en otra unudad fisica. En ese
caso, deberemos esperar a repetir el error una vez hayamos puesto el fichero
de paginacion en la misma unidad que windows.

Resultado del analizador: (es conveniente leer todos, ya que nos va
indicando, version del sistema operativo, parches instalados, etc...) Y
sobre todo la parte final:

Microsoft (R) Windows Debugger Version 6.4.0007.2
Copyright (c) Microsoft Corporation. All rights reserved.


Loading Dump File [\\ka000SRV\d$\WINDOWS\MEMORY.DMP]
Kernel Summary Dump File: Only kernel address space is available

Symbol search path is:
SRV*c:\websymbols*http://msdl.microsoft.com/download/symbols
Executable search path is:
Windows Server 2003 Kernel Version 3790 (Service Pack 1) MP (4 procs) Free
x86 compatible
Product: LanManNt, suite: TerminalServer SingleUserTS
Built by: 3790.srv03_sp1_rtm.050324-1447
Kernel base = 0x80800000 PsLoadedModuleList = 0x808af988
Debug session time: Thu May 19 19:32:53.800 2005 (GMT+2)
System Uptime: 0 days 0:05:14.483
Loading Kernel Symbols
.
Loading unloaded module list
.
Loading User Symbols
PEB is paged out (Peb.Ldr = 7ffd800c). Type ".hh dbgerr001" for details
*******************************************************************************
*
*
* Bugcheck Analysis
*
*
*
*******************************************************************************

Use !analyze -v to get detailed debugging information.

BugCheck 44, {87e5a490, d75, 0, 0}

*** ERROR: Module load completed but symbols could not be loaded for
ax88172.sys
*** ERROR: Module load completed but symbols could not be loaded for
portmap.sys
*** ERROR: Module load completed but symbols could not be loaded for
PfModNT.sys
*** ERROR: Module load completed but symbols could not be loaded for
nfsrdr.sys
*** ERROR: Module load completed but symbols could not be loaded for
dump_Fasttrak.sys
*** ERROR: Module load completed but symbols could not be loaded for
winacusb.sys
*** ERROR: Module load completed but symbols could not be loaded for vmm.sys
*** ERROR: Module load completed but symbols could not be loaded for
ctac32k.sys
*** ERROR: Module load completed but symbols could not be loaded for
ctsfm2k.sys
*** ERROR: Module load completed but symbols could not be loaded for
emupia2k.sys
*** ERROR: Module load completed but symbols could not be loaded for
ha10kx2k.sys
*** ERROR: Module load completed but symbols could not be loaded for
hap16v2k.sys
*** ERROR: Module load completed but symbols could not be loaded for
ctoss2k.sys
*** ERROR: Symbol file could not be found. Defaulted to export symbols for
drmk.sys -
*** ERROR: Module load completed but symbols could not be loaded for
ctaud2k.sys
*** ERROR: Module load completed but symbols could not be loaded for
e100b325.sys
*** ERROR: Module load completed but symbols could not be loaded for
lstone2k.sys
*** ERROR: Module load completed but symbols could not be loaded for
el90xbc5.sys
*** ERROR: Module load completed but symbols could not be loaded for
MTXPARHM.sys
*** ERROR: Module load completed but symbols could not be loaded for pfc.sys
*** ERROR: Module load completed but symbols could not be loaded for
drmkaud.sys
*** ERROR: Module load completed but symbols could not be loaded for
ASAPIW2k.sys
*** ERROR: Module load completed but symbols could not be loaded for
MTXPARHD.dll
*** ERROR: Module load completed but symbols could not be loaded for
netmate2.sys
*** ERROR: Symbol file could not be found. Defaulted to export symbols for
rpcxdr.sys -
*** ERROR: Module load completed but symbols could not be loaded for
Fasttrak.sys
*** ERROR: Module load completed but symbols could not be loaded for
VMNetSrv.sys
*** ERROR: Module load completed but symbols could not be loaded for
TSKNF601.SYS
*** ERROR: Module load completed but symbols could not be loaded for
ctprxy2k.sys
*** ERROR: Module load completed but symbols could not be loaded for
PSXDRV.SYS
*** ERROR: Module load completed but symbols could not be loaded for
memalloc.sys
*************************************************************************
*** ***
*** ***
*** Your debugger is not using the correct symbols ***
*** ***
*** In order for this command to work properly, your symbol path ***
*** must point to .pdb files that have full type information. ***
*** ***
*** Certain .pdb files (such as the public OS symbols) do not ***
*** contain the required information. Contact the group that ***
*** provided you with these symbols if you need this command to ***
*** work. ***
*** ***
*** Type referenced: ocaData ***
*** ***
*************************************************************************
Probably caused by : usbehci.sys

Followup: MachineOwner


==


Bien, esta es la primera informacion del error. Aparece un nombre de modulo
candidato: usbehci.sys el cual corresponde a uno de los drivers del propio
windows para USB. Al menos ya sabemos que el casque está provocado por
"algo" que está en el bus USB.
Es extraño, a no ser un error hardware, que un driver del propio Microsoft
sea el causante.

Fijemonos que en una linea superior, la propia salida del debugger nos
aconseja:

**** Use !analyze -v to get detailed debugging information.

Por tanto en la linea inferior de la pantalla, procedemos a ejecutar ese
comando:




0: kd> !analyze -v

*******************************************************************************
*
*
* Bugcheck Analysis
*
*
*
*******************************************************************************

MULTIPLE_IRP_COMPLETE_REQUESTS (44)
A driver has requested that an IRP be completed (IoCompleteRequest()), but
the packet has already been completed. This is a tough bug to find because
the easiest case, a driver actually attempted to complete its own packet
twice, is generally not what happened. Rather, two separate drivers each
believe that they own the packet, and each attempts to complete it. The
first actually works, and the second fails. Tracking down which drivers
in the system actually did this is difficult, generally because the trails
of the first driver have been covered by the second. However, the driver
stack for the current request can be found by examining the DeviceObject
fields in each of the stack locations.
Arguments:
Arg1: 87e5a490, Address of the IRP
Arg2: 00000d75
Arg3: 00000000
Arg4: 00000000

Debugging Details:



IRP_ADDRESS: 87e5a490

DEFAULT_BUCKET_ID: DRIVER_FAULT

BUGCHECK_STR: 0x44

CURRENT_IRQL: 2

DEVICE_OBJECT: 8a055618

DRIVER_OBJECT: 8a14eaa8

IMAGE_NAME: usbehci.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 42435bb3

MODULE_NAME: usbehci

FAULTING_MODULE: ba27b000 usbehci

LAST_CONTROL_TRANSFER: from 808596ec to 8087b6be

STACK_TEXT:
f789ee10 808596ec 00000044 87e5a490 00000d75 nt!KeBugCheckEx+0x1b
f789ee48 ba11ddc4 87e5a490 88770eb0 8a0e1028 nt!IopfCompleteRequest+0x2f7
f789eeb0 ba11ea45 b70989c0 00000000 8083b28b
USBPORT!USBPORT_CompleteTransfer+0x38c
f789eee0 ba11f558 026e6f44 8a0e10e0 8a0e10e0
USBPORT!USBPORT_DoneTransfer+0x137
f789ef18 ba120d58 8a0e1028 8083b28b 8a0e1230
USBPORT!USBPORT_FlushDoneTransferList+0x168
f789ef44 ba12eef2 8a0e1028 8083b28b 8a0e1028 USBPORT!USBPORT_DpcWorker+0x224
f789ef80 ba12f06a 8a0e1028 00000001 ffdffa40
USBPORT!USBPORT_IsrDpcWorker+0x380
f789ef9c 8083eb0f 8a0e164c 6b755044 00000000 USBPORT!USBPORT_IsrDpc+0x166
f789eff4 8083a92b b76d5d44 00000000 00000000 nt!KiRetireDpcList+0xca


STACK_COMMAND: .bugcheck ; kb

FOLLOWUP_NAME: MachineOwner

FAILURE_BUCKET_ID: 0x44_IMAGE_usbehci.sys_DATE_3_25_2005

BUCKET_ID: 0x44_IMAGE_usbehci.sys_DATE_3_25_2005

Followup: MachineOwner




La salida del comando nos ta la explicacion de por que ocurre un
MULTIPLE_IRP_COMPLETE_REQUESTS, basicamente nos informa que un driver ha
solicitado la ejecucion de un IRP (IoCompleteRequest) pero el paquete ya
habia sido completado. No dice que es un problema no resuelto por el
software y dificil de encontrar ya que en el mejor de los casos, un driver
errorneo que pidió su propio paquete dos veces, no suele ser lo que ha
sucedido. Nos dice igualmente que lo mas probable es que dos drivers
diferentes cada uno de ellos, se cree que el paquete es suyo y hacen
intentos para completarlo. Por ultimo indica que seguir la pista de esto no
suele ser facil.

Veamos que se equivoca, y que al menos en nuestro caso es sencillo de seguir
;-)

Si no fijamos igualmente en la parte anterior, nos da la direccion del IRP
en estas lineas:

Arguments:
Arg1: 87e5a490, Address of the IRP
Arg2: 00000d75
Arg3: 00000000
Arg4: 00000000

Por tanto, vamos a pedir al debugguer que nos puestre el contenido de esa
direccion ejecutando el comando: !IRP con la direccion anterior:

=


0: kd> !IRP 87e5a490
Irp is active with 3 stacks 3 is current (= 0x87e5a548)
No Mdl Thread 00000000: 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

[ f, 0] 0 c0 8a055618 00000000 b69de300-00000000 Success Error

\Driver\usbehci ax88172
Args: b70989c0 00000000 00220003 00000000

=
Esta ultima linea, nos da todos los drivers que han intervenido "creyendo"
que un paquete era suyo y han intentado completar la peticion. Y al ni ser
realmente suya es lo que ha provocado el fallo del sistema. Vemos en la
penultima linea que son:

\Driver\usbehci ax88172

El primero corresponde al stack USB de windows y el segundo a un
"dudoso" y no certificado driver de un dispositvo de red (una NIC LAN
10/100). El aix88712 es el chip que monta y su driver se llama igual.

Por tanto. ya sabemos quien ha sido el culpable :-)

==
¿ha sido sencillo no? os animo a que investigueis cada caso y me ofrezco
a daros soporte a estas salidad y las dudas que vayan surgiendo, en los
grupos de noticias de MS.



Jose Manuel Tella Llop
MVP - Windows
jmtella@XXXcompuserve.com (quitar XXX)
http://www.multingles.net/jmt.htm

Este mensaje se proporciona "como está" sin garantías de ninguna clase,
y no otorga ningún derecho.

This posting is provided "AS IS" with no warranties, and confers no
rights.
You assume all risk for your use.