Hi Alex,
2009/9/28 Alexandru Carp :
> I don’t see filter manager on that stack. Maybe you don’t have symbols ?
>
Yes… I’m not sure why, but I needed to .reload to persuade WinDbg
to get the symbols. The traces are more sensible now
> Anyway, since the thread is waiting on a resource, I would start by calling !locks on that resource.
>
It looks like I’m deadlocking with RDBSS for a resource (I’m attached
to a network file system).
First, this is the resource I think I’m deadlocking on:
Resource @ 0x820b5018 Exclusively owned
Contention Count = 1
NumberOfExclusiveWaiters = 1
Threads: 8206d020-01<*>
Threads Waiting On Exclusive Access:
8208a538
The thread holding this resource is the rdbss worker thread:
lkd> !thread 8206d020 7
THREAD 8206d020 Cid 0004.00c0 Teb: 00000000 Win32Thread: 00000000
WAIT: (Executive) KernelMode Non-Alertable
f745dbb0 SynchronizationEvent
IRP List:
8206e620: (0006,0190) Flags: 00000404 Mdl: 00000000
Not impersonating
DeviceMap e10001f8
Owning Process 0 Image:
Attached Process 823c6a00 Image: System
Wait Start TickCount 8273 Ticks: 16323 (0:00:04:15.046)
Context Switch Count 220
UserTime 00:00:00.000
KernelTime 00:00:00.015
DBGHELP: rdbss - public symbols
c:\symcache\rdbss.pdb\B8FBFEC3A9EC42BCBAF08AC6F4CB01E12\rdbss.pdb
Start Address rdbss!RxWorkerThreadDispatcher (0xf813293d)
Stack Init f745e000 Current f745db3c Base f745e000 Limit f745b000 Call 0
Priority 14 BasePriority 8 PriorityDecrement 5 DecrementCount 16
ChildEBP RetAddr Args to Child
f745db54 80503846 8206d090 8206d020 804fb078 nt!KiSwapContext+0x2f
(FPO: [Uses EBP] [0,0,4])
f745db60 804fb078 8206e630 8206e620 820b8808 nt!KiSwapThread+0x8a (FPO: [0,0,0])
f745db88 80583b0e 00000000 00000000 00000000
nt!KeWaitForSingleObject+0x1c2 (FPO: [5,5,4])
f745dbd4 805bb472 000b8808 00000000 820b87f0 nt!IopDeleteFile+0x148
(FPO: [1,9,4])
f745dbf0 805266da 820b8808 00000000 00000000
nt!ObpRemoveObjectRoutine+0xe0 (FPO: [2,1,4])
f745dc08 8050a89a 00000000 8209d468 00000000
nt!ObfDereferenceObject+0x4c (FPO: [0,0,0])
f745dc30 8050b426 e10b31c8 8209d498 00000000 nt!MiSegmentDelete+0xec
(FPO: [1,5,4])
f745dc54 8050f8a5 8209d468 00000000 820b5000
nt!MiCheckControlArea+0x1c4 (FPO: [3,3,4])
f745dca0 804e5e6e 820b5000 01000000 e121c808 nt!MmPurgeSection+0x57d
(FPO: [4,11,0])
f745dccc f81355c3 820b500c 00000000 00000000
nt!CcPurgeCacheSection+0x100 (FPO: [4,2,4])
f745dcf4 f813a0ab e1260008 00000000 00000000
rdbss!RxPurgeFcbInSystemCache+0x6b (FPO: [5,2,0])
f745dd1c f8132591 e11cd930 f81321e0 822b1e68
rdbss!RxPurgeFobxFromCache+0x5f (FPO: [1,0,4])
f745dd4c f8132848 822b1b58 821df030 f8131fc0
rdbss!RxScavengerFinalizeEntries+0x119 (FPO: [1,6,4])
f745dd6c f81284b1 822b1b58 00000000 8206d020
rdbss!RxScavengerTimerRoutine+0x53 (FPO: [1,2,4])
f745dd9c f8132957 00131fc0 f8132240 f745dddc
rdbss!RxpWorkerThreadDispatcher+0x93 (FPO: [2,6,4])
f745ddac 805cff70 f8131fc0 00000000 00000000
rdbss!RxWorkerThreadDispatcher+0x1a (FPO: [1,0,0])
f745dddc 805460ee f813293d f8131fc0 00000000
nt!PspSystemThreadStartup+0x34 (FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
and the thread waiting on exclusive access is my userspace thread.
The wepcFilter calls are my minifilter:
lkd> !thread 8208a538 7
THREAD 8208a538 Cid 04dc.05f8 Teb: 7ffde000 Win32Thread: 00000000
WAIT: (Executive) KernelMode Non-Alertable
8223f328 SynchronizationEvent
8208a628 NotificationTimer
IRP List:
82094cc0: (0006,0094) Flags: 00000000 Mdl: 00000000
Not impersonating
DeviceMap e1837bc8
Owning Process 0 Image:
Attached Process 822ea4b0 Image: wepc-us.exe
Wait Start TickCount 27085 Ticks: 45 (0:00:00:00.703)
Context Switch Count 646
UserTime 00:00:00.000
KernelTime 00:00:00.000
Win32 Start Address windbg!WinSymbol::UpdateNames (0x0104b7e0)
Start Address kernel32!BaseThreadStartThunk (0x7c8106f9)
Stack Init f73ea000 Current f73e9864 Base f73ea000 Limit f73e7000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 16
DBGHELP: mrxsmb - public symbols
c:\symcache\mrxsmb.pdb\9ABEB1460B13404F800EA4FFFD6667932\mrxsmb.pdb
DBGHELP: fltMgr - public symbols
c:\symcache\fltMgr.pdb\30197425FFC04385B84C0354E5035D5C1\fltMgr.pdb
SYMSRV: c:\symcache\wepcFilter.pdb\F59465AEFFCE4C23BE09416CA827C4681\wepcFilter.pdb
not found
SYMSRV: http://msdl.microsoft.com/download/symbols/wepcFilter.pdb/F59465AEFFCE4C23BE09416CA827C4681/wepcFilter.pdb
not found
DBGHELP: wepcFilter - private symbols & lines
y:\src\wepc\filter\objchk_wxp_x86\i386\wepcFilter.pdb
ChildEBP RetAddr Args to Child
f73e987c 80503846 8208a5a8 8208a538 804fb078 nt!KiSwapContext+0x2f
(FPO: [Uses EBP] [0,0,4])
f73e9888 804fb078 00000000 820b5018 8208a538 nt!KiSwapThread+0x8a (FPO: [0,0,0])
f73e98b0 80535d5c 00000000 00000000 00000000
nt!KeWaitForSingleObject+0x1c2 (FPO: [5,5,4])
f73e98ec 805361b4 00000000 82087670 8206ed01
nt!ExpWaitForResource+0xd4 (FPO: [0,5,0])
f73e990c f8133ff2 820b5018 8206ed01 00000000
nt!ExAcquireResourceExclusiveLite+0x8e (FPO: [2,3,0])
f73e9950 f8134832 e1260008 82087670 00000001
rdbss!__RxAcquireFcb+0x1f9 (FPO: [Non-Fpo])
f73e99b4 f8128d51 82087670 820b8808 f81318a8 rdbss!RxCommonClose+0x84
(FPO: [Non-Fpo])
f73e9a4c f8132cc2 f81318a8 8206e602 8206e6b4
rdbss!RxFsdCommonDispatch+0x353 (FPO: [Non-Fpo])
f73e9a74 f80b4317 822b1b58 8206e602 00000000 rdbss!RxFsdDispatch+0xda
(FPO: [2,0,0])
f73e9a94 804ef19f 00000000 0106e620 8206e620
mrxsmb!MRxSmbFsdDispatch+0x134 (FPO: [2,1,4])
f73e9aa4 f84e1e9b 822a3e78 00000000 f739ebd0 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
f73e9ac8 f84e4d59 f73e9ae0 82243020 00000001
fltMgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0x20b (FPO:
[3,4,4])
f73e9af8 f73a0500 823d5ef4 00000001 00000000
fltMgr!FltCompletePendedPreOperation+0x8b (FPO: [3,6,4])
f73e9b1c f739edaf e1179ea0 00275100 00000082
wepcFilter!handleRequestCompletion+0x140 (FPO: [Non-Fpo]) (CONV:
stdcall) [y:\src\wepc\filter\wepcrequest.c @ 357]
f73e9b54 f84e329d f73bd5e4 00275100 00000010
wepcFilter!wepcDataMessageHandler+0x1df (FPO: [Non-Fpo]) (CONV:
stdcall) [y:\src\wepc\filter\wepcfilter.c @ 515]
f73e9b9c f84edef8 82272bd0 00275100 00000010
fltMgr!FltpFilterMessage+0x73 (FPO: [Non-Fpo])
f73e9bd0 f84e1a37 82272b00 82094c00 00275100
fltMgr!FltpMsgDeviceControl+0xa4 (FPO: [10,1,4])
f73e9c14 f84e1f7f 8234c678 82094cc0 82272bd0
fltMgr!FltpMsgDispatch+0x87 (FPO: [2,2,0])
f73e9c40 804ef19f 8234c678 82094cc0 806e6410 fltMgr!FltpDispatch+0x33
(FPO: [2,6,4])
f73e9c50 8057f982 82094d30 82272bd0 82094cc0 nt!IopfCallDriver+0x31
(FPO: [0,0,0])
f73e9c64 805807f7 8234c678 82094cc0 82272bd0
nt!IopSynchronousServiceTail+0x70 (FPO: [7,0,4])
f73e9d00 80579274 000007e8 00000000 00000000
nt!IopXxxControlFile+0x5c5 (FPO: [Non-Fpo])
f73e9d34 8054162c 000007e8 00000000 00000000
nt!NtDeviceIoControlFile+0x2a (FPO: [10,0,0])
f73e9d34 7c90e514 000007e8 00000000 00000000 nt!KiFastCallEntry+0xfc
(FPO: [0,0] TrapFrame @ f73e9d64)
002cfefc 00000000 00000000 00000000 00000000 ntdll!KiFastSystemCallRet
(FPO: [0,0,0])
Using this information I did a quick search of the NTFSD list archives
and came up with this post which looks somewhat similar to my problem:
http://www.osronline.com/showThread.cfm?link=154874
I’m not entirely sure about this, but it looks at least similar…
Investigating further with my own minifilter I’ve observed the following:
1. If I attach to local filesystems only I don’t deadlock.
2. If I pass FLT_PREOP_COMPLETE to FltCompletePendedPreOperation()
and mark the callback data as cancelled (rather than passing
FLT_PREOP_SUCCESS_NO_CALLBACK as I was previously), I don’t deadlock.
I presume this is because the IRP doesn’t ever make it down to RDBSS.
3. The deadlock seems to be somewhat timing dependent; I either
hang on the first IRP I process, or after some (small) number of IRPs
depending on the amount of debug the filter outputs.
Is there anything special I should do for network filesystem IRPs in
order to pend / complete ?
Thanks,
Tom
2009/9/28 Alexandru Carp :
> Hello Tom,
>
> I don’t see filter manager on that stack. Maybe you don’t have symbols ?
>
> Anyway, since the thread is waiting on a resource, I would start by calling !locks on that resource.
>
> Regards,
> Alex.
> This posting is provided “AS IS” with no warranties, and confers no rights.
–
Tom Parkin
www.thhp.org.uk
The worst moment for the atheist is when he is really thankful and has
nobody to thank /Rossetti/