Overlapped reads of same file not handled by multiple IO threads in userspace FS

157 views
Skip to first unread message

Bradley Schatz

unread,
Mar 4, 2020, 11:29:07 PM3/4/20
to WinFsp
Hi, 

We are experimenting porting from Dokany to WinFSP because we want scalable async IO in our FS. 

We are issuing multiple async reads (IO depth 64) to a single virtual file backed by WinFSP. The reads are of non-overlapping file regions. 

Setting a breakpoint on the Read handler in our filesystem yields only on a single thread pausing, with no other IO threads appearing to handle the other queued requests. (ie, in our Dokany implementation, we would get 16 threads paused, one for each IO thread). 

We have tried manually setting the IO thread count in FspFilesystemStartDispatcher as an attempt to fix this, but no joy. 

Can you confirm that we should be seeing multiple IO threads handling requests for reads to a single file? We'd appreciate your thoughts on where we might be going wrong. 

Thanks,
Bradley


- OS version and build: Windows 10.1903
- WinFsp version : 2020 (1.6.20027)

Bill Zissimopoulos

unread,
Mar 5, 2020, 9:46:30 AM3/5/20
to Bradley Schatz, WinFsp

SUMMARY

 

The WinFsp concurrency model allows for concurrent READs to the same file. It is therefore possible to get multiple concurrent READs on different threads. This of course assumes that other application(s) are issuing such READs to the file system and that the Cache Manager is not involved which may influence READ ordering.

 

Please read about the user mode locking strategy at this link and ensure that you correctly configure your file system.

 

https://github.com/billziss-gh/winfsp/blob/v1.7B1/inc/winfsp/winfsp.h#L117-L146

 

 

EXPLANATION

 

WinFsp applies locks both in kernel and user mode and for multiple purposes. Many of these locks are needed for the correct operation of WinFsp, but a few are also provided as a convenience to the user mode file system.

 

The following locks are significant for user mode file system developers. All such locks are exclusive/shared locks. It should be noted that kernel mode locks should be considered an implementation detail and that only the documented user mode locks should be relied upon to always be there.

 

Kernel mode (managed by the FSD):

 

  • Rename lock: This is a *namespace* lock that is acquired shared during Create/Open and exclusive during Rename.
  • I/O lock: This is a *per-file* lock that is acquired shared during read operations (e.g. READ, QUERYINFORMATION, etc.) and exclusive during write operations (e.g. WRITE, SETINFORMATION, etc.)

 

User mode (managed by the DLL):

 

 

Bill

--
You received this message because you are subscribed to the Google Groups "WinFsp" group.
To unsubscribe from this group and stop receiving emails from it, send an email to winfsp+un...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/winfsp/b8b69396-9880-4ddb-b0b1-a371ec9b20c7%40googlegroups.com.

Bradley Schatz

unread,
Mar 5, 2020, 6:10:26 PM3/5/20
to WinFsp
Hi Bill,
Thanks for your detailed reply. 

We are using FSP_FILE_SYSTEM_OPERATION_GUARD_STRATEGY_FINE for the Per-Operation Guard Lock.


This of course assumes that other application(s) are issuing such READs to the file system and that the Cache Manager is not involved which may influence READ ordering.


The concurrent reads are all from the same thread and using the same file handle. Would that serialise the accesses?

Thanks,
Bradley

Bill Zissimopoulos

unread,
Mar 6, 2020, 3:39:39 AM3/6/20
to Bradley Schatz, WinFsp

It depends how you are issuing them.

 

If you open the file handle in overlapped mode and also issue them using overlapped I/O then they will not be serialized.

 

OTOH, if you open the file handle in non-overlapped mode, then the I/O Manager takes locks on all I/O and therefore the operations will be serialized.

 

Bill

--

You received this message because you are subscribed to the Google Groups "WinFsp" group.
To unsubscribe from this group and stop receiving emails from it, send an email to winfsp+un...@googlegroups.com.

Bradley Schatz

unread,
Mar 12, 2020, 10:49:30 PM3/12/20
to WinFsp
Thanks Bill, 
I have created test cases that:
  • (a) CreateFile with FILE_FLAG_OVERLAPPED and 16x ReadFile with OVERLAPPED, and 
  • (b) regular synchronous IO CreateFile with 16x ReadFile (no OVERLAPPED)
I verified this using procmon. The target file is only being used by this test, and is open read only. Between tests I clear the file cache using RamMap | Empty Standby List. 

Both result in a single call at a time to the user space filesystem (serialised handling of reads). Not what I was expecting for (a) but expected for (b).

When running these test cases against the equivalent Dokany implementation (same OS, etc), I get multiple concurrent calls to the user space filesystem for (a) and a single call at a time to the user space filesystem for (b).

I built the current git version of winfsp and set a breakpoint at memfs.cpp::Read, using memfs as the UFS. Running my testcase results in the same serial behaviour as with our UFS. 

Any suggestions on diagnosing why this isn't working as expected?

-bradley

$ fltmc filters

Filter Name                     Num Instances    Altitude    Frame
------------------------------  -------------  ------------  -----
bindflt                                 1       409800         0
Sophos Endpoint Defense                38       389220         0
SAVOnAccess                            15       324000         0
storqosflt                              0       244000         0
wcifs                                   1       189900         0
CldFlt                                  0       180451         0
aksdf                                  15       145900         0
FileCrypt                               0       141100         0
luafv                                   1       135000         0
npsvctrig                               1        46000         0
Wof                                    11        40700         0
FileInfo                               15        40500         0

$ fltmc instances
Filter                Volume Name                              Altitude        Instance Name       Frame   SprtFtrs  VlStatus
--------------------  -------------------------------------  ------------  ----------------------  -----   --------  --------
FileInfo              F:                                         40500     FileInfo                  0     00000007
FileInfo              G:                                         40500     FileInfo                  0     00000007
FileInfo              E:                                         40500     FileInfo                  0     00000007
FileInfo              J:                                         40500     FileInfo                  0     00000007
FileInfo              H:                                         40500     FileInfo                  0     00000007
FileInfo              D:                                         40500     FileInfo                  0     00000007
FileInfo                                                         40500     FileInfo                  0     00000007
FileInfo                                                         40500     FileInfo                  0     00000007
FileInfo              C:                                         40500     FileInfo                  0     00000007
FileInfo              \Device\HarddiskVolumeShadowCopy2          40500     FileInfo                  0     00000007
FileInfo              \Device\HarddiskVolumeShadowCopy3          40500     FileInfo                  0     00000007
FileInfo              \Device\HarddiskVolumeShadowCopy4          40500     FileInfo                  0     00000007
FileInfo              \Device\Mup                                40500     FileInfo                  0     00000007
FileInfo              \Device\Volume{d6cc17c5-1734-4085-bce7-964f1e9f5de9}      40500     FileInfo                  0     00000007
FileInfo              V:                                         40500     FileInfo                  0     00000007
SAVOnAccess           F:                                        324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           G:                                        324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           E:                                        324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           J:                                        324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           H:                                        324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           D:                                        324000     SAVOnAccess Instance      0     00000004
SAVOnAccess                                                     324000     SAVOnAccess Instance      0     00000004
SAVOnAccess                                                     324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           C:                                        324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           \Device\HarddiskVolumeShadowCopy2         324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           \Device\HarddiskVolumeShadowCopy3         324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           \Device\HarddiskVolumeShadowCopy4         324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           \Device\Mup                               324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           \Device\Volume{d6cc17c5-1734-4085-bce7-964f1e9f5de9}     324000     SAVOnAccess Instance      0     00000004
SAVOnAccess           V:                                        324000     SAVOnAccess Instance      0     00000004
Sophos Endpoint Defense  F:                                         80670     SophosED Security Enhancer Instance    0     00000000
Sophos Endpoint Defense  F:                                        389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  F:                                        324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  G:                                        389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  G:                                         80670     SophosED Security Enhancer Instance    0     00000000
Sophos Endpoint Defense  G:                                        324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  E:                                         80670     SophosED Security Enhancer Instance    0     00000000
Sophos Endpoint Defense  E:                                        389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  E:                                        324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  J:                                        389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  J:                                        324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  J:                                         80670     SophosED Security Enhancer Instance    0     00000000
Sophos Endpoint Defense  H:                                        324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  H:                                        389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  H:                                         80670     SophosED Security Enhancer Instance    0     00000000
Sophos Endpoint Defense  D:                                         80670     SophosED Security Enhancer Instance    0     00000000
Sophos Endpoint Defense  D:                                        324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  D:                                        389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense                                            389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense                                            324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense                                             80670     SophosED Security Enhancer Instance    0     00000000
Sophos Endpoint Defense                                            324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense                                            389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  C:                                         80670     SophosED Security Enhancer Instance    0     00000000
Sophos Endpoint Defense  C:                                        324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  C:                                        389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  \Device\HarddiskVolumeShadowCopy2         389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  \Device\HarddiskVolumeShadowCopy2         324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  \Device\HarddiskVolumeShadowCopy3         324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  \Device\HarddiskVolumeShadowCopy3         389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  \Device\HarddiskVolumeShadowCopy4         324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  \Device\HarddiskVolumeShadowCopy4         389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  \Device\Mup                               324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  \Device\Mup                               389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  \Device\Volume{d6cc17c5-1734-4085-bce7-964f1e9f5de9}     389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  \Device\Volume{d6cc17c5-1734-4085-bce7-964f1e9f5de9}     324050     SophosED Antivirus Instance    0     00000004
Sophos Endpoint Defense  V:                                        389220     SophosED Activity Monitor Instance    0     00000004
Sophos Endpoint Defense  V:                                        324050     SophosED Antivirus Instance    0     00000004
Wof                   F:                                         40700     Wof Instance              0     00000007
Wof                   G:                                         40700     Wof Instance              0     00000007
Wof                   E:                                         40700     Wof Instance              0     00000007
Wof                   J:                                         40700     Wof Instance              0     00000007
Wof                   H:                                         40700     Wof Instance              0     00000007
Wof                   D:                                         40700     Wof Instance              0     00000007
Wof                                                              40700     Wof Instance              0     00000007
Wof                   C:                                         40700     Wof Instance              0     00000007
Wof                   \Device\HarddiskVolumeShadowCopy2          40700     Wof Instance              0     00000007
Wof                   \Device\HarddiskVolumeShadowCopy3          40700     Wof Instance              0     00000007
Wof                   \Device\HarddiskVolumeShadowCopy4          40700     Wof Instance              0     00000007
aksdf                 F:                                        145900     aksdf Instance            0     00000000
aksdf                 G:                                        145900     aksdf Instance            0     00000000
aksdf                 E:                                        145900     aksdf Instance            0     00000000
aksdf                 J:                                        145900     aksdf Instance            0     00000000
aksdf                 H:                                        145900     aksdf Instance            0     00000000
aksdf                 D:                                        145900     aksdf Instance            0     00000000
aksdf                                                           145900     aksdf Instance            0     00000000
aksdf                                                           145900     aksdf Instance            0     00000000
aksdf                 C:                                        145900     aksdf Instance            0     00000000
aksdf                 \Device\HarddiskVolumeShadowCopy2         145900     aksdf Instance            0     00000000
aksdf                 \Device\HarddiskVolumeShadowCopy3         145900     aksdf Instance            0     00000000
aksdf                 \Device\HarddiskVolumeShadowCopy4         145900     aksdf Instance            0     00000000
aksdf                 \Device\Mup                               145900     aksdf Instance            0     00000000
aksdf                 \Device\Volume{d6cc17c5-1734-4085-bce7-964f1e9f5de9}     145900     aksdf Instance            0     00000000
aksdf                 V:                                        145900     aksdf Instance            0     00000000
bindflt               C:                                        409800     bindflt Instance          0     00000007
luafv                 C:                                        135000     luafv                     0     00000007
npsvctrig             \Device\NamedPipe                          46000     npsvctrig                 0     00000000
wcifs                 C:                                        189900     wcifs Instance            0     00000007


