smb returns access denied for MJ_WRITE

Jiajun_Lu · August 26, 2010, 4:02pm

Hi guys,

We have a legacy file system filter driver which generally works fine
now. However, recently we found a problem no write permission on Windows
2008 R2 x64 when users try to access files from the same machine via
network share something like “\localhost\share\xxx”. There is no
problem if files are accessed from local drive “C:\xxxx”. And there is
no problem if files are access from another machine
“\server\share\xxx”. And of course, without our filter driver,
everything is fine.

Procmon shows Create, QuerySecurityObject, and
QueryNetworkFileInformation are all success without problem at least not
a problem so obvious. But smb server returns ACCESS DENIED immediately
without passing MJ_WRITE to our filter driver.

Has anybody had this problem before? What kind of possible reasons, this
WRITE can be denied by smb server (maybe smb client) ? And is there any
tool I can use to get more information about Windows smb server?

Thanks,
Max

Bronislav_Gabrhelik · August 27, 2010, 9:42am

Do you use the same credencials for working cases as for non-working case?
Isn’t your filter attached also to the SMB/CIFS redirector (on the client side of the request)? If yes, check that it doesn’t modify anything.

You are saying nothing about functionality of your legacy filter, so it is hard to help.

denied by smb server (maybe smb client)
It is quite easy to determine with some monitor (e.g. FileSpy).

Bronislav Gabrhelik

Jiajun_Lu · August 27, 2010, 11:38am

Thank you for you reply. Our driver is just intercepting and redirecting
file IOs.

It is only attached to file system.

Here is the fileSpy log when I use notepad to save via network shared on
the same machine. G: is where our driver attached. I can see when
notepad opens the file, our driver receives MJ_CREATE and other
QueryInformation Irps. We don’t support fast io now. So
FASTIO_QUERY_NETWORK_OPEN_INFO failed. But when notepad writes, our
driver doesn’t receive MJ_WRITE. STATUS_ACCESS_DENIED is returned.

If I understand correct, MUP is client side. But I couldn’t attach to
smb server. All I know is our driver doesn’t receive from smb server.

Thanks again and below is the filespy log.

1 10:19:40.145 2 System 2660 FFFFFA800E0CDBA0 IRP FFFFF98006D20E50
IRP_MJ_CREATE 40000884 00000000 FFFFFA800E0D52E0 FFFFFA8011FFAA08
FFFFFA8011FF67D8 02000000 0000000000000000 G:\Shared\222.txt
STATUS_SUCCESS FILE_OPEN_IF CreOpts: 00020140 Access: 0012019F Share:
00000001 Attrib: 00000080 Result: FILE_OPENED
2 10:19:40.148 0 System 2660 FFFFFA800E0CDBA0 FastIO
FASTIO_QUERY_NETWORK_OPEN_INFO FFFFFA800E0D52E0 FFFFFA8011FFAA08
FFFFFA8011FF67D8 01040000 FFFFFA8011FFAB70 G:\Shared\222.txt FAILURE
3 10:19:40.148 0 System 2660 FFFFFA800E0CDBA0 IRP FFFFF98006D3EE50
IRP_MJ_QUERY_INFORMATION 40060874 00000000 FFFFFA800E0D52E0
FFFFFA8011FFAA08 FFFFFA8011FF67D8 01040000 FFFFFA8011FFAB70
G:\Shared\222.txt STATUS_SUCCESS FileNetworkOpenInformation
AllocationSize: 00000000-00100000 EndOfFile: 00000000-00000000 Attrib:
00002020
4 10:19:40.149 0 System 2660 FFFFFA800E0CDBA0 IRP FFFFF98006CFEE50
IRP_MJ_QUERY_SECURITY 40000004 00000000 FFFFFA800E0D52E0
FFFFFA8011FFAA08 FFFFFA8011FF67D8 01040000 FFFFFA8011FFAB70
G:\Shared\222.txt STATUS_SUCCESS
5 10:19:40.150 0 System 2660 FFFFFA800E0CDBA0 IRP FFFFF980042ECE50
IRP_MJ_QUERY_INFORMATION 40060874 00000000 FFFFFA800E0D52E0
FFFFFA8011FFAA08 FFFFFA8011FF67D8 01040000 FFFFFA8011FFAB70
G:\Shared\222.txt STATUS_SUCCESS FileInternalInformation
6 10:19:40.143 10 notepad.exe 588 FFFFFA800E03F5B0 IRP
FFFFF98006D3ADC0 IRP_MJ_CREATE 40000884 00000000 FFFFFA800F87F500
FFFFF8A004E2D4F0 FFFFF8A004E2D890 02000002 0000000000000000
\Device\Mup\Srv1\Shared\222.txt STATUS_SUCCESS FILE_OPEN_IF CreOpts:
00020060 Access: 0012019F Share: 00000001 Attrib: 00000080 Result:
FILE_OPENED
7 10:19:40.155 0 notepad.exe 588 FFFFFA800E03F5B0 IRP
FFFFF98006D04DC0 IRP_MJ_WRITE 40060A00 00000000 FFFFFA800F87F500
FFFFF8A004E2D4F0 FFFFF8A004E2D890 00040002 FFFFFA800E07F608
\Device\Mup\Srv1\Shared\222.txt STATUS_ACCESS_DENIED Offset
00000000-00000000 ToWrite 3 Written: 0

