I have created a volume device object and mounted it using files(many files)
i.e. When ever read/write request comes for this device, i read/write from
the files and process the requests.
I have maintained a queue which holds the IRPs coming to my volume diver. so
when ever IRP comes, i queue these IRPs in my queue. Using separate thread,
My own thread, i dequeue the IRP and process and complete the IRP. But
before reading or wirting i need to open the file. I have only one thread
used to process the IRPs. So processing IRPS is sequential. Is my approach
is write or is thier any flaw in it. Actually i faced a deadlock once in a
while. Deadlock is : their is one read request for my volume device. This
requests holds an eresource exclusively. Now i queue the IRP and sent status
pending from my driver. Now when i tries to process the IRP(read request),
it tries to acquire the same eresource already acquired be orignal thread
for this IRP. For service the IRP(Read request) I need to open a file so i
called ZwCreateFile which in turn give control to IO manager and then ntfs.
ntfs then trties to acquire the eresource in shared mode. Please suggest me
how to proceed.
I think the reason behind deadlock is that i am processing all the IRPS
coming to my driver in an asynchronous way. May be i need to process some
IRPs synchronously. Remember i am sitting below file system that is volume
driver for my own virtual volume
I have a dead-lock condition where my system thread below is waiting on an
event object. How can I determine what this thread is waiting for (e.g. who
is holding it up? I am holding no resources and mutex locks within my driver
or in this thread. My driver has opened this file during startup. In the
code Only one thread is allowed to write to that file at any particular
time. I have copied the dump. Please have an insight into the dump and let
me know the problem. Actually my driver is volume driver that is residing
below file system
f78d563c 80832f7a 8619c948 8619c8d0 8619c978 nt!KiSwapContext+0x26 (FPO:
[Uses EBP] [0,0,4])
f78d5668 8082925c 00000000 e5d000d0 e5d000d0 nt!KiSwapThread+0x284 (FPO:
[Non-Fpo])
f78d56b0 f719edf6 f78d56e0 00000000 00000000 nt!KeWaitForSingleObject+0x346
(FPO: [Non-Fpo])
f78d56f0 f71619f3 e5d000d0 f78d58c0 00001000 Ntfs!NtfsWaitForIoAtEof+0x49
(FPO: [Non-Fpo])
f78d58e4 f715adf7 f78d58f4 856a4008 0108070a Ntfs!NtfsCommonWrite+0xbe0
(FPO: [Non-Fpo])
f78d5a60 8081dcdf 85d70198 856a4008 860c62d8 Ntfs!NtfsFsdWrite+0x16a (FPO:
[Non-Fpo])
f78d5a74 f7215c53 860c62d8 856a41bc 0000000f nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d5a9c 8081dcdf 85d84020 856a4008 856a41e0 fltmgr!FltpDispatch+0x6f (FPO:
[Non-Fpo])
f78d5ab0 f6445bbe 856a4008 857b0700 85735888 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be
wrong.
f78d5adc f644b2ce 856a4008 f78d5b24 85735888 naiavf5x+0x1bbe
f78d5b1c f6446520 856a4008 85735888 857f1f38 naiavf5x+0x72ce
f78d5b30 8081dcdf 857b3828 856a4008 2b801000 naiavf5x+0x2520
f78d5b44 8081e3f9 00000000 f78d5b80 85749df0 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d5b58 80835f26 8573580a f78d5b80 f78d5c48 nt!IoSynchronousPageWrite+0xaf
(FPO: [Non-Fpo])
f78d5c74 80837339 e5bdd008 e5bdd010 85749df0 nt!MiFlushSectionInternal+0x6ba
(FPO: [Non-Fpo])
f78d5cb8 8080ef30 85e17a68 f78d5d00 01000400 nt!MmFlushSection+0x23f (FPO:
[Non-Fpo])
f78d5cd0 8080edad 857364a0 00000000 00000000 nt!CcMapAndCopy+0x43c (FPO:
[SEH])
f78d5d4c 8080c7d5 857364a0 f7b4ca00 f78d5d90 nt!CcMapAndCopy+0x2b9 (FPO:
[Non-Fpo])
f78d5ddc f715b36c 85735888 f78d5fb4 00000400 nt!CcCopyWrite+0x29b (FPO:
[Non-Fpo])
f78d5fd8 f715adf7 85d5e4c0 856a76a8 85d84020 Ntfs!NtfsCommonWrite+0x1cea
(FPO: [Non-Fpo])
f78d604c 8081dcdf 85d70198 856a76a8 860c62d8 Ntfs!NtfsFsdWrite+0x16a (FPO:
[Non-Fpo])
f78d6060 f7215c53 860c62d8 856a785c ffffffff nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6088 8081dcdf 85d84020 856a76a8 856a7880 fltmgr!FltpDispatch+0x6f (FPO:
[Non-Fpo])
f78d609c f6445bbe 856a76a8 857b0700 85735888 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d60c8 f644b2ce 856a76a8 f78d6110 856a76a8 naiavf5x+0x1bbe
f78d6108 f6446520 856a76a8 856a76a8 857f1f38 naiavf5x+0x72ce
f78d611c 8081dcdf 857b3828 856a76a8 00000001 naiavf5x+0x2520
f78d6130 808f47b7 856a785c 00000001 856a76a8 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6144 808f24ee 857b3828 856a76a8 85735888
nt!IopSynchronousServiceTail+0x10b (FPO: [Non-Fpo])
f78d61ec 80888c7c 80000568 00000000 00000000 nt!NtWriteFile+0x65a (FPO:
[Non-Fpo])
f78d61ec 8082f421 80000568 00000000 00000000 nt!KiFastCallEntry+0xfc (FPO:
[0,0] TrapFrame @ f78d6218)
f78d6288 f639abcc 80000568 00000000 00000000 nt!ZwWriteFile+0x11 (FPO:
[9,0,0])
f78d62c0 f639ab46 86017d50 f7b4bc00 00000400 MyDrv!InWriteFile+0x2c (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d62ec f6396647 86017d50 f7b4bc00 2b801200 MyDrv!WRITE_FILE+0x36 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d6320 f63967f6 00000000 85d5c530 f7b4bc00 MyDrv!VsWrite+0xa7 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d6350 f63975be f7b4bc00 85d5c530 00000400 MyDrv!VsWriteToLog+0x136 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d63e8 f6397bf6 f7b4b000 60db4000 00000000 MyDrv!VsWriteMap+0x9ee (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d6410 f6392ce0 f7b4b000 60db4000 00000000 MyDrv!VolumeWrite+0x46 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d6454 f638c498 857250e8 857168a8 00000001 MyDrv!ProcessWriteRequest+0xf0
(FPO: [Non-Fpo]) (CONV: stdcall)
f78d6488 f6385686 85725030 85b6bbd0 00000004 MyDrv!ImageWrite+0x298 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d64a4 8081dcdf 85725030 85b6bbd0 85b6bbd0 MyDrv!DispatchWrite+0xb6 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d64b8 f715b0ce f78d68b0 f78d669c f715a702 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d64c4 f715a702 f78d68b0 85725030 60db4000 Ntfs!NtfsSingleAsync+0x91 (FPO:
[Non-Fpo])
f78d669c f715ac1f f78d68b0 85b6bbd0 e132d0d0 Ntfs!NtfsNonCachedIo+0x2db
(FPO: [Non-Fpo])
f78d68a0 f715adf7 f78d68b0 85b6bbd0 0108070a Ntfs!NtfsCommonWrite+0x18e6
(FPO: [Non-Fpo])
f78d6a1c 8081dcdf 8577f718 85b6bbd0 860c62d8 Ntfs!NtfsFsdWrite+0x16a (FPO:
[Non-Fpo])
f78d6a30 f7215c53 860c62d8 85b6bcac 00000400 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6a58 8081dcdf 8577b358 85b6bbd0 85b6bcd0 fltmgr!FltpDispatch+0x6f (FPO:
[Non-Fpo])
f78d6a6c f6445bbe 85b6bbd0 857b0700 85f699c0 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6a98 f644b2ce 85b6bbd0 f78d6ae0 85f699c0 naiavf5x+0x1bbe
f78d6ad8 f6446520 85b6bbd0 85f699c0 857f1f38 naiavf5x+0x72ce
f78d6aec 8081dcdf 85760e78 85b6bbd0 00000000 naiavf5x+0x2520
f78d6b00 8081e3f9 00000000 f78d6b3c 8573bf20 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6b14 80835f26 85f69904 f78d6b3c f78d6c04 nt!IoSynchronousPageWrite+0xaf
(FPO: [Non-Fpo])
f78d6c30 8083730b e1487008 e1487010 8573bf20 nt!MiFlushSectionInternal+0x6ba
(FPO: [Non-Fpo])
f78d6c74 8080f7e6 8573bee8 f78d6c00 00001000 nt!MmFlushSection+0x211 (FPO:
[Non-Fpo])
f78d6cfc 8080fb59 00001000 00000000 00000001 nt!CcFlushCache+0x3a6 (FPO:
[Non-Fpo])
f78d6d40 80812502 8619c8d0 808ae5c0 8619c280 nt!CcWriteBehind+0x11b (FPO:
[Non-Fpo])
f78d6d80 8087f92f 8619c280 00000000 8619c8d0 nt!CcWorkerThread+0x12c (FPO:
[Non-Fpo])
f78d6dac 80948bd0 8619c280 00000000 00000000 nt!ExpWorkerThread+0xeb (FPO:
[Non-Fpo])
f78d6ddc 8088d4e2 8087f844 00000000 00000000 nt!PspSystemThreadStartup+0x2e
(FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
0: kd> !irp 856a4008
Irp is active with 10 stacks 9 is current (= 0x856a4198)
Mdl=f78d5b80: No System Buffer: Thread 8619c8d0: 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
[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
[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
[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
[4, 0] 0 e0 85d70198 85735888 f6445b50-f78d5ac4 Success Error Cancel
\FileSystem\Ntfs naiavf5x
Args: 00001000 00000000 2b801000 00000000
[4, 0] 0 0 857b3828 85735888 00000000-00000000
\FileSystem\NaiAvFilter1
Args: 00001000 00000000 2b801000 00000000
0: kd> !irp 856a76a8
Irp is active with 10 stacks 9 is current (= 0x856a7838)
No Mdl: No System Buffer: Thread 8619c8d0: 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
[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
[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
[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
[4, 0] 4 e0 85d70198 85735888 f6445b50-f78d60b0 Success Error Cancel
\FileSystem\Ntfs naiavf5x
Args: 00000400 00000000 2b801200 00000000
[4, 0] 4 0 857b3828 85735888 00000000-00000000
\FileSystem\NaiAvFilter1
Args: 00000400 00000000 2b801200 00000000
0: kd> dt nt!_FILE_OBJECT 0x85735888
+0x000 Type : 5
+0x002 Size : 0x70
+0x004 DeviceObject : 0x860f2d48 _DEVICE_OBJECT
+0x008 Vpb : 0x860f1518 _VPB
+0x00c FsContext : 0xe5d000d0
+0x010 FsContext2 : 0xe5c24b80
+0x014 SectionObjectPointer : 0x85e30e2c _SECTION_OBJECT_POINTERS
+0x018 PrivateCacheMap : 0x85736578
+0x01c FinalStatus : 0
+0x020 RelatedFileObject : (null)
+0x024 LockOperation : 0 ‘’
+0x025 DeletePending : 0 ‘’
+0x026 ReadAccess : 0x1 ‘’
+0x027 WriteAccess : 0x1 ‘’
+0x028 DeleteAccess : 0 ‘’
+0x029 SharedRead : 0x1 ‘’
+0x02a SharedWrite : 0 ‘’
+0x02b SharedDelete : 0 ‘’
+0x02c Flags : 0x1c3052
+0x030 FileName : _UNICODE_STRING “\data\WriteData1”
+0x038 CurrentByteOffset : _LARGE_INTEGER 0x2b801200
+0x040 Waiters : 0
+0x044 Busy : 1
+0x048 LastLock : (null)
+0x04c Lock : _KEVENT
+0x05c Event : _KEVENT
+0x06c CompletionContext : (null)
You’re doing filesystem I/O from a volume filter driver. That is not for
the faint of heart.
In this particular instance, the cache manager is doing a write behind on
your file, and you are responding by issuing a synchronous file system write
on the same file. That is the cause of the deadlock. The filesystem needs
to synchronize writes at end-of-file but you are not allowing the the write
at end of file to finish before sending another one.
Major problems I see in the design and implementation of “MyDrv”:
- Synchronous ZwWriteFile from volume stack dispatch routine. This causes
recursion into the filesystem that more or less guarantees a deadlock. - Use of ZwWriteFile at all from a volume stack dispatch routine. Did you
know it’s possible you can be called at DISPATCH_LEVEL? - How are you enforcing “Only one thread is allowed to write to that file
at any particular time.”? This doesn’t sound good. - You’ve opened your log file for write-through–the most complex caching
method for you to deal with. - Unless I missed a FO_ bit translation you’ve opened the file with
FO_SEQUENTIAL_ONLY and FO_RANDOM_ACCESS. Huh?
- Dan.
-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of Tim Parker
Sent: Friday, June 15, 2007 4:48 AM
To: Windows File Systems Devs Interest List
Subject: [ntfsd] deadlock
I have a dead-lock condition where my system thread below is waiting on an
event object. How can I determine what this thread is waiting for (e.g. who
is holding it up? I am holding no resources and mutex locks within my driver
or in this thread. My driver has opened this file during startup. In the
code Only one thread is allowed to write to that file at any particular
time. I have copied the dump. Please have an insight into the dump and let
me know the problem. Actually my driver is volume driver that is residing
below file system
f78d563c 80832f7a 8619c948 8619c8d0 8619c978 nt!KiSwapContext+0x26 (FPO:
[Uses EBP] [0,0,4])
f78d5668 8082925c 00000000 e5d000d0 e5d000d0 nt!KiSwapThread+0x284 (FPO:
[Non-Fpo])
f78d56b0 f719edf6 f78d56e0 00000000 00000000 nt!KeWaitForSingleObject+0x346
(FPO: [Non-Fpo])
f78d56f0 f71619f3 e5d000d0 f78d58c0 00001000 Ntfs!NtfsWaitForIoAtEof+0x49
(FPO: [Non-Fpo])
f78d58e4 f715adf7 f78d58f4 856a4008 0108070a Ntfs!NtfsCommonWrite+0xbe0
(FPO: [Non-Fpo])
f78d5a60 8081dcdf 85d70198 856a4008 860c62d8 Ntfs!NtfsFsdWrite+0x16a (FPO:
[Non-Fpo])
f78d5a74 f7215c53 860c62d8 856a41bc 0000000f nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d5a9c 8081dcdf 85d84020 856a4008 856a41e0 fltmgr!FltpDispatch+0x6f (FPO:
[Non-Fpo])
f78d5ab0 f6445bbe 856a4008 857b0700 85735888 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
WARNING: Stack unwind information not available. Following frames may be
wrong.
f78d5adc f644b2ce 856a4008 f78d5b24 85735888 naiavf5x+0x1bbe
f78d5b1c f6446520 856a4008 85735888 857f1f38 naiavf5x+0x72ce
f78d5b30 8081dcdf 857b3828 856a4008 2b801000 naiavf5x+0x2520
f78d5b44 8081e3f9 00000000 f78d5b80 85749df0 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d5b58 80835f26 8573580a f78d5b80 f78d5c48 nt!IoSynchronousPageWrite+0xaf
(FPO: [Non-Fpo])
f78d5c74 80837339 e5bdd008 e5bdd010 85749df0 nt!MiFlushSectionInternal+0x6ba
(FPO: [Non-Fpo])
f78d5cb8 8080ef30 85e17a68 f78d5d00 01000400 nt!MmFlushSection+0x23f (FPO:
[Non-Fpo])
f78d5cd0 8080edad 857364a0 00000000 00000000 nt!CcMapAndCopy+0x43c (FPO:
[SEH])
f78d5d4c 8080c7d5 857364a0 f7b4ca00 f78d5d90 nt!CcMapAndCopy+0x2b9 (FPO:
[Non-Fpo])
f78d5ddc f715b36c 85735888 f78d5fb4 00000400 nt!CcCopyWrite+0x29b (FPO:
[Non-Fpo])
f78d5fd8 f715adf7 85d5e4c0 856a76a8 85d84020 Ntfs!NtfsCommonWrite+0x1cea
(FPO: [Non-Fpo])
f78d604c 8081dcdf 85d70198 856a76a8 860c62d8 Ntfs!NtfsFsdWrite+0x16a (FPO:
[Non-Fpo])
f78d6060 f7215c53 860c62d8 856a785c ffffffff nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6088 8081dcdf 85d84020 856a76a8 856a7880 fltmgr!FltpDispatch+0x6f (FPO:
[Non-Fpo])
f78d609c f6445bbe 856a76a8 857b0700 85735888 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d60c8 f644b2ce 856a76a8 f78d6110 856a76a8 naiavf5x+0x1bbe
f78d6108 f6446520 856a76a8 856a76a8 857f1f38 naiavf5x+0x72ce
f78d611c 8081dcdf 857b3828 856a76a8 00000001 naiavf5x+0x2520
f78d6130 808f47b7 856a785c 00000001 856a76a8 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6144 808f24ee 857b3828 856a76a8 85735888
nt!IopSynchronousServiceTail+0x10b (FPO: [Non-Fpo])
f78d61ec 80888c7c 80000568 00000000 00000000 nt!NtWriteFile+0x65a (FPO:
[Non-Fpo])
f78d61ec 8082f421 80000568 00000000 00000000 nt!KiFastCallEntry+0xfc (FPO:
[0,0] TrapFrame @ f78d6218)
f78d6288 f639abcc 80000568 00000000 00000000 nt!ZwWriteFile+0x11 (FPO:
[9,0,0])
f78d62c0 f639ab46 86017d50 f7b4bc00 00000400 MyDrv!InWriteFile+0x2c (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d62ec f6396647 86017d50 f7b4bc00 2b801200 MyDrv!WRITE_FILE+0x36 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d6320 f63967f6 00000000 85d5c530 f7b4bc00 MyDrv!VsWrite+0xa7 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d6350 f63975be f7b4bc00 85d5c530 00000400 MyDrv!VsWriteToLog+0x136 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d63e8 f6397bf6 f7b4b000 60db4000 00000000 MyDrv!VsWriteMap+0x9ee (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d6410 f6392ce0 f7b4b000 60db4000 00000000 MyDrv!VolumeWrite+0x46 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d6454 f638c498 857250e8 857168a8 00000001 MyDrv!ProcessWriteRequest+0xf0
(FPO: [Non-Fpo]) (CONV: stdcall)
f78d6488 f6385686 85725030 85b6bbd0 00000004 MyDrv!ImageWrite+0x298 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d64a4 8081dcdf 85725030 85b6bbd0 85b6bbd0 MyDrv!DispatchWrite+0xb6 (FPO:
[Non-Fpo]) (CONV: stdcall)
f78d64b8 f715b0ce f78d68b0 f78d669c f715a702 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d64c4 f715a702 f78d68b0 85725030 60db4000 Ntfs!NtfsSingleAsync+0x91 (FPO:
[Non-Fpo])
f78d669c f715ac1f f78d68b0 85b6bbd0 e132d0d0 Ntfs!NtfsNonCachedIo+0x2db
(FPO: [Non-Fpo])
f78d68a0 f715adf7 f78d68b0 85b6bbd0 0108070a Ntfs!NtfsCommonWrite+0x18e6
(FPO: [Non-Fpo])
f78d6a1c 8081dcdf 8577f718 85b6bbd0 860c62d8 Ntfs!NtfsFsdWrite+0x16a (FPO:
[Non-Fpo])
f78d6a30 f7215c53 860c62d8 85b6bcac 00000400 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6a58 8081dcdf 8577b358 85b6bbd0 85b6bcd0 fltmgr!FltpDispatch+0x6f (FPO:
[Non-Fpo])
f78d6a6c f6445bbe 85b6bbd0 857b0700 85f699c0 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6a98 f644b2ce 85b6bbd0 f78d6ae0 85f699c0 naiavf5x+0x1bbe
f78d6ad8 f6446520 85b6bbd0 85f699c0 857f1f38 naiavf5x+0x72ce
f78d6aec 8081dcdf 85760e78 85b6bbd0 00000000 naiavf5x+0x2520
f78d6b00 8081e3f9 00000000 f78d6b3c 8573bf20 nt!IofCallDriver+0x45 (FPO:
[Non-Fpo])
f78d6b14 80835f26 85f69904 f78d6b3c f78d6c04 nt!IoSynchronousPageWrite+0xaf
(FPO: [Non-Fpo])
f78d6c30 8083730b e1487008 e1487010 8573bf20 nt!MiFlushSectionInternal+0x6ba
(FPO: [Non-Fpo])
f78d6c74 8080f7e6 8573bee8 f78d6c00 00001000 nt!MmFlushSection+0x211 (FPO:
[Non-Fpo])
f78d6cfc 8080fb59 00001000 00000000 00000001 nt!CcFlushCache+0x3a6 (FPO:
[Non-Fpo])
f78d6d40 80812502 8619c8d0 808ae5c0 8619c280 nt!CcWriteBehind+0x11b (FPO:
[Non-Fpo])
f78d6d80 8087f92f 8619c280 00000000 8619c8d0 nt!CcWorkerThread+0x12c (FPO:
[Non-Fpo])
f78d6dac 80948bd0 8619c280 00000000 00000000 nt!ExpWorkerThread+0xeb (FPO:
[Non-Fpo])
f78d6ddc 8088d4e2 8087f844 00000000 00000000 nt!PspSystemThreadStartup+0x2e
(FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
0: kd> !irp 856a4008
Irp is active with 10 stacks 9 is current (= 0x856a4198)
Mdl=f78d5b80: No System Buffer: Thread 8619c8d0: 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
[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
[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
[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
[4, 0] 0 e0 85d70198 85735888 f6445b50-f78d5ac4 Success Error Cancel
\FileSystem\Ntfs naiavf5x
Args: 00001000 00000000 2b801000 00000000
[4, 0] 0 0 857b3828 85735888 00000000-00000000
\FileSystem\NaiAvFilter1
Args: 00001000 00000000 2b801000 00000000
0: kd> !irp 856a76a8
Irp is active with 10 stacks 9 is current (= 0x856a7838)
No Mdl: No System Buffer: Thread 8619c8d0: 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
[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
[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
[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
[4, 0] 4 e0 85d70198 85735888 f6445b50-f78d60b0 Success Error Cancel
\FileSystem\Ntfs naiavf5x
Args: 00000400 00000000 2b801200 00000000
[4, 0] 4 0 857b3828 85735888 00000000-00000000
\FileSystem\NaiAvFilter1
Args: 00000400 00000000 2b801200 00000000
0: kd> dt nt!_FILE_OBJECT 0x85735888
+0x000 Type : 5
+0x002 Size : 0x70
+0x004 DeviceObject : 0x860f2d48 _DEVICE_OBJECT
+0x008 Vpb : 0x860f1518 _VPB
+0x00c FsContext : 0xe5d000d0
+0x010 FsContext2 : 0xe5c24b80
+0x014 SectionObjectPointer : 0x85e30e2c _SECTION_OBJECT_POINTERS
+0x018 PrivateCacheMap : 0x85736578
+0x01c FinalStatus : 0
+0x020 RelatedFileObject : (null)
+0x024 LockOperation : 0 ‘’
+0x025 DeletePending : 0 ‘’
+0x026 ReadAccess : 0x1 ‘’
+0x027 WriteAccess : 0x1 ‘’
+0x028 DeleteAccess : 0 ‘’
+0x029 SharedRead : 0x1 ‘’
+0x02a SharedWrite : 0 ‘’
+0x02b SharedDelete : 0 ‘’
+0x02c Flags : 0x1c3052
+0x030 FileName : _UNICODE_STRING “\data\WriteData1”
+0x038 CurrentByteOffset : _LARGE_INTEGER 0x2b801200
+0x040 Waiters : 0
+0x044 Busy : 1
+0x048 LastLock : (null)
+0x04c Lock : _KEVENT
+0x05c Event : _KEVENT
+0x06c CompletionContext : (null)
— Questions? First check the IFS FAQ at
https://www.osronline.com/article.cfm?id=17 You are currently subscribed to
ntfsd as: xxxxx@privtek.com To unsubscribe send a blank email to
xxxxx@lists.osr.com
Dan,
Thanks for reply.
>2) Use of ZwWriteFile at all from a volume stack dispatch routine. Did
you
>know it’s possible you can be called at DISPATCH_LEVEL?"
If the I/o Request comes to me at above passive level then i process this
request asynchronously, I mean i have created a seprate thread which is used
to process the IRPs coming to my volume driver at IRQL >PASSIVE_LEVEL.
>3) How are you enforcing “Only one thread is allowed to write to that file
>at any particular time.”? This doesn’t sound good.
The file to which i am writing is created by my volume driver itself in
FILE_SHARE_READ, so that no one else can write to my file. I have taken a
variable for synchronization and based upon the value of that variable only
one thread is allowed to read/write to that file. Any read write of that
variable needs to acquire mutex first. This way i assure that only one
thread is allowed to read write to that file.
>4) Unless I missed a FO_ bit translation you’ve opened the file with
>FO_SEQUENTIAL_ONLY and FO_RANDOM_ACCESS. Huh?
these are the flags i have used while creating a file
FILE_NON_DIRECTORY_FILE | FILE_RANDOM_ACCESS | FILE_SYNCHRONOUS_IO_NONALERT
I have not used this flag FO_SEQUENTIAL_ONLY.
On 6/15/07, Dan Kyler wrote:
>
> You’re doing filesystem I/O from a volume filter driver. That is not for
> the faint of heart.
>
> In this particular instance, the cache manager is doing a write behind on
> your file, and you are responding by issuing a synchronous file system
> write
> on the same file. That is the cause of the deadlock. The filesystem
> needs
> to synchronize writes at end-of-file but you are not allowing the the
> write
> at end of file to finish before sending another one.
>
> Major problems I see in the design and implementation of “MyDrv”:
>
> 1) Synchronous ZwWriteFile from volume stack dispatch routine. This
> causes
> recursion into the filesystem that more or less guarantees a deadlock.
> 2) Use of ZwWriteFile at all from a volume stack dispatch routine. Did
> you
> know it’s possible you can be called at DISPATCH_LEVEL?
> 3) How are you enforcing “Only one thread is allowed to write to that file
> at any particular time.”? This doesn’t sound good.
> 3) You’ve opened your log file for write-through–the most complex caching
> method for you to deal with.
> 4) Unless I missed a FO_ bit translation you’ve opened the file with
> FO_SEQUENTIAL_ONLY and FO_RANDOM_ACCESS. Huh?
>
> - Dan.
>
> -----Original Message-----
> From: xxxxx@lists.osr.com
> [mailto:xxxxx@lists.osr.com] On Behalf Of Tim Parker
> Sent: Friday, June 15, 2007 4:48 AM
> To: Windows File Systems Devs Interest List
> Subject: [ntfsd] deadlock
>
>
> I have a dead-lock condition where my system thread below is waiting on an
> event object. How can I determine what this thread is waiting for (e.g.
> who
> is holding it up? I am holding no resources and mutex locks within my
> driver
> or in this thread. My driver has opened this file during startup. In the
> code Only one thread is allowed to write to that file at any particular
> time. I have copied the dump. Please have an insight into the dump and let
> me know the problem. Actually my driver is volume driver that is residing
> below file system
>
>
>
>
>
> f78d563c 80832f7a 8619c948 8619c8d0 8619c978 nt!KiSwapContext+0x26 (FPO:
> [Uses EBP] [0,0,4])
> f78d5668 8082925c 00000000 e5d000d0 e5d000d0 nt!KiSwapThread+0x284 (FPO:
> [Non-Fpo])
> f78d56b0 f719edf6 f78d56e0 00000000 00000000
> nt!KeWaitForSingleObject+0x346
> (FPO: [Non-Fpo])
> f78d56f0 f71619f3 e5d000d0 f78d58c0 00001000 Ntfs!NtfsWaitForIoAtEof+0x49
> (FPO: [Non-Fpo])
> f78d58e4 f715adf7 f78d58f4 856a4008 0108070a Ntfs!NtfsCommonWrite+0xbe0
> (FPO: [Non-Fpo])
> f78d5a60 8081dcdf 85d70198 856a4008 860c62d8 Ntfs!NtfsFsdWrite+0x16a (FPO:
> [Non-Fpo])
> f78d5a74 f7215c53 860c62d8 856a41bc 0000000f nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> f78d5a9c 8081dcdf 85d84020 856a4008 856a41e0 fltmgr!FltpDispatch+0x6f
> (FPO:
> [Non-Fpo])
> f78d5ab0 f6445bbe 856a4008 857b0700 85735888 nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> WARNING: Stack unwind information not available. Following frames may be
> wrong.
> f78d5adc f644b2ce 856a4008 f78d5b24 85735888 naiavf5x+0x1bbe
> f78d5b1c f6446520 856a4008 85735888 857f1f38 naiavf5x+0x72ce
> f78d5b30 8081dcdf 857b3828 856a4008 2b801000 naiavf5x+0x2520
> f78d5b44 8081e3f9 00000000 f78d5b80 85749df0 nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> f78d5b58 80835f26 8573580a f78d5b80 f78d5c48
> nt!IoSynchronousPageWrite+0xaf
> (FPO: [Non-Fpo])
> f78d5c74 80837339 e5bdd008 e5bdd010 85749df0
> nt!MiFlushSectionInternal+0x6ba
> (FPO: [Non-Fpo])
> f78d5cb8 8080ef30 85e17a68 f78d5d00 01000400 nt!MmFlushSection+0x23f (FPO:
> [Non-Fpo])
> f78d5cd0 8080edad 857364a0 00000000 00000000 nt!CcMapAndCopy+0x43c (FPO:
> [SEH])
> f78d5d4c 8080c7d5 857364a0 f7b4ca00 f78d5d90 nt!CcMapAndCopy+0x2b9 (FPO:
> [Non-Fpo])
> f78d5ddc f715b36c 85735888 f78d5fb4 00000400 nt!CcCopyWrite+0x29b (FPO:
> [Non-Fpo])
> f78d5fd8 f715adf7 85d5e4c0 856a76a8 85d84020 Ntfs!NtfsCommonWrite+0x1cea
> (FPO: [Non-Fpo])
> f78d604c 8081dcdf 85d70198 856a76a8 860c62d8 Ntfs!NtfsFsdWrite+0x16a (FPO:
> [Non-Fpo])
> f78d6060 f7215c53 860c62d8 856a785c ffffffff nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> f78d6088 8081dcdf 85d84020 856a76a8 856a7880 fltmgr!FltpDispatch+0x6f
> (FPO:
> [Non-Fpo])
> f78d609c f6445bbe 856a76a8 857b0700 85735888 nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> f78d60c8 f644b2ce 856a76a8 f78d6110 856a76a8 naiavf5x+0x1bbe
> f78d6108 f6446520 856a76a8 856a76a8 857f1f38 naiavf5x+0x72ce
> f78d611c 8081dcdf 857b3828 856a76a8 00000001 naiavf5x+0x2520
> f78d6130 808f47b7 856a785c 00000001 856a76a8 nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> f78d6144 808f24ee 857b3828 856a76a8 85735888
> nt!IopSynchronousServiceTail+0x10b (FPO: [Non-Fpo])
> f78d61ec 80888c7c 80000568 00000000 00000000 nt!NtWriteFile+0x65a (FPO:
> [Non-Fpo])
> f78d61ec 8082f421 80000568 00000000 00000000 nt!KiFastCallEntry+0xfc (FPO:
> [0,0] TrapFrame @ f78d6218)
> f78d6288 f639abcc 80000568 00000000 00000000 nt!ZwWriteFile+0x11 (FPO:
> [9,0,0])
> f78d62c0 f639ab46 86017d50 f7b4bc00 00000400 MyDrv!InWriteFile+0x2c (FPO:
> [Non-Fpo]) (CONV: stdcall)
> f78d62ec f6396647 86017d50 f7b4bc00 2b801200 MyDrv!WRITE_FILE+0x36 (FPO:
> [Non-Fpo]) (CONV: stdcall)
> f78d6320 f63967f6 00000000 85d5c530 f7b4bc00 MyDrv!VsWrite+0xa7 (FPO:
> [Non-Fpo]) (CONV: stdcall)
> f78d6350 f63975be f7b4bc00 85d5c530 00000400 MyDrv!VsWriteToLog+0x136
> (FPO:
> [Non-Fpo]) (CONV: stdcall)
> f78d63e8 f6397bf6 f7b4b000 60db4000 00000000 MyDrv!VsWriteMap+0x9ee (FPO:
> [Non-Fpo]) (CONV: stdcall)
> f78d6410 f6392ce0 f7b4b000 60db4000 00000000 MyDrv!VolumeWrite+0x46 (FPO:
> [Non-Fpo]) (CONV: stdcall)
> f78d6454 f638c498 857250e8 857168a8 00000001
> MyDrv!ProcessWriteRequest+0xf0
> (FPO: [Non-Fpo]) (CONV: stdcall)
> f78d6488 f6385686 85725030 85b6bbd0 00000004 MyDrv!ImageWrite+0x298 (FPO:
> [Non-Fpo]) (CONV: stdcall)
> f78d64a4 8081dcdf 85725030 85b6bbd0 85b6bbd0 MyDrv!DispatchWrite+0xb6
> (FPO:
> [Non-Fpo]) (CONV: stdcall)
> f78d64b8 f715b0ce f78d68b0 f78d669c f715a702 nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> f78d64c4 f715a702 f78d68b0 85725030 60db4000 Ntfs!NtfsSingleAsync+0x91
> (FPO:
> [Non-Fpo])
> f78d669c f715ac1f f78d68b0 85b6bbd0 e132d0d0 Ntfs!NtfsNonCachedIo+0x2db
> (FPO: [Non-Fpo])
> f78d68a0 f715adf7 f78d68b0 85b6bbd0 0108070a Ntfs!NtfsCommonWrite+0x18e6
> (FPO: [Non-Fpo])
> f78d6a1c 8081dcdf 8577f718 85b6bbd0 860c62d8 Ntfs!NtfsFsdWrite+0x16a (FPO:
> [Non-Fpo])
> f78d6a30 f7215c53 860c62d8 85b6bcac 00000400 nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> f78d6a58 8081dcdf 8577b358 85b6bbd0 85b6bcd0 fltmgr!FltpDispatch+0x6f
> (FPO:
> [Non-Fpo])
> f78d6a6c f6445bbe 85b6bbd0 857b0700 85f699c0 nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> f78d6a98 f644b2ce 85b6bbd0 f78d6ae0 85f699c0 naiavf5x+0x1bbe
> f78d6ad8 f6446520 85b6bbd0 85f699c0 857f1f38 naiavf5x+0x72ce
> f78d6aec 8081dcdf 85760e78 85b6bbd0 00000000 naiavf5x+0x2520
> f78d6b00 8081e3f9 00000000 f78d6b3c 8573bf20 nt!IofCallDriver+0x45 (FPO:
> [Non-Fpo])
> f78d6b14 80835f26 85f69904 f78d6b3c f78d6c04
> nt!IoSynchronousPageWrite+0xaf
> (FPO: [Non-Fpo])
> f78d6c30 8083730b e1487008 e1487010 8573bf20
> nt!MiFlushSectionInternal+0x6ba
> (FPO: [Non-Fpo])
> f78d6c74 8080f7e6 8573bee8 f78d6c00 00001000 nt!MmFlushSection+0x211 (FPO:
> [Non-Fpo])
> f78d6cfc 8080fb59 00001000 00000000 00000001 nt!CcFlushCache+0x3a6 (FPO:
> [Non-Fpo])
> f78d6d40 80812502 8619c8d0 808ae5c0 8619c280 nt!CcWriteBehind+0x11b (FPO:
> [Non-Fpo])
> f78d6d80 8087f92f 8619c280 00000000 8619c8d0 nt!CcWorkerThread+0x12c (FPO:
> [Non-Fpo])
> f78d6dac 80948bd0 8619c280 00000000 00000000 nt!ExpWorkerThread+0xeb (FPO:
> [Non-Fpo])
> f78d6ddc 8088d4e2 8087f844 00000000 00000000
> nt!PspSystemThreadStartup+0x2e
> (FPO: [Non-Fpo])
> 00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
>
>
> 0: kd> !irp 856a4008
> Irp is active with 10 stacks 9 is current (= 0x856a4198)
> Mdl=f78d5b80: No System Buffer: Thread 8619c8d0: 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
> [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
> [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
> [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
> >[4, 0] 0 e0 85d70198 85735888 f6445b50-f78d5ac4 Success Error Cancel
> \FileSystem\Ntfs naiavf5x
> Args: 00001000 00000000 2b801000 00000000
> [4, 0] 0 0 857b3828 85735888 00000000-00000000
> \FileSystem\NaiAvFilter1
> Args: 00001000 00000000 2b801000 00000000
>
> 0: kd> !irp 856a76a8
> Irp is active with 10 stacks 9 is current (= 0x856a7838)
> No Mdl: No System Buffer: Thread 8619c8d0: 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
> [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
> [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
> [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
> >[4, 0] 4 e0 85d70198 85735888 f6445b50-f78d60b0 Success Error Cancel
> \FileSystem\Ntfs naiavf5x
> Args: 00000400 00000000 2b801200 00000000
> [4, 0] 4 0 857b3828 85735888 00000000-00000000
> \FileSystem\NaiAvFilter1
> Args: 00000400 00000000 2b801200 00000000
>
> 0: kd> dt nt!_FILE_OBJECT 0x85735888
> +0x000 Type : 5
> +0x002 Size : 0x70
> +0x004 DeviceObject : 0x860f2d48 _DEVICE_OBJECT
> +0x008 Vpb : 0x860f1518 _VPB
> +0x00c FsContext : 0xe5d000d0
> +0x010 FsContext2 : 0xe5c24b80
> +0x014 SectionObjectPointer : 0x85e30e2c _SECTION_OBJECT_POINTERS
> +0x018 PrivateCacheMap : 0x85736578
> +0x01c FinalStatus : 0
> +0x020 RelatedFileObject : (null)
> +0x024 LockOperation : 0 ‘’
> +0x025 DeletePending : 0 ‘’
> +0x026 ReadAccess : 0x1 ‘’
> +0x027 WriteAccess : 0x1 ‘’
> +0x028 DeleteAccess : 0 ‘’
> +0x029 SharedRead : 0x1 ‘’
> +0x02a SharedWrite : 0 ‘’
> +0x02b SharedDelete : 0 ‘’
> +0x02c Flags : 0x1c3052
> +0x030 FileName : _UNICODE_STRING “\data\WriteData1”
> +0x038 CurrentByteOffset : _LARGE_INTEGER 0x2b801200
> +0x040 Waiters : 0
> +0x044 Busy : 1
> +0x048 LastLock : (null)
> +0x04c Lock : _KEVENT
> +0x05c Event : _KEVENT
> +0x06c CompletionContext : (null)
> — Questions? First check the IFS FAQ at
> https://www.osronline.com/article.cfm?id=17 You are currently subscribed
> to
> ntfsd as: xxxxx@privtek.com To unsubscribe send a blank email to
> xxxxx@lists.osr.com
>
>
> —
> Questions? First check the IFS FAQ at
> https://www.osronline.com/article.cfm?id=17
>
> You are currently subscribed to ntfsd as: xxxxx@gmail.com
> To unsubscribe send a blank email to xxxxx@lists.osr.com
>