Windows Explored

Everyday Windows Desktop Support, Advanced Troubleshooting & Other OS Tidbits

  • May 2012
    M T W T F S S
    « Apr   Jun »
  • Translate

  • Advertisements

Troubleshooting a “Hard Hang”

Posted by William Diaz on May 7, 2012

I recently put together a quad core system from parts my brother was retiring from his home system. Soon after getting everything up and running, the new system would sometimes hard hang while working via VPN. A hard hang is when the OS becomes completely unresponsive but is still running. I had earlier prepared myself for the next instance of this encounter by enabling CrashOnCtrlScroll in the Windows registry so that the next time it happened I could manually crash the system from the keyboard and examine the memory dump with WinDbg for signs of the responsible culprit. You can read about how to enable this option in this earlier blog Forcing a System Crash on an Unresponsive PC.

Upon opening a kernel dump, the analyze –v command is a clickable hyperlink1.

2: kd> !analyze -v
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *

The user manually initiated this crash dump.
Arg1: 0000000000000000
Arg2: 0000000000000000
Arg3: 0000000000000000
Arg4: 0000000000000000

Debugging Details:





LAST_CONTROL_TRANSFER:  from fffff880059c3ddf to fffff80002c9a640

fffff880`02f8b648 fffff880`059c3ddf : 00000000`000000e2 00000000`00000000 00000000`00000000 00000000`00000000 : nt!KeBugCheckEx
fffff880`02f8b650 fffff880`059c391b : fffffa80`03dc1e20 fffff800`02dc5fbd fffffa80`06672e40 00000000`00000040 : kbdhid!KbdHidProcessCrashDump+0x1df
fffff880`02f8b690 fffff880`05981629 : fffffa80`06461ca0 fffffa80`0643a910 fffffa80`00000000 00000000`0000000e : kbdhid!KbdHid_InsertCodesIntoQueue+0xbb
fffff880`02f8b6f0 fffff880`0598187c : fffffa80`000000c6 fffffa80`0643a910 00000000`0000000e 00000000`00000001 : HIDPARSE!HidP_KbdPutKey+0x3d
fffff880`02f8b720 fffff880`059817d2 : 00000000`00000000 fffff880`0597f9d6 00000000`00000007 fffff880`11de0000 : HIDPARSE!HidP_TranslateUsage+0x6c
fffff880`02f8b760 fffff880`059c361e : 00000000`00000000 fffffa80`06461c6c fffffa80`06461b90 00000000`00000000 : HIDPARSE!HidP_TranslateUsageAndPagesToI8042ScanCodes+0xde
fffff880`02f8b7c0 fffff800`02c9da91 : fffffa80`0632ebc3 fffff880`00000001 fffffa80`00000000 00000000`00000009 : kbdhid!KbdHid_ReadComplete+0x222
fffff880`02f8b840 fffff880`059699c4 : fffffa80`06431ed0 fffffa80`06431e06 fffffa80`06449100 00000000`00000000 : nt!IopfCompleteRequest+0x3b1
fffff880`02f8b920 fffff880`05969c2d : fffffa80`06431b02 fffffa80`06431b00 fffffa80`064491d0 00000000`00000008 : HIDCLASS!HidpDistributeInterruptReport+0x130
fffff880`02f8b9b0 fffff800`02c9da91 : fffffa80`051f1ee3 00000000`00000000 fffffa80`06449001 fffffa80`051f1c60 : HIDCLASS!HidpInterruptReadComplete+0x235
fffff880`02f8ba40 fffff880`110135d9 : fffffa80`05407050 fffffa80`03f50e00 00000000`00000000 00000000`00000000 : nt!IopfCompleteRequest+0x3b1
fffff880`02f8bb20 fffff880`11013ab7 : fffffa80`0403d002 fffffa80`051f1c60 00000000`ffffffff fffffa80`05407ea8 : USBPORT!USBPORT_Core_iCompleteDoneTransfer+0xa15
fffff880`02f8bc00 fffff880`1101164f : fffffa80`05407ea8 fffffa80`054071a0 fffffa80`05408040 00000000`00000000 : USBPORT!USBPORT_Core_iIrpCsqCompleteDoneTransfer+0x3a7
fffff880`02f8bc60 fffff880`11002f89 : fffffa80`05407050 00000000`00000000 fffffa80`05407e02 fffffa80`05407ea8 : USBPORT!USBPORT_Core_UsbIocDpc_Worker+0xf3
fffff880`02f8bca0 fffff800`02ca5b1c : fffff880`02f63180 fffffa80`05407ea8 fffffa80`05407ec0 00000000`00000000 : USBPORT!USBPORT_Xdpc_Worker+0x1d9
fffff880`02f8bcd0 fffff800`02c9236a : fffff880`02f63180 fffff880`02f6dfc0 00000000`00000000 fffff880`11002db0 : nt!KiRetireDpcList+0x1bc
fffff880`02f8bd80 00000000`00000000 : fffff880`02f8c000 fffff880`02f86000 fffff880`02f8bd40 00000000`00000000 : nt!KiIdleLoop+0x5a

Note that WinDbg points out that this is a manually initiated crash. The results are rather expected and quite generic. What we are seeing here is the USB keyboard actually telling the OS to bug check. This is a multicore PC so I need to look at the other processors by dumping their thread stacks as well. You can tell the current examine processor you are on by finding the current IRQL for the thread stack (above, this is CURRENT_IRQL: 2 or Processor 2) or by looking in the WinDbg command bar2:
To change to another processor, I use the change current processor command ~n (where n is the processor number). Afterwards, dump the processor stack with k or !thread. For example looking at the first core, or processor 0, reveals what looks like a 3rd party driver:

1: kd> ~0
0: kd> k
Child-SP          RetAddr           Call Site
fffff800`0402e950 fffff800`02c9061f nt!KxWaitForSpinLockAndAcquire+0x12
fffff800`0402e980 fffff880`11dcf953 nt!KeAcquireSpinLockAtDpcLevel+0x6f
fffff800`0402e9d0 fffff800`032089ce l160x64!MiniportProcessSGList+0x33
fffff800`0402ea20 fffff800`03208c0d hal!HalpAllocateAdapterCallback+0x146
fffff800`0402eac0 fffff800`03208825 hal!IoFreeMapRegisters+0xed
fffff800`0402eb30 fffff880`014b3831 hal!HalPutScatterGatherList+0xd5
fffff800`0402eb90 fffff880`11dcf7dd ndis!NdisMFreeNetBufferSGList+0x31
fffff800`0402ebd0 fffff880`11dcdeb5 l160x64!DmaTxInterrupt+0xc5
fffff800`0402ec10 fffff880`014b2bb6 l160x64!MiniportInterruptDPC+0x5d
fffff800`0402ec40 fffff800`02ca5b1c ndis!ndisInterruptDpc+0x1b6
fffff800`0402ecd0 fffff800`02c9236a nt!KiRetireDpcList+0x1bc
fffff800`0402ed80 00000000`00000000 nt!KiIdleLoop+0x5a

Perhaps I can get some details by looking up the module name using the list modules verbose match command:

0: kd> lmvm l160x64
start             end                 module name
fffff880`11dcc000 fffff880`11dde000   l160x64    (pdb symbols)          c:\symcache\l160x64.pdb\C94FF76A967D498A9994CF11EEF7364C1\l160x64.pdb
    Loaded symbol image file: l160x64.sys
    Image path: \SystemRoot\system32\DRIVERS\l160x64.sys
    Image name: l160x64.sys
    Timestamp:        Fri Jun 19 09:15:45 2009 (4A3B8F81)
    CheckSum:         00017BEF
    ImageSize:        00012000
    Translations:     0000.04b0 0000.04e4 0409.04b0 0409.04e4

Not enough details but I can navigate to this location and look at the file properties:
5-5-2012 1-10-44 AM
Yep, 3rd party Ethernet driver, which I was already suspicious of since the hang would only happen when I was using VPN. The other processor stacks only reveal MS kernel mode drivers or processor drivers, further isolating the cause of the hard hang to this vendor’s driver. The next course of action is to download an updated set of Ethernet drivers for this device.

1 When dealing with hangs, you may want to add an additional parameter to tell the WinDbg heuristics engine this is a hang scenario and use !analyze –v –hang instead. You may also want to use the this command after changing the processor context to the suspicious thread stack if you are unsure: For example, after changing to processor 0 with and verbose off, !analyze –hang:

kd> !analyze -hang
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *

Use !analyze -v to get detailed debugging information.

BugCheck E2, {0, 0, 0, 0}

Scanning for threads blocked on locks …
Cannot get _ERESOURCE type
Probably caused by : l160x64.sys ( l160x64!MiniportProcessSGList+33 )

Followup: MachineOwner

With verbose:

0: kd> !analyze -v -hang
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *

The user manually initiated this crash dump.
Arg1: 0000000000000000
Arg2: 0000000000000000
Arg3: 0000000000000000
Arg4: 0000000000000000

Debugging Details:

Scanning for threads blocked on locks …
Cannot get _ERESOURCE type





BLOCKED_THREAD:  fffff80002e1acc0

LAST_CONTROL_TRANSFER:  from fffff80002c9061f to fffff80002c822e2

fffff800`0402e950 fffff800`02c9061f : fffff800`02e0ce80 00000000`00000000 fffffa80`0566ad20 fffff800`0402e8e8 : nt!KxWaitForSpinLockAndAcquire+0x12
fffff800`0402e980 fffff880`11dcf953 : fffffa80`056d0968 fffff800`03209472 fffffa80`0566e330 fffffa80`056d0960 : nt!KeAcquireSpinLockAtDpcLevel+0x6f
fffff800`0402e9d0 fffff800`032089ce : fffffa80`056d0968 00000000`00000048 00000000`00000000 00000000`00000003 : l160x64!MiniportProcessSGList+0x33
fffff800`0402ea20 fffff800`03208c0d : fffffa80`05097050 fffffa80`05662880 fffffa80`05662901 00000000`00000000 : hal!HalpAllocateAdapterCallback+0x146
fffff800`0402eac0 fffff800`03208825 : fffffa80`056ca7e8 00000000`000000c0 00000000`00000000 fffffa80`04635730 : hal!IoFreeMapRegisters+0xed
fffff800`0402eb30 fffff880`014b3831 : fffffa80`041e27e0 00000000`00000000 fffffa80`0566dd48 00000000`00000000 : hal!HalPutScatterGatherList+0xd5
fffff800`0402eb90 fffff880`11dcf7dd : fffffa80`05668010 fffffa80`0566dd48 fffffa80`05668010 00000000`00300000 : ndis!NdisMFreeNetBufferSGList+0x31
fffff800`0402ebd0 fffff880`11dcdeb5 : fffffa80`05668010 00000000`00000000 fffffa80`050971a0 00000000`00300000 : l160x64!DmaTxInterrupt+0xc5
fffff800`0402ec10 fffff880`014b2bb6 : 00000000`00060248 fffffa80`056d6010 fffff800`02e0ce80 00000000`00000000 : l160x64!MiniportInterruptDPC+0x5d
fffff800`0402ec40 fffff800`02ca5b1c : fffffa80`056d6038 00000003`00000000 00000000`00000000 fffff800`02e0ce80 : ndis!ndisInterruptDpc+0x1b6
fffff800`0402ecd0 fffff800`02c9236a : fffff800`02e0ce80 fffff800`02e1acc0 00000000`00000000 fffff880`014b2a00 : nt!KiRetireDpcList+0x1bc
fffff800`0402ed80 00000000`00000000 : fffff800`0402f000 fffff800`04029000 fffff800`0402ed40 00000000`00000000 : nt!KiIdleLoop+0x5a


fffff880`11dcf953 488b1e          mov     rbx,qword ptr [rsi]


SYMBOL_NAME:  l160x64!MiniportProcessSGList+33

FOLLOWUP_NAME:  MachineOwner

MODULE_NAME: l160x64

IMAGE_NAME:  l160x64.sys


FAILURE_BUCKET_ID:  X64_0xE2_l160x64!MiniportProcessSGList+33

BUCKET_ID:  X64_0xE2_l160x64!MiniportProcessSGList+33

Followup: MachineOwner

2 Processor are numbered starting at 0, so Processor 2 is actually the third core. To quickly see how many cores there are, use the !cpuinfo command.


Leave a Reply

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: