Thursday, January 29, 2015

CPU starvation

Our system has a monitoring thread to detect and report CPU starvation on each core if any. When the monitored thread runs on any core, the monitoring thread will record its execution time. If any monitored thread has not been run for more than the pre-defined threshold (e.g., 5 seconds), the monitoring thread will report it and panic if running with debugging version code.
Below is an example of Windows panic due to CPU starvation detected by this monitoring thread and how to find out which core is starved and why?
First, windbg "!analyze -v" will tell you its panic due that monitoring thread.
And the traces/logs will also indicate the same thing like (XXX means some sensitive information):

11:17:34.311    2163276 FFFFF88003706040 XXX: 'PerCpu 3 Watchdog' Warning, Last Refresh: 109ms above 100ms count: 1.
11:17:34.935     623969 FFFFF880009DD040 XXX Interrupt missed, scheduling port thread
11:17:35.153     218392 FFFFF880009DD040 XXX Interrupt missed, scheduling port thread
...
11:17:39.630     931055 FFFFF880009DD040 *** STUCK_DETECTION_THRESHOLD 5000000us exceeded, this==FFFFFA80205A0620, thread: FFFFFA80205AA040
11:17:39.630          5 FFFFF880009DD040 Assertion Failed:  (0)
11:17:39.630         14 FFFFF880009DD040 at XXX

Note the windows panic time is (Windbg is set to UTC+8, while the crashed system is UTC):

2: kd> .time
Debug session time: Thu Jan 15 19:17:39.680 2015 (UTC + 8:00)
System Uptime: 0 days 0:10:29.819

Let check the starved thread:

2: kd>  dt _KTHREAD FFFFFA80205AA040 -r1
nt!_KTHREAD
...
   +0x218 Affinity         : _GROUP_AFFINITY
      +0x000 Mask             : 8
      +0x008 Group            : 0
      +0x00a Reserved         : [3] 0
   +0x228 IdealProcessor   : 3
   +0x22c UserIdealProcessor : 3

Or a more specific command:

2: kd>  dt _KTHREAD FFFFFA80205AA040 Affinity.Mask
nt!_KTHREAD
   +0x218 Affinity      :
      +0x000 Mask          : 8

Affinity.Mask of 8 means this thread affine to core 3 ( 8 == 1 << 3). So the monitored thread on core 3 was starved! So, let's look at what's currently running on core 3?
2: kd> ~3
3: kd> !thread
THREAD fffffa81e708fb60  Cid 0f88.6540  Teb: 000007fffffd9000 Win32Thread: 0000000000000000 RUNNING on processor 3
Not impersonating
DeviceMap                 fffff8a0020c0c60
Owning Process            fffffa8016025b30       Image:         sppsvc.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      40024          Ticks: 348 (0:00:00:05.428)
Context Switch Count      2              IdealProcessor: 0            
UserTime                  00:00:00.000
KernelTime                00:00:05.428
Win32 Start Address 0x0000000076fefbc0
Stack Init fffff8857661cc70 Current fffff8857661c680
Base fffff8857661d000 Limit fffff88576617000 Call 0
Priority 8 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Args to Child                                                           : Call Site
fffff885`7661c9b0 fffff800`022cec9c : fffffa80`158f6100 fffff885`7661ca68 fffff885`7661ca88 00000000`00000001 : nt!KxWaitForLockOwnerShip+0x34
fffff885`7661c9e0 fffff800`022e1f13 : fffffa81`e708fb60 00000000`770d45c0 fffff885`00000102 00000000`0027ca00 : nt!NtWaitForWorkViaWorkerFactory+0x41b
fffff885`7661cae0 00000000`77022c1a : 00000000`76fefe0b 00000000`0027d101 00000000`00000000 00000000`770d45e8 : nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffff885`7661cae0)
00000000`00cef5f8 00000000`76fefe0b : 00000000`0027d101 00000000`00000000 00000000`770d45e8 00000000`770d4610 : 0x77022c1a
00000000`00cef600 00000000`0027d101 : 00000000`00000000 00000000`770d45e8 00000000`770d4610 00000000`00000000 : 0x76fefe0b
00000000`00cef608 00000000`00000000 : 00000000`770d45e8 00000000`770d4610 00000000`00000000 00000000`00000000 : 0x27d101



It's waiting on a lock and notice the KernelTime is 00:00:05.428, meaning it has been running and waiting for more than 5 seconds.

And it also shows several pending DPCs on core:
3: kd> !dpcs
...
*** ERROR: Module load completed but symbols could not be loaded for bxvbda.sys
 3: Normal  : 0xfffffa800aaaedd0 0xfffff88001307940 bxvbda
 3: Normal  : 0xfffffa800aae0dd0 0xfffff88001307940 bxvbda
 3: Normal  : 0xfffff8800368d9e8 0xfffff800023fdb60 nt!PpmPerfAction
 3: Normal  : 0xfffff881e0f12ba0 0xfffff88002adb820 XXX
 3: Normal  : 0xfffff881e1b12af8 0xfffff88002adb820 XXX
 3: Normal  : 0xfffff881dcf12da0 0xfffff88002adb820 XXX
 3: Normal  : 0xfffff881ddb12cf8 0xfffff88002adb820 XXX
 3: Normal  : 0xfffff881de512cf8 0xfffff88002adb820 XXX
 3: Normal  : 0xfffff881def12cf8 0xfffff88002adb820 XXX
 3: Normal  : 0xfffff881ddb11fd8 0xfffff88002adb820 XXX

And core 3 also has several READY threads, also meaning it's starved:
3: kd> !ready 7
...
Processor 3: Ready Threads at priority 15
    THREAD fffffa81d7ba7040  Cid 0004.02e4  Teb: 0000000000000000 Win32Thread: 0000000000000000 READY on processor 3
    Not impersonating
    DeviceMap                 fffff8a0000094a0
    Owning Process            fffffa8009d1a9e0       Image:         System
    Attached Process          N/A            Image:         N/A
    Wait Start TickCount      40026          Ticks: 346 (0:00:00:05.397)
    Context Switch Count      18199          IdealProcessor: 0            
    UserTime                  00:00:00.000
    KernelTime                00:00:00.156
    Win32 Start Address EmcPAL!EmcpalThreadTransitPoint (0xfffff880021a8a40)
    Stack Init fffff881e9a25c70 Current fffff881e9a255b0
    Base fffff881e9a26000 Limit fffff881e9a20000 Call 0
    Priority 15 BasePriority 15 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
    Child-SP          RetAddr           : Args to Child                                                           : Call Site
    fffff881`e9a255f0 fffff800`022e7f22 : fffff880`00000003 fffffa81`d7ba7040 fffff880`00000000 fffff880`1b9c9ae0 : nt!KiSwapContext+0x7a
    fffff881`e9a25730 fffff800`022ea73f : fffff880`03771fc0 fffff880`021a8a40 fffff881`00000000 fffff880`399a3240 : nt!KiCommitThreadWait+0x1d2
    fffff881`e9a257c0 fffff880`021a83e0 : 00000000`00000300 fffff881`00000000 fffff880`1b9c9a00 fffff881`e9d96600 : nt!KeWaitForSingleObject+0x19f
    fffff881`e9a25860 fffff881`e9d966d5 : fffff881`00000003 fffff881`ea033318 00000000`00000080 fffff881`ea033318 : XXX
    fffff881`e9a258a0 fffff881`e9c2d2c8 : fffff881`00000003 fffffa80`15bb8400 00000000`00000008 00000000`00000000 : XXX
    fffff881`e9a25920 fffff880`021a8b19 : fffffa81`d7ba7040 ffffffff`4d2fa200 fffffa80`1566e950 00000000`0000ffff : XXX
    fffff881`e9a25950 fffff800`0257e14a : fffffa81`d7ba7040 fffffa80`09d1a9e0 fffff881`e9a25c70 fffffa81`d7ba7040 : XXX
    fffff881`e9a25c00 fffff800`022d45c6 : fffff880`0376d180 fffffa81`d7ba7040 fffff880`03778040 00000000`00000200 : nt!PspSystemThreadStartup+0x5a
    fffff881`e9a25c40 00000000`00000000 : fffff881`e9a26000 00000000`00000000 00000000`00000000 00000000`00000000 : nt!KiStartSystemThread+0x16

Processor 3: Ready Threads at priority 13
    THREAD fffffa8009d90040  Cid 0004.0058  Teb: 0000000000000000 Win32Thread: 0000000000000000 READY on processor 3
    Not impersonating
    DeviceMap                 fffff8a0000094a0
    Owning Process            fffffa8009d1a9e0       Image:         System
    Attached Process          N/A            Image:         N/A
    Wait Start TickCount      40090          Ticks: 282 (0:00:00:04.399)
    Context Switch Count      14622          IdealProcessor: 0            
    UserTime                  00:00:00.000
    KernelTime                00:00:04.336
    Win32 Start Address nt!ExpWorkerThread (0xfffff800022ecee0)
    Stack Init fffff880039a8c70 Current fffff880039a7e60
    Base fffff880039a9000 Limit fffff880039a3000 Call 0
    Priority 13 BasePriority 12 UnusualBoost 1 ForegroundBoost 0 IoPriority 2 PagePriority 5
    Child-SP          RetAddr           : Args to Child                                                           : Call Site
    fffff880`039a7ea0 fffff800`022b79fa : fffff880`009d2180 fffffa80`09d90040 fffffa80`09d90240 00000000`00000000 : nt!KiSwapContext+0x7a
    fffff880`039a7fe0 fffff800`022b802c : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : nt!KeSetSystemGroupAffinityThread+0x18a
    fffff880`039a8050 fffff800`0259f989 : fffffa80`09d1acc0 0053002b`002b0010 00000001`00000048 fffff880`00280026 : nt!PopExecuteOnTargetProcessors+0xdc
    fffff880`039a80f0 fffff800`025ecb91 : 00000000`00000003 00000000`00000006 00000000`00000000 00000000`00000000 : nt!PoGetIdleTimes+0xd9
    fffff880`039a8150 fffff800`025ed599 : fffff8a0`02d12148 fffffa80`6365734b 00000000`00000003 fffff880`039a8ae0 : nt!ExpQuerySystemInformation+0x1001
    fffff880`039a8500 fffff800`022e1f13 : fffff880`039a0000 fffff800`022e0ebd 00000000`00000041 fffff8a0`02d12000 : nt!NtQuerySystemInformation+0x4d
    fffff880`039a8540 fffff800`022de4b0 : fffff880`01973fe4 00000000`00020000 fffff880`039a8704 fffff8a0`02d12120 : nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffff880`039a8540)
    fffff880`039a86d8 fffff880`01973fe4 : 00000000`00020000 fffff880`039a8704 fffff8a0`02d12120 00000000`00000000 : nt!KiServiceLinkage
    fffff880`039a86e0 fffff880`019744dd : fffffa80`0ab89a10 fffff800`022eaf83 fffff8a0`20206f49 fffff8a0`00df8010 : cng!GatherRandomKey+0x294
    fffff880`039a8aa0 fffff800`025d9b4d : 00000000`00000001 00000000`00000001 00000000`00000000 fffffa80`09d90040 : cng!scavengingWorkItemRoutine+0x3d
    fffff880`039a8b40 fffff800`022ecff1 : fffff800`025c6d00 fffffa80`09d90001 00000000`00000000 00000000`00000096 : nt!IopProcessWorkItem+0x3d
    fffff880`039a8b70 fffff800`0257e14a : 00000000`00000000 fffffa80`09d90040 00000000`00000080 fffffa80`09d1a9e0 : nt!ExpWorkerThread+0x111
    fffff880`039a8c00 fffff800`022d45c6 : fffff880`0376d180 fffffa80`09d90040 fffff880`03778040 00000000`00000000 : nt!PspSystemThreadStartup+0x5a
    fffff880`039a8c40 00000000`00000000 : fffff880`039a9000 fffff880`039a3000 fffff880`039a88a0 00000000`00000000 : nt!KiStartSystemThread+0x16

Processor 3: Ready Threads at priority 8
    THREAD fffffa81e03d4060  Cid 08c4.0960  Teb: 000000007ef9e000 Win32Thread: 0000000000000000 READY on processor 3
    Not impersonating
    DeviceMap                 fffff8a0000094a0
    Owning Process            fffffa81e03d4b30       Image:         XXX
    Attached Process          N/A            Image:         N/A
    Wait Start TickCount      40073          Ticks: 299 (0:00:00:04.664)
    Context Switch Count      1013           IdealProcessor: 0            
    UserTime                  00:00:00.000
    KernelTime                00:00:00.000
    Win32 Start Address 0x0000000010041968
    Stack Init fffff881e8511c70 Current fffff881e85116f0
    Base fffff881e8512000 Limit fffff881e850c000 Call 0
    Priority 8 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
    Child-SP          RetAddr           : Args to Child                                                           : Call Site
    fffff881`e8511730 fffff800`022b2fa5 : fffff880`009d2180 fffffa81`e03d4060 fffff880`009d2180 00000000`00000004 : nt!KiSwapContext+0x7a
    fffff881`e8511870 fffff800`0226a3d7 : fffffa81`e03d4b30 fffff881`e8511b60 fffffa81`e03d4060 00000000`00000008 : nt!KiProcessDeferredReadyList+0x111
    fffff881`e85118b0 fffff800`025acc86 : fffff881`e8511b00 00000000`00000400 00000000`00000000 fffff881`e8511b60 : nt!KeSetLegacyAffinityThread+0xd3
    fffff881`e8511920 fffff800`022e1f13 : fffffa81`e03d4060 fffffa81`e03d4060 fffff881`e8511ab8 00000000`000001bc : nt!NtSetInformationThread+0x915
    fffff881`e8511ae0 00000000`770213ea : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffff881`e8511ae0)
    00000000`0250e678 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : 0x770213ea

Let's take the READY thread of fffffa81d7ba7040 on core 3 as an example, its Wait Start TickCount is 40026, while current TickCount is 40372:
3: kd> !kuser
_KUSER_SHARED_DATA at fffff78000000000
TickCount:    f99a027 * 0000000000009db4 (0:00:10:29.807)
TimeZone Id: 0
ImageNumber Range: [8664 .. 8664]
Crypto Exponent: 0
SystemRoot: 'C:\Windows'
3: kd> .formats 9db4
Evaluate expression:
  Hex:     00000000`00009db4
  Decimal: 40372
...

So this thread has been in READY for about 346 (40372 - 400026) ticks, which equals about 5.4 seconds! The other two threads on core 3 have the similar situation, including the starved monitored thread. Note the monitored thread is in STANDBY, not READY.

3: kd> !thread FFFFFA80205AA040
THREAD fffffa80205aa040  Cid 0004.0600  Teb: 0000000000000000 Win32Thread: 0000000000000000 STANDBY
Not impersonating
DeviceMap                 fffff8a0000094a0
Owning Process            fffffa8009d1a9e0       Image:         System
Attached Process          N/A            Image:         N/A
Wait Start TickCount      40042          Ticks: 330 (0:00:00:05.148)
Context Switch Count      54232          IdealProcessor: 0            
UserTime                  00:00:00.000
KernelTime                00:00:00.421
Win32 Start Address EmcPAL!EmcpalThreadTransitPoint (0xfffff880021a8a40)
Stack Init fffff881e758ac70 Current fffff881e758a630
Base fffff881e758b000 Limit fffff881e7585000 Call 0
Priority 17 BasePriority 15 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Args to Child                                                           : Call Site
fffff881`e758a670 fffff800`022e7f22 : fffffa80`205aa040 fffffa80`205aa040 00000000`00000000 00000000`0000000a : nt!KiSwapContext+0x7a
fffff881`e758a7b0 fffff800`022ea73f : fffffa80`205a06c8 00000000`00000014 00000000`00000059 00000000`00000001 : nt!KiCommitThreadWait+0x1d2
fffff881`e758a840 fffff880`021a83e0 : 00000000`00000000 fffff881`00000000 fffffa80`205a0600 fffffa80`205a0600 : nt!KeWaitForSingleObject+0x19f

So, let's check why the current thread on core 3 was hogging CPU?

3: kd> !thread
THREAD fffffa81e708fb60  Cid 0f88.6540  Teb: 000007fffffd9000 Win32Thread: 0000000000000000 RUNNING on processor 3
Not impersonating
DeviceMap                 fffff8a0020c0c60
Owning Process            fffffa8016025b30       Image:         sppsvc.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      40024          Ticks: 348 (0:00:00:05.428)
Context Switch Count      2              IdealProcessor: 0            
UserTime                  00:00:00.000
KernelTime                00:00:05.428
Win32 Start Address 0x0000000076fefbc0
Stack Init fffff8857661cc70 Current fffff8857661c680
Base fffff8857661d000 Limit fffff88576617000 Call 0
Priority 8 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Child-SP          RetAddr           : Args to Child                                                           : Call Site
fffff885`7661c9b0 fffff800`022cec9c : fffffa80`158f6100 fffff885`7661ca68 fffff885`7661ca88 00000000`00000001 : nt!KxWaitForLockOwnerShip+0x34
fffff885`7661c9e0 fffff800`022e1f13 : fffffa81`e708fb60 00000000`770d45c0 fffff885`00000102 00000000`0027ca00 : nt!NtWaitForWorkViaWorkerFactory+0x41b
fffff885`7661cae0 00000000`77022c1a : 00000000`76fefe0b 00000000`0027d101 00000000`00000000 00000000`770d45e8 : nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffff885`7661cae0)
00000000`00cef5f8 00000000`76fefe0b : 00000000`0027d101 00000000`00000000 00000000`770d45e8 00000000`770d4610 : 0x77022c1a
00000000`00cef600 00000000`0027d101 : 00000000`00000000 00000000`770d45e8 00000000`770d4610 00000000`00000000 : 0x76fefe0b
00000000`00cef608 00000000`00000000 : 00000000`770d45e8 00000000`770d4610 00000000`00000000 00000000`00000000 : 0x27d101