Max

On 8/27/2010 8:43 AM, xxxxx@xythos.com wrote:

Do you use the same credencials for working cases as for non-working case?
Isn’t your filter attached also to the SMB/CIFS redirector (on the client side of the request)? If yes, check that it doesn’t modify anything.

You are saying nothing about functionality of your legacy filter, so it is hard to help.

> denied by smb server (maybe smb client)
It is quite easy to determine with some monitor (e.g. FileSpy).

Bronislav Gabrhelik

NTFSD is sponsored by OSR

For our schedule of debugging and file system seminars
(including our new fs mini-filter seminar) visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer

Bronislav_Gabrhelik · August 30, 2010, 4:26am

Short investigation: It looks like there is a special path for localhost requests. Below is data captured by procmon. In log below the WriteFile request to D:\share\ahoj.txt has process context NOTEPAD, which is client side application accessing file on the server side. Weird! Stack of that requests proves that RDBSS has some special processing of requests coming to local system. E.G. It means that your driver is on the stack twice, with the two instances of device. I cannot follow causes and consequences as I know minimum about your driver design and system configuration.

Bronislav Gabrhelik

9:38:07.4311381 AM NOTEPAD.EXE 4264 4928 CreateFile \localhost\share\ahoj.txt SUCCESS Desired Access: Generic Read/Write, Disposition: OpenIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, AllocationSize: 0, OpenResult: Opened
9:38:07.4314799 AM NOTEPAD.EXE 4264 4928 CreateFile \localhost\share\ahoj.txt SUCCESS Desired Access: Read Attributes, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Complete If Oplocked, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
9:38:07.4321893 AM NOTEPAD.EXE 4264 4928 QueryFileInternalInformationFile \localhost\share\ahoj.txt SUCCESS IndexNumber: 0x200000023fa0e
9:38:07.4322041 AM NOTEPAD.EXE 4264 4928 CloseFile \localhost\share\ahoj.txt SUCCESS
9:38:07.4322325 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE \localhost\share\ahoj.txt SUCCESS
9:38:07.4326360 AM NOTEPAD.EXE 4264 4928 CreateFile \localhost\share\ahoj.txt SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Complete If Oplocked, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
9:38:07.4334308 AM NOTEPAD.EXE 4264 4928 QueryStandardInformationFile \localhost\share\ahoj.txt FAST IO DISALLOWED
9:38:07.4334493 AM NOTEPAD.EXE 4264 4928 QueryStandardInformationFile \localhost\share\ahoj.txt SUCCESS AllocationSize: 0, EndOfFile: 0, NumberOfLinks: 1, DeletePending: False, Directory: False
9:38:07.4335180 AM NOTEPAD.EXE 4264 4928 CloseFile \localhost\share\ahoj.txt SUCCESS
9:38:07.4335480 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE \localhost\share\ahoj.txt SUCCESS
9:38:07.4344009 AM NOTEPAD.EXE 4264 4928 WriteFile \localhost\share\ahoj.txt SUCCESS Offset: 0, Length: 6, Priority: Normal
9:38:07.4344289 AM NOTEPAD.EXE 4264 4928 WriteFile D:\share\ahoj.txt FAST IO DISALLOWED Offset: 0, Length: 6
9:38:07.4344500 AM NOTEPAD.EXE 4264 4928 WriteFile D:\share\ahoj.txt SUCCESS Offset: 0, Length: 6
9:38:07.4344939 AM NOTEPAD.EXE 4264 4928 SetEndOfFileInformationFile \localhost\share\ahoj.txt SUCCESS EndOfFile: 6
9:38:07.4345127 AM NOTEPAD.EXE 4264 4928 SetAllInformationFile \localhost\share\ahoj.txt SUCCESS AllocationSize: 6
9:38:07.4348813 AM NOTEPAD.EXE 4264 4928 CreateFile \localhost\share\ SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
9:38:07.4350462 AM NOTEPAD.EXE 4264 4928 QueryDirectory \localhost\share\ahoj.txt SUCCESS Filter: ahoj.txt, 1: ahoj.txt
9:38:07.4351907 AM NOTEPAD.EXE 4264 4928 CloseFile \localhost\share\ SUCCESS
9:38:07.4352148 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE \localhost\share\ SUCCESS
9:38:07.4356774 AM NOTEPAD.EXE 4264 4928 CloseFile \localhost\share\ahoj.txt SUCCESS
9:38:07.4357051 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE \localhost\share\ahoj.txt SUCCESS

0 fltmgr.sys FltpPerformPreCallbacks + 0x2f7
1 fltmgr.sys FltpPassThroughFastIo + 0x4d
2 fltmgr.sys FltpFastIoWrite + 0x1ce
3 rdbss.sys RxShadowFastLowIo + 0x268
4 rdbss.sys RxLowIoSubmit + 0xba
5 rdbss.sys RxLowIoWriteShell + 0x7f
6 rdbss.sys RxCommonFileWrite + 0x1ba2
7 rdbss.sys RxCommonWrite + 0xe6 0
8 rdbss.sys RxFsdCommonDispatch + 0x870
9 rdbss.sys RxFsdDispatch + 0x224
10 mrxsmb.sys MRxSmbFsdDispatch + 0xc0
11 mup.sys MupiCallUncProvider + 0x161
12 mup.sys MupStateMachine + 0x128
13 mup.sys MupFsdIrpPassThrough + 0x12d
14 fltmgr.sys FltpLegacyProcessingAfterPreCallbacksCompleted + 0x24f
15 fltmgr.sys FltpDispatch + 0xcf
16 eamon.sys eamon.sys + 0x5943
17 fltmgr.sys FltpLegacyProcessingAfterPreCallbacksCompleted + 0x24f
18 fltmgr.sys FltpDispatch + 0xcf
19 ntoskrnl.exe IopSynchronousServiceTail + 0xf9
20 ntoskrnl.exe NtWriteFile + 0x7e2

“Normal” stack which communicates to TCP/IP looks like

eeaac824 f7f8da4b 82012500 81f38790 822feeb0 rdbss!RxCeSubmitAsynchronousTdiRequest+0x28
eeaac85c f7f971b4 822fa384 822fa3ac 8224ed54 rdbss!RxTdiSend+0x1ca
eeaac8b8 f7f18b79 8224ed88 00000000 81f9b684 rdbss!RxCeSend+0x74
eeaac8e0 f7ef5ad0 8224ed38 81f9c7b8 81f9b398 mrxsmb!VctTranceive+0x66
eeaac924 f7f1ad7a 00f9b398 00000000 81f9b684 mrxsmb!SmbCeTranceive+0x233
eeaac960 f7f1d8f2 00000000 0000002c f7f1d592 mrxsmb!SmbPseOrdinaryExchange+0x18e
eeaac9b0 f7f1ac04 01f9b398 822cb2e0 eeaac9e4 mrxsmb!SmbPseExchangeStart_Write+0x1e3
eeaac9c0 f7f1905f 81f9b398 80701940 f7f14940 mrxsmb!SmbPseExchangeStart_default+0x12
eeaac9e4 f7f1d410 81f9c7b8 822cb360 822cb2e0 mrxsmb!SmbCeInitiateExchange+0x287
eeaaca24 f7f975b3 822cb2e0 e19d1b10 f7f95a78 mrxsmb!MRxSmbWrite+0x309
eeaaca4c f7f9b302 012cb2e0 f7f9b321 00000000 rdbss!RxLowIoSubmit+0x1c3
eeaaca6c f7f9ba5b 822cb2e0 f7f9b40d 822cb2e0 rdbss!RxLowIoWriteShell+0x77
eeaacb90 f7f8cd51 822cb2e0 82330820 f7f958a8 rdbss!RxCommonWrite+0x116f
eeaacc28 f7f96cc2 f7f958a8 82033c04 82033c78 rdbss!RxFsdCommonDispatch+0x353
eeaacc50 f7f18317 81ff9030 82033c04 82330820 rdbss!RxFsdDispatch+0xda
eeaacc70 804e13d9 00000000 01033c08 80701410 mrxsmb!MRxSmbFsdDispatch+0x134

Scott_Noone_OSR · August 30, 2010, 1:31pm

wrote in message news:xxxxx@ntfsd…
> Short investigation: It looks like there is a special path for localhost
> requests.

This behavior started showing up in Vista I believe. You can see some pretty
strange stuff when you test loopback because of it and you definitely get
different behavior than what you see over the real network.

-scott

–
Scott Noone
Consulting Associate
OSR Open Systems Resources, Inc.
http://www.osronline.com

wrote in message news:xxxxx@ntfsd…
> Short investigation: It looks like there is a special path for localhost
> requests. Below is data captured by procmon. In log below the WriteFile
> request to D:\share\ahoj.txt has process context NOTEPAD, which is client
> side application accessing file on the server side. Weird! Stack of that
> requests proves that RDBSS has some special processing of requests coming
> to local system. E.G. It means that your driver is on the stack twice,
> with the two instances of device. I cannot follow causes and consequences
> as I know minimum about your driver design and system configuration.
>
> Bronislav Gabrhelik
>
> 9:38:07.4311381 AM NOTEPAD.EXE 4264 4928 CreateFile
> \localhost\share\ahoj.txt SUCCESS Desired Access: Generic Read/Write,
> Disposition: OpenIf, Options: Synchronous IO Non-Alert, Non-Directory
> File, Attributes: N, ShareMode: Read, AllocationSize: 0, OpenResult:
> Opened
> 9:38:07.4314799 AM NOTEPAD.EXE 4264 4928 CreateFile
> \localhost\share\ahoj.txt SUCCESS Desired Access: Read Attributes,
> Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert,
> Non-Directory File, Complete If Oplocked, Attributes: n/a, ShareMode:
> Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
> 9:38:07.4321893 AM NOTEPAD.EXE 4264 4928 QueryFileInternalInformationFile
> \localhost\share\ahoj.txt SUCCESS IndexNumber: 0x200000023fa0e
> 9:38:07.4322041 AM NOTEPAD.EXE 4264 4928 CloseFile
> \localhost\share\ahoj.txt SUCCESS
> 9:38:07.4322325 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE
> \localhost\share\ahoj.txt SUCCESS
> 9:38:07.4326360 AM NOTEPAD.EXE 4264 4928 CreateFile
> \localhost\share\ahoj.txt SUCCESS Desired Access: Read Data/List
> Directory, Synchronize, Disposition: Open, Options: Synchronous IO
> Non-Alert, Non-Directory File, Complete If Oplocked, Attributes: n/a,
> ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
> 9:38:07.4334308 AM NOTEPAD.EXE 4264 4928 QueryStandardInformationFile
> \localhost\share\ahoj.txt FAST IO DISALLOWED
> 9:38:07.4334493 AM NOTEPAD.EXE 4264 4928 QueryStandardInformationFile
> \localhost\share\ahoj.txt SUCCESS AllocationSize: 0, EndOfFile: 0,
> NumberOfLinks: 1, DeletePending: False, Directory: False
> 9:38:07.4335180 AM NOTEPAD.EXE 4264 4928 CloseFile
> \localhost\share\ahoj.txt SUCCESS
> 9:38:07.4335480 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE
> \localhost\share\ahoj.txt SUCCESS
> 9:38:07.4344009 AM NOTEPAD.EXE 4264 4928 WriteFile
> \localhost\share\ahoj.txt SUCCESS Offset: 0, Length: 6, Priority: Normal
> 9:38:07.4344289 AM NOTEPAD.EXE 4264 4928 WriteFile D:\share\ahoj.txt FAST
> IO DISALLOWED Offset: 0, Length: 6
> 9:38:07.4344500 AM NOTEPAD.EXE 4264 4928 WriteFile D:\share\ahoj.txt
> SUCCESS Offset: 0, Length: 6
> 9:38:07.4344939 AM NOTEPAD.EXE 4264 4928 SetEndOfFileInformationFile
> \localhost\share\ahoj.txt SUCCESS EndOfFile: 6
> 9:38:07.4345127 AM NOTEPAD.EXE 4264 4928 SetAllInformationFile
> \localhost\share\ahoj.txt SUCCESS AllocationSize: 6
> 9:38:07.4348813 AM NOTEPAD.EXE 4264 4928 CreateFile \localhost\share\
> SUCCESS Desired Access: Read Data/List Directory, Synchronize,
> Disposition: Open, Options: Directory, Synchronous IO Non-Alert,
> Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a,
> OpenResult: Opened
> 9:38:07.4350462 AM NOTEPAD.EXE 4264 4928 QueryDirectory
> \localhost\share\ahoj.txt SUCCESS Filter: ahoj.txt, 1: ahoj.txt
> 9:38:07.4351907 AM NOTEPAD.EXE 4264 4928 CloseFile \localhost\share\
> SUCCESS
> 9:38:07.4352148 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE \localhost\share\
> SUCCESS
> 9:38:07.4356774 AM NOTEPAD.EXE 4264 4928 CloseFile
> \localhost\share\ahoj.txt SUCCESS
> 9:38:07.4357051 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE
> \localhost\share\ahoj.txt SUCCESS
>
>
> 0 fltmgr.sys FltpPerformPreCallbacks + 0x2f7
> 1 fltmgr.sys FltpPassThroughFastIo + 0x4d
> 2 fltmgr.sys FltpFastIoWrite + 0x1ce
> 3 rdbss.sys RxShadowFastLowIo + 0x268
> 4 rdbss.sys RxLowIoSubmit + 0xba
> 5 rdbss.sys RxLowIoWriteShell + 0x7f
> 6 rdbss.sys RxCommonFileWrite + 0x1ba2
> 7 rdbss.sys RxCommonWrite + 0xe6 0
> 8 rdbss.sys RxFsdCommonDispatch + 0x870
> 9 rdbss.sys RxFsdDispatch + 0x224
> 10 mrxsmb.sys MRxSmbFsdDispatch + 0xc0
> 11 mup.sys MupiCallUncProvider + 0x161
> 12 mup.sys MupStateMachine + 0x128
> 13 mup.sys MupFsdIrpPassThrough + 0x12d
> 14 fltmgr.sys FltpLegacyProcessingAfterPreCallbacksCompleted + 0x24f
> 15 fltmgr.sys FltpDispatch + 0xcf
> 16 eamon.sys eamon.sys + 0x5943
> 17 fltmgr.sys FltpLegacyProcessingAfterPreCallbacksCompleted + 0x24f
> 18 fltmgr.sys FltpDispatch + 0xcf
> 19 ntoskrnl.exe IopSynchronousServiceTail + 0xf9
> 20 ntoskrnl.exe NtWriteFile + 0x7e2
>
>
> “Normal” stack which communicates to TCP/IP looks like
>
> eeaac824 f7f8da4b 82012500 81f38790 822feeb0
> rdbss!RxCeSubmitAsynchronousTdiRequest+0x28
> eeaac85c f7f971b4 822fa384 822fa3ac 8224ed54 rdbss!RxTdiSend+0x1ca
> eeaac8b8 f7f18b79 8224ed88 00000000 81f9b684 rdbss!RxCeSend+0x74
> eeaac8e0 f7ef5ad0 8224ed38 81f9c7b8 81f9b398 mrxsmb!VctTranceive+0x66
> eeaac924 f7f1ad7a 00f9b398 00000000 81f9b684 mrxsmb!SmbCeTranceive+0x233
> eeaac960 f7f1d8f2 00000000 0000002c f7f1d592
> mrxsmb!SmbPseOrdinaryExchange+0x18e
> eeaac9b0 f7f1ac04 01f9b398 822cb2e0 eeaac9e4
> mrxsmb!SmbPseExchangeStart_Write+0x1e3
> eeaac9c0 f7f1905f 81f9b398 80701940 f7f14940
> mrxsmb!SmbPseExchangeStart_default+0x12
> eeaac9e4 f7f1d410 81f9c7b8 822cb360 822cb2e0
> mrxsmb!SmbCeInitiateExchange+0x287
> eeaaca24 f7f975b3 822cb2e0 e19d1b10 f7f95a78 mrxsmb!MRxSmbWrite+0x309
> eeaaca4c f7f9b302 012cb2e0 f7f9b321 00000000 rdbss!RxLowIoSubmit+0x1c3
> eeaaca6c f7f9ba5b 822cb2e0 f7f9b40d 822cb2e0 rdbss!RxLowIoWriteShell+0x77
> eeaacb90 f7f8cd51 822cb2e0 82330820 f7f958a8 rdbss!RxCommonWrite+0x116f
> eeaacc28 f7f96cc2 f7f958a8 82033c04 82033c78
> rdbss!RxFsdCommonDispatch+0x353
> eeaacc50 f7f18317 81ff9030 82033c04 82330820 rdbss!RxFsdDispatch+0xda
> eeaacc70 804e13d9 00000000 01033c08 80701410
> mrxsmb!MRxSmbFsdDispatch+0x134
>
>

Jiajun_Lu · August 31, 2010, 4:19pm

Thanks Bronislav, your information is very appreciated.

It seems when the file is access from local, rdbss will directly write
to the file system. Normally, it will go through mrxsmb again. If this
is true, probably rdbss denied the write request when our driver is
attached. Do I understand correctly?

Is there anyway to get more logging or messages from rdbss?

Thanks,
Max

On 8/30/2010 3:27 AM, xxxxx@xythos.com wrote:

Short investigation: It looks like there is a special path for localhost requests. Below is data captured by procmon. In log below the WriteFile request to D:\share\ahoj.txt has process context NOTEPAD, which is client side application accessing file on the server side. Weird! Stack of that requests proves that RDBSS has some special processing of requests coming to local system. E.G. It means that your driver is on the stack twice, with the two instances of device. I cannot follow causes and consequences as I know minimum about your driver design and system configuration.

Bronislav Gabrhelik

9:38:07.4311381 AM NOTEPAD.EXE 4264 4928 CreateFile \localhost\share\ahoj.txt SUCCESS Desired Access: Generic Read/Write, Disposition: OpenIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, AllocationSize: 0, OpenResult: Opened
9:38:07.4314799 AM NOTEPAD.EXE 4264 4928 CreateFile \localhost\share\ahoj.txt SUCCESS Desired Access: Read Attributes, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Complete If Oplocked, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
9:38:07.4321893 AM NOTEPAD.EXE 4264 4928 QueryFileInternalInformationFile \localhost\share\ahoj.txt SUCCESS IndexNumber: 0x200000023fa0e
9:38:07.4322041 AM NOTEPAD.EXE 4264 4928 CloseFile \localhost\share\ahoj.txt SUCCESS
9:38:07.4322325 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE \localhost\share\ahoj.txt SUCCESS
9:38:07.4326360 AM NOTEPAD.EXE 4264 4928 CreateFile \localhost\share\ahoj.txt SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Complete If Oplocked, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
9:38:07.4334308 AM NOTEPAD.EXE 4264 4928 QueryStandardInformationFile \localhost\share\ahoj.txt FAST IO DISALLOWED
9:38:07.4334493 AM NOTEPAD.EXE 4264 4928 QueryStandardInformationFile \localhost\share\ahoj.txt SUCCESS AllocationSize: 0, EndOfFile: 0, NumberOfLinks: 1, DeletePending: False, Directory: False
9:38:07.4335180 AM NOTEPAD.EXE 4264 4928 CloseFile \localhost\share\ahoj.txt SUCCESS
9:38:07.4335480 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE \localhost\share\ahoj.txt SUCCESS
9:38:07.4344009 AM NOTEPAD.EXE 4264 4928 WriteFile \localhost\share\ahoj.txt SUCCESS Offset: 0, Length: 6, Priority: Normal
9:38:07.4344289 AM NOTEPAD.EXE 4264 4928 WriteFile D:\share\ahoj.txt FAST IO DISALLOWED Offset: 0, Length: 6
9:38:07.4344500 AM NOTEPAD.EXE 4264 4928 WriteFile D:\share\ahoj.txt SUCCESS Offset: 0, Length: 6
9:38:07.4344939 AM NOTEPAD.EXE 4264 4928 SetEndOfFileInformationFile \localhost\share\ahoj.txt SUCCESS EndOfFile: 6
9:38:07.4345127 AM NOTEPAD.EXE 4264 4928 SetAllInformationFile \localhost\share\ahoj.txt SUCCESS AllocationSize: 6
9:38:07.4348813 AM NOTEPAD.EXE 4264 4928 CreateFile \localhost\share\ SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
9:38:07.4350462 AM NOTEPAD.EXE 4264 4928 QueryDirectory \localhost\share\ahoj.txt SUCCESS Filter: ahoj.txt, 1: ahoj.txt
9:38:07.4351907 AM NOTEPAD.EXE 4264 4928 CloseFile \localhost\share\ SUCCESS
9:38:07.4352148 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE \localhost\share\ SUCCESS
9:38:07.4356774 AM NOTEPAD.EXE 4264 4928 CloseFile \localhost\share\ahoj.txt SUCCESS
9:38:07.4357051 AM NOTEPAD.EXE 4264 4928 IRP_MJ_CLOSE \localhost\share\ahoj.txt SUCCESS

0 fltmgr.sys FltpPerformPreCallbacks + 0x2f7
1 fltmgr.sys FltpPassThroughFastIo + 0x4d
2 fltmgr.sys FltpFastIoWrite + 0x1ce
3 rdbss.sys RxShadowFastLowIo + 0x268
4 rdbss.sys RxLowIoSubmit + 0xba
5 rdbss.sys RxLowIoWriteShell + 0x7f
6 rdbss.sys RxCommonFileWrite + 0x1ba2
7 rdbss.sys RxCommonWrite + 0xe6 0
8 rdbss.sys RxFsdCommonDispatch + 0x870
9 rdbss.sys RxFsdDispatch + 0x224
10 mrxsmb.sys MRxSmbFsdDispatch + 0xc0
11 mup.sys MupiCallUncProvider + 0x161
12 mup.sys MupStateMachine + 0x128
13 mup.sys MupFsdIrpPassThrough + 0x12d
14 fltmgr.sys FltpLegacyProcessingAfterPreCallbacksCompleted + 0x24f
15 fltmgr.sys FltpDispatch + 0xcf
16 eamon.sys eamon.sys + 0x5943
17 fltmgr.sys FltpLegacyProcessingAfterPreCallbacksCompleted + 0x24f
18 fltmgr.sys FltpDispatch + 0xcf
19 ntoskrnl.exe IopSynchronousServiceTail + 0xf9
20 ntoskrnl.exe NtWriteFile + 0x7e2

“Normal” stack which communicates to TCP/IP looks like

eeaac824 f7f8da4b 82012500 81f38790 822feeb0 rdbss!RxCeSubmitAsynchronousTdiRequest+0x28
eeaac85c f7f971b4 822fa384 822fa3ac 8224ed54 rdbss!RxTdiSend+0x1ca
eeaac8b8 f7f18b79 8224ed88 00000000 81f9b684 rdbss!RxCeSend+0x74
eeaac8e0 f7ef5ad0 8224ed38 81f9c7b8 81f9b398 mrxsmb!VctTranceive+0x66
eeaac924 f7f1ad7a 00f9b398 00000000 81f9b684 mrxsmb!SmbCeTranceive+0x233
eeaac960 f7f1d8f2 00000000 0000002c f7f1d592 mrxsmb!SmbPseOrdinaryExchange+0x18e
eeaac9b0 f7f1ac04 01f9b398 822cb2e0 eeaac9e4 mrxsmb!SmbPseExchangeStart_Write+0x1e3
eeaac9c0 f7f1905f 81f9b398 80701940 f7f14940 mrxsmb!SmbPseExchangeStart_default+0x12
eeaac9e4 f7f1d410 81f9c7b8 822cb360 822cb2e0 mrxsmb!SmbCeInitiateExchange+0x287
eeaaca24 f7f975b3 822cb2e0 e19d1b10 f7f95a78 mrxsmb!MRxSmbWrite+0x309
eeaaca4c f7f9b302 012cb2e0 f7f9b321 00000000 rdbss!RxLowIoSubmit+0x1c3
eeaaca6c f7f9ba5b 822cb2e0 f7f9b40d 822cb2e0 rdbss!RxLowIoWriteShell+0x77
eeaacb90 f7f8cd51 822cb2e0 82330820 f7f958a8 rdbss!RxCommonWrite+0x116f
eeaacc28 f7f96cc2 f7f958a8 82033c04 82033c78 rdbss!RxFsdCommonDispatch+0x353
eeaacc50 f7f18317 81ff9030 82033c04 82330820 rdbss!RxFsdDispatch+0xda
eeaacc70 804e13d9 00000000 01033c08 80701410 mrxsmb!MRxSmbFsdDispatch+0x134

NTFSD is sponsored by OSR

For our schedule of debugging and file system seminars
(including our new fs mini-filter seminar) visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer

Bronislav_Gabrhelik · September 2, 2010, 6:40am

It looks like RDBSS uses FastIo. I thought that only IO Manager is originator of Fast IOs up to now. Rdbss might not handle the case when FastIO is not supported, or your filter incorrectly declares that it doesnt support fastIOs.

Bronek

OSR_Community_User · September 2, 2010, 10:09am

> It looks like RDBSS uses FastIo. I thought that only IO Manager is originator of Fast IOs up to now.

I think SRV can use FastIo, at least MDL-related ones.

–
Maxim S. Shatskih
Windows DDK MVP
xxxxx@storagecraft.com
http://www.storagecraft.com

Jiajun_Lu · September 8, 2010, 7:32pm

On 9/2/2010 9:09 AM, Maxim S. Shatskih wrote:

> It looks like RDBSS uses FastIo. I thought that only IO Manager is originator of Fast IOs up to now.

I think SRV can use FastIo, at least MDL-related ones.

That was my first thought too. I did implement fast_network_open_info,
fast read and fast write. But it still doesn’t work. Fast write was
never called during the save.

OSR_Community_User · September 8, 2010, 8:23pm

You can try the OSR IrpTracker and see who fails the IRP when \Device\Mup gets the IRP_MJ_WRITE