On Friday, 6 March 2020 18:39:39 UTC+10, Bill Zissimopoulos wrote:

It depends how you are issuing them.

 

If you open the file handle in overlapped mode and also issue them using overlapped I/O then they will not be serialized.

 

OTOH, if you open the file handle in non-overlapped mode, then the I/O Manager takes locks on all I/O and therefore the operations will be serialized.

 

Bill

 

 

On 3/6/20, 1:10 AM, win...@googlegroups.com on behalf of Bradley Schatz wrote:

 

Hi Bill,

Thanks for your detailed reply. 

 

We are using FSP_FILE_SYSTEM_OPERATION_GUARD_STRATEGY_FINE

for the Per-Operation Guard Lock.

 

 

This of course assumes that other application(s) are issuing such READs to the file system and that the Cache Manager is not involved which may influence READ ordering.

 

The concurrent reads are all from the same thread and using the same file handle. Would that serialise the accesses?

 

Thanks,
Bradley

--
You received this message because you are subscribed to the Google Groups "WinFsp" group.

To unsubscribe from this group and stop receiving emails from it, send an email to winfsp+unsubscribe@googlegroups.com.

Bill Zissimopoulos

unread,
Mar 14, 2020, 11:58:13 AM3/14/20
to Bradley Schatz, WinFsp

My apologies for the late response, but I was traveling.

 

I think the problem is that you are still doing caching reads. Caching reads work by attempting to copy memory directly from the Cache Manager; if that memory is not paged in, a page fault is incurred which issues a recursive READ to the file system and I believe (but do not know for certain as this is Windows internal code) that this paging READ is synchronous. In other words when using caching READ’s you are at the whims of the Cache Manager algorithms. (Recall that WinFsp uses the Cache Manager.)

 

You should open files with the FILE_FLAG_NO_BUFFERING flag to disable the cache for them. Running MEMFS with FileInfoTimeout != -1 should also do it.

 

If you still find that this does not work as expected, please consider opening an issue on GitHub together with your test program so that I can properly look at it. As far as I can remember there is (or should be) nothing in WinFsp that inherently limits shared READ’s so you may have discovered a bug.

 

Bill

To unsubscribe from this group and stop receiving emails from it, send an email to winfsp+un...@googlegroups.com.

--

You received this message because you are subscribed to the Google Groups "WinFsp" group.

To unsubscribe from this group and stop receiving emails from it, send an email to winfsp+un...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/winfsp/d85bd694-26bd-41ad-b1f4-929c90b36ca6%40googlegroups.com.

Bradley Schatz

unread,
Mar 15, 2020, 8:57:23 PM3/15/20
to WinFsp
Hi Bill,

Thanks for your reply and pointing me to FileInfoTimeout tweak. I have tested with FileInfoTimeout=0, FileInfoTimeout=1, and on the client side, FILE_FLAG_NO_BUFFERING on the open. Still no joy. 

I have raised issue 291, which includes a test program that raises the issue. 

Thanks,
Bradley
Reply all
Reply to author
Forward
0 new messages