3: kd> uf nt!KxWaitForLockOwnerShip+0x34
...
nt!KxWaitForLockOwnerShip:
fffff800`023143a0 48895c2408      mov     qword ptr [rsp+8],rbx
fffff800`023143a5 57              push    rdi
fffff800`023143a6 4883ec20        sub     rsp,20h
fffff800`023143aa 4883490801      or      qword ptr [rcx+8],1
fffff800`023143af 488bf9          mov     rdi,rcx
fffff800`023143b2 48890a          mov     qword ptr [rdx],rcx
fffff800`023143b5 33db            xor     ebx,ebx
fffff800`023143b7 660f1f0400      nop     word ptr [rax+rax]
nt!KxWaitForLockOwnerShip+0x20:
fffff800`023143bc ffc3            inc     ebx
fffff800`023143be 851d780f2000    test    dword ptr [nt!HvlLongSpinCountMask (fffff800`0251533c)],ebx
fffff800`023143c4 0f84efb2faff    je      nt! ?? ::FNODOBFM::`string'+0x5d90 (fffff800`022bf6b9)
nt!KxWaitForLockOwnerShip+0x2e:
fffff800`023143ca f390            pause
nt!KxWaitForLockOwnerShip+0x30:
fffff800`023143cc 488b4f08        mov     rcx,qword ptr [rdi+8]
fffff800`023143d0 f6c101          test    cl,1
fffff800`023143d3 75e7            jne    
nt!KxWaitForLockOwnerShip+0x20 (fffff800`023143bc)
nt!KxWaitForLockOwnerShip+0x39:
fffff800`023143d5 f0830c2400      lock or dword ptr [rsp],0
fffff800`023143da 0faee8          lfence
fffff800`023143dd 8bc3            mov     eax,ebx
fffff800`023143df 488b5c2430      mov     rbx,qword ptr [rsp+30h]
fffff800`023143e4 4883c420        add     rsp,20h
fffff800`023143e8 5f              pop     rdi
fffff800`023143e9 c3              ret
3: kd> r
rax=0000000000000000 rbx=00000000253598ce rcx=fffffa8015e14321
rdx=fffffa80795cbdc0 rsi=0000000000000102 rdi=fffff8857661ca28
rip=fffff800023143d0 rsp=fffff8857661c9b0 rbp=fffff8857661cb60
 r8=fffff8857661c600  r9=0000000000000000 r10=0000000000000028
r11=fffffa8016aa0408 r12=fffffa80158f6160 r13=fffff88003689180
r14=fffffa8015e14320 r15=0000000000000001
iopl=0         nv up ei pl nz na pe nc
cs=0010  ss=0018  ds=0000  es=0000  fs=0000  gs=0000             efl=00000202
nt!KxWaitForLockOwnerShip+0x34:
fffff800`023143d0 f6c101          test    cl,1
3: kd> dqs rdi+8
fffff885`7661ca30  fffffa80`15e14321
fffff885`7661ca38  00000000`0027ca00

If a thread is waiting for a lock, the lock must be held by someone else or the lock is corrupted.
The RUNNING threads don't show anyone is holding a lock:
3: kd> !running -t
System Processors:  (000000000000003f)
  Idle Processors:  (0000000000000011) (0000000000000000) (0000000000000000) (0000000000000000)
       Prcbs             Current         (pri) Next            (pri) Idle
  1    fffff880009a0180  fffff880009ab040 ( 0) fffffa80205a9b60 (15) fffff880009ab040  ................
Child-SP          RetAddr           Call Site
fffff880`009c7780 fffff880`024588c8 tcpip!WfpProcessInTransportStackIndication+0x5e
fffff880`009c7910 fffff880`0245d7b8 tcpip!InetInspectReceiveDatagram+0x1d8
fffff880`009c79b0 fffff880`0245afda tcpip!TcpTcbReceive+0x11c
fffff880`009c7ac0 fffff880`0245bd6b tcpip!TcpMatchReceive+0x1fa
fffff880`009c7c10 fffff880`0243719a tcpip!TcpPreValidatedReceive+0x36b
fffff880`009c7ce0 fffff800`022ef618 tcpip!IppLoopbackTransmit+0x11a
fffff880`009c7d90 fffff880`02437aaf nt!KeExpandKernelStackAndCalloutEx+0xd8
fffff880`009c7e70 fffff880`0245aa30 tcpip!IppLoopbackEnqueue+0x22f
fffff880`009c7f20 fffff880`0246192c tcpip!IpNlpFastSendDatagram+0x1370
fffff880`009c8050 fffff880`02487b66 tcpip!TcpTcbSend+0x43c
fffff880`009c82d0 fffff880`02487506 tcpip!TcpFlushDelay+0x316
fffff880`009c83b0 fffff800`022ee5ec tcpip!TcpPeriodicTimeoutHandler+0x3f9
fffff880`009c8430 fffff800`022ee486 nt!KiProcessTimerDpcTable+0x6c
fffff880`009c84a0 fffff800`022ee36e nt!KiProcessExpiredTimerList+0xc6
fffff880`009c8af0 fffff800`022ee157 nt!KiTimerExpiration+0x1be
fffff880`009c8b90 fffff800`022da9aa nt!KiRetireDpcList+0x277
fffff880`009c8c40 00000000`00000000 nt!KiIdleLoop+0x5a
  2    fffff880009d2180  fffff880009dd040 ( 0) fffffa8009d95980 (18) fffff880009dd040  ................
Child-SP          RetAddr           Call Site
fffff880`009fa1c8 fffff881`e839bb1a nt!KeBugCheckEx
fffff880`009fa1d0 fffff881`e839b223 XXX
fffff880`009fa210 fffff881`e839b7ac XXX
fffff880`009fa260 fffff881`e839a2e1 XXX
fffff880`009fa2b0 fffff881`e839ac3f XXX
fffff880`009fa300 fffff880`0212bcd6 XXX
fffff880`009fa360 fffff880`0209392a XXX
fffff880`009fa430 fffff800`022ee486 nt!KiProcessTimerDpcTable+0x6c
fffff880`009fa4a0 fffff800`022ee36e nt!KiProcessExpiredTimerList+0xc6
fffff880`009faaf0 fffff800`022ee157 nt!KiTimerExpiration+0x1be
fffff880`009fab90 fffff800`022da9aa nt!KiRetireDpcList+0x277
fffff880`009fac40 00000000`00000000 nt!KiIdleLoop+0x5a
  3    fffff88003689180  fffffa81e708fb60 ( 8) fffffa80205aa040 (17) fffff88003694040  ................
Child-SP          RetAddr           Call Site
fffff885`7661c9b0 fffff800`022cec9c nt!KxWaitForLockOwnerShip+0x34
fffff885`7661c9e0 fffff800`022e1f13 nt!NtWaitForWorkViaWorkerFactory+0x41b
fffff885`7661cae0 00000000`77022c1a nt!KiSystemServiceCopyEnd+0x13
00000000`00cef5f8 00000000`76fefe0b 0x77022c1a
00000000`00cef600 00000000`0027d101 0x76fefe0b
00000000`00cef608 00000000`00000000 0x27d101
  5    fffff8800376d180  fffffa800ac22b60 (17)                       fffff88003778040  ................
Child-SP          RetAddr           Call Site
fffff880`0379cdc0 fffff880`0212b5fb XXX
fffff880`0379ce20 fffff880`02238123 XXX
fffff880`0379cf00 fffff800`022e5755 nt!KiRetireDpcList+0x1bc
fffff880`0379cfb0 fffff800`022e556c nt!KyRetireDpcList+0x5
fffff880`03de5520 fffff800`0232e993 nt!KiDispatchInterruptContinue
fffff880`03de5550 fffff800`022deb62 nt!KiDpcInterruptBypass+0x13
fffff880`03de5560 fffff800`0222d2c3 nt!KiInterruptDispatch+0x212
fffff880`03de56f0 fffff800`0222ca7b hal!HalpTscStallExecutionProcessor+0xbf
fffff880`03de5750 fffff880`021c97c7 hal!KeStallExecutionProcessor+0x183
fffff880`03de5780 fffff880`021c9d50 XXX

And the thread on core 3 was waiting on the lock's address at rdi+8, and its value is fffffa8015e14321, which doesn't look like a valid lock. So, the lock is probably corrupted by some bad guy.

No comments:

Post a Comment