虫趣:FAST_MUTEX死锁

拿到一个dump文件后,经过简单分析,是设备驱动在处理电源IRP时,超时未完成导致的。这是一个典型的0x9F BSOD错误:

DRIVER_POWER_STATE_FAILURE (9f)
A driver has failed to complete a power IRP within a specific time (usually 10 minutes).
Arguments:
Arg1: 0000000000000003, A device object has been blocking an Irp for too long a time
Arg2: fffffa800182aa90, Physical Device Object of the stack
Arg3: fffff800139e9930, nt!TRIAGE_9F_POWER on Win7, otherwise the Functional Device Object of the stack
Arg4: fffffa8002437e10, The blocked IRP

自动分析的内容告诉我:在处理地址为fffffa8002437e10的电源IRP(IRP_MJ_POWER)时,超时(一般10分钟)未能完成,所以引发了系统0x9F蓝屏。自动分析同时列出了当前线程(处理此IRP的线程)调用栈:

Child-SP          RetAddr           Call Site
fffff880`181ab5e0 fffff800`169137cb nt!KiSwapContext(void)+0x76
(Inline Function) --------`-------- nt!KiSwapThread+0xfa
fffff880`181ab720 fffff800`1691260f nt!KiCommitThreadWait+0x23b
fffff880`181ab7e0 fffff800`16977acd nt!KeWaitForSingleObject+0x1cf 
fffff880`181ab870 fffff800`16920255 nt!ExpAcquireFastMutexContended+0x3d
(Inline Function) --------`-------- nt!ExAcquireFastMutex+0x38 
fffff880`181ab8b0 fffff880`046208b6 nt!KeAcquireGuardedMutex(struct _FAST_MUTEX * Mutex = 0xfffffa80`044e81e0)+0x45 
// 中间省略ModuleA的调用
fffff880`181abca0 fffff800`168a2fd9 nt!PopIrpWorker(void * Context = )+0x284
fffff880`181abd50 fffff800`169577e6 nt!PspSystemThreadStartup
fffff880`181abda0 00000000`00000000 nt!KxStartSystemThread(void)+0x16

从调用栈能够看到,线程因为在等待一个同步对象,而进入了休眠状态。从字面上看,这是一个FAST_MUTEX对象。如果能够得到这个对象的地址,就太好了。我试图加载NT模块的私有符号,很幸运成功了。切换到函数KeAcquireGuardedMutex的调用帧后,得到了同步对象的有效信息:

0: kd> dt _fast_mutex 0xfffffa80`044e81e0
nt!_FAST_MUTEX
   +0x000 Count            : 0n4
   +0x008 Owner            : 0xfffffa80`02c8d7c0 Void
   +0x010 Contention       : 8
   +0x018 Event            : _KEVENT
   +0x030 OldIrql          : 0

调试最担心的问题就是地址无效,比较有效的方法是通过关键值的比对,判断地址的有效性。这里我感兴趣的是Owner变量,是这个FAST_MUTEX对象的拥有者线程。如果地址正确的话,我就能够得到一个线程调用栈。切过去看看:

0: kd> !thread 0xfffffa80`02c8d7c0
//省略summary
nt!KiSwapContext+0x76 
nt!KiSwapThread+0xfa (Inline Function @ fffff800`169137cb) 
nt!KiCommitThreadWait+0x23b 
nt!KeWaitForSingleObject+0x1cf 
nt!MiWaitForInPageComplete+0xb8 
nt!MiIssueHardFault+0x1b7 
nt!MmAccessFault+0x81f 
nt!KiPageFault+0x16e (TrapFrame @ fffff880`03b3a810) 
//中间省略ModuleA的调用
nt!PspSystemThreadStartup+0x59 
nt!KxStartSystemThread+0x16

地址是有效的,并且得到的调用栈中也有一堆ModuleA的函数。问题到此可告一段落了:

  1. 线程1在处理IRP_MJ_POWER的时候,试图获取一个FAST_MUTEX同步对象,但因获取失败而进入休眠状态(并因休眠过久,而导致BSOD)。
  2. 在成功获取FAST_MUTEX对象的地址后,从它的结构体中得到了当前拥有此同步对象的线程2地址。
  3. 切换到线程2,发现线程2有一个无法处理的页错误,也同样处于等待状态中。

这个问题到目前为止,可判定是一个死锁问题。只要线程2能够及时释放它所拥有的FAST_MUTEX对象就可以了。但更深层的原因则是线程2竟然因为一个页错误而陷入长时间的等待,得不到解决。由于这个中间的模块是一个保密模块,本人无权限分析。所以到这里为止我的任务就结束了,接下来要让ModuleA模块的部门做进一步分析。

6,430 total views, 1 views today

《虫趣:FAST_MUTEX死锁》有6个想法

  1. 再问一下:

    1. 如何切换到函数KeAcquireGuardedMutex的调用帧?比如说什么命令?

    2. 张老师,为什么说这个问题是由模块A导致的?有点跳,没理解.
    由于这个中间的模块是一个保密模块,本人无权限分析。所以到这里为止我的任务就结束了,接下来要让ModuleA模块的部门做进一步分析。

    3. 我也碰到相同的问题,但!analyze -v OUTPUT is:

    我的感觉是,既然有TIMEOUT的问题,肯定与DEADLOCK有一定关系.
    否则不太可能产生如此长时间的IRP不能完全的问题.
    这个问题是在DPC处理过程中产生的(KiExecuteAllDpcs),但STACK TRACE中的PopIrpWatchdog,不是特别明白.
    张老师,请指点一下,如何进一步?

    DRIVER_POWER_STATE_FAILURE (9f)
    A driver has failed to complete a power IRP within a specific time.
    Arguments:
    Arg1: 00000003, A device object has been blocking an Irp for too long a time
    Arg2: 85be34c0, Physical Device Object of the stack
    Arg3: 836c5a00, nt!TRIAGE_9F_POWER on Win7 and higher, otherwise the Functional Device Object of the stack
    Arg4: bcd5eaa0, The blocked IRP

    Debugging Details:
    ——————

    DRVPOWERSTATE_SUBCODE: 3

    DRIVER_OBJECT: 8e146d88

    IMAGE_NAME: UsbHub3.sys

    DEBUG_FLR_IMAGE_TIMESTAMP: 51ce4697

    MODULE_NAME: UsbHub3

    FAULTING_MODULE: 91496000 UsbHub3

    DEFAULT_BUCKET_ID: WIN8_DRIVER_FAULT

    BUGCHECK_STR: 0x9F

    PROCESS_NAME: System

    CURRENT_IRQL: 2

    ANALYSIS_VERSION: 6.3.9600.16384 (debuggers(dbg).130821-1623) x86fre

    DPC_STACK_BASE: FFFFFFFF836CA000

    STACK_TEXT:
    836c59d8 82522894 0000009f 00000003 85be34c0 nt!KeBugCheckEx
    836c5a10 825228c7 a8124490 00000000 825fb558 nt!PopIrpWatchdogBugcheck+0xb0
    836c5a28 825c56fb a81244d8 a8124490 4cbf50c5 nt!PopIrpWatchdog+0x28
    836c5ae0 825c6e81 836ae330 836c5b28 b74a2900 nt!KiExecuteAllDpcs+0x1f2
    836c5c00 8255a3f4 00000000 0000000e 00000000 nt!KiRetireDpcList+0xed
    836c5c04 00000000 0000000e 00000000 00000000 nt!KiIdleLoop+0x38

    STACK_COMMAND: kb

    FOLLOWUP_NAME: MachineOwner

    IMAGE_VERSION: 6.2.9200.16654

    FAILURE_BUCKET_ID: 0x9F_VRF_3_POWER_DOWN_IMAGE_UsbHub3.sys

    BUCKET_ID: 0x9F_VRF_3_POWER_DOWN_IMAGE_UsbHub3.sys

    ANALYSIS_SOURCE: KM

    FAILURE_ID_HASH_STRING: km:0x9f_vrf_3_power_down_image_usbhub3.sys

    FAILURE_ID_HASH: {24a7695b-3b1b-f4c1-c0d4-fe69b9b34182}

    Followup: MachineOwner
    ———

    1. 1. .frame x命令可以切换,在call视图中,双击某一帧也能切换。
      2. 因为模块A的名字已经列出来了。通过dump分析到这个地步,已经有充足理由让模块A做进一步分析。
      3. 用!irp bcd5eaa0看这个IRP是哪个设备栈在处理。然后要定位和此设备驱动有关的调用栈,通过!stacks命令可以列出栈。另外,我提供无偿的dump服务:http://www.yiiyee.cn/Blog/dumpservice/

  2. 张老师,

    似乎BSOD DUMP FILE不可以使用CALLS 双击来切换FRAMES?

    另外有个问题,为什么STACK TRACE中的函数,后面都有一个+0xXXXX的OFFSET?
    既然是一个函数调用,那每个函数都是从一开始(0x0)执行,这个OFFSET是什么意思呢?

匿名进行回复 取消回复

电子邮件地址不会被公开。