file_mmap unavailable errors on ntfs partition

[CkNoSFeRaTU]

qBittorrent & operating system versions

qBittorrent: v4.4.3.1 x64 Operation system: gentoo amd64 Kernel: 5.15.44 from sys-kernel/gentoo-sources Qt: 5.15.4 libtorrent-rasterbar: v2.0.6

What is the problem?

When first chunk coming for a file in torrent client window is freezing for ~10 seconds and after that torrent is stopped with 'Errored: Resource temporarily unavailable". The file it complained can be observed to be successfully created on destination. If you keep restarting torrent then the same behaviour will happen for every other file in torrent. File sizes seems doesn't matter. Once all files are created that way issue is gone for that torrent. That with "pre-allocate disk space for all files" turned off. But If you turn it on it doesn't change anything, at least for torrents which are already added. Not tried to restart client after the change or readding a torrent.

Steps to reproduce

1. Mount ntfs partition using ntfs3 kernel driver
2. Try to add and download any torrent with alive peers to this partition.

Additional context

That happens on partitions mounted with ntfs3 kernel driver upstreamed by Paragon to vanilla kernel last year.

Log(s) & preferences file(s)

03/07/2022 19:38 - File error alert. Torrent: "example". File: "/mnt/ntfs-d/example/filename.exe". Reason: example file_mmap (/mnt/ntfs-d/example/filename.exe) error: Resource temporarily unavailable 03/07/2022 19:32 - File error alert. Torrent: "example". File: "/mnt/ntfs-d/example/filename-7.bin". Reason: example file_mmap (/mnt/ntfs-d/example/filename-7.bin) error: Resource temporarily unavailable 03/07/2022 19:30 - Options saved. (turned on file pre-allocation) 03/07/2022 19:28 - File error alert. Torrent: "example". File: "/mnt/ntfs-d/example/filename-5.bin". Reason: example file_mmap (/mnt/ntfs-d/example/filename-5.bin) error: Resource temporarily unavailable 03/07/2022 19:25 - File error alert. Torrent: "example". File: "/mnt/ntfs-d/example/filename-6.bin". Reason: example file_mmap (/mnt/ntfs-d/example/filename-6.bin) error: Resource temporarily unavailable 03/07/2022 19:23 - File error alert. Torrent: "example". File: "/mnt/ntfs-d/example/filename-4.bin". Reason: example file_mmap (/mnt/ntfs-d/example/filename-4.bin) error: Resource temporarily unavailable 03/07/2022 19:21 - File error alert. Torrent: "example". File: "/mnt/ntfs-d/example/filename-1.bin". Reason: example file_mmap (/mnt/ntfs-d/example/filename-1.bin) error: Resource temporarily unavailable 03/07/2022 19:20 - File error alert. Torrent: "example". File: "/mnt/ntfs-d/example/filename-8.bin". Reason: example file_mmap (/mnt/ntfs-d/example/filename-8.bin) error: Resource temporarily unavailable 03/07/2022 19:19 - File error alert. Torrent: "example". File: "/mnt/ntfs-d/example/filename-3.bin". Reason: example file_mmap (/mnt/ntfs-d/example/filename-3.bin) error: Resource temporarily unavailable

[glassez]

@arvidn Do you think this is a problem with the NTFS driver?

[arvidn]

this has come up before, but I believe that was with the user-space NFTS driver. (ntfs-3g)

[CkNoSFeRaTU]

Yeah, I didn't check libtorrent's issues prior to creating this issue. There is the same bug already filled half a year ago: https://github.com/arvidn/libtorrent/issues/6612. Also with Paragon's kernel driver and same EAGAIN error.

I don't believe the problem is really with ntfs3 driver, just quirk in implementation or limitations of ntfs filesystem itself. According to comments in ntfs driver source code it cannot have more than one unwritten area at a time.

In any case EAGAIN should be treated as wait and retry later and not as an error.

[arvidn]

so, the filesystem only supports a single dirty memory mapped file at a time? you could try to change file_pool_size to 0 or 1. It's weird though, it's the mmap() call itself that's failing. By the time the mapping is being made, it can't know whether the file will be dirtied or not.

[CkNoSFeRaTU]

I compiled current linux-next kernel and added a couple of printks around inode management in ntfs3 module. Thats what happens:

[ 2450.419139] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1197)] ntfs_create_inode start: 0
[ 2450.419199] ntfs3: [ntfs_new_inode (fs/ntfs3/fsntfs.c:1653)] insert_inode_locked: 563524
[ 2450.419204] ntfs3: [ntfs_new_inode (fs/ntfs3/fsntfs.c:1659)] insert_inode_locked success: 563524
[ 2450.419225] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1650)] unlock_new_inode: 563524
[ 2450.419229] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1653)] ntfs_create_inode stop: 563524
[ 2450.472672] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:399)] before inode_trylock: 563524
[ 2450.472678] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:401)] inode_trylock failed: 563524
[ 2450.472691] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:399)] before inode_trylock: 563524
[ 2450.472694] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:405)] inode_lock acquired: 563524
[ 2451.931049] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:409)] inode_unlock: 563524

After creating inode there are a continuous mmap calls (usually 2, sometimes up to 10) which trying to acquire inode lock and eventually one of them successed. After that all activity is stopped. Meanwhile qBittorrent's UI is still frozen for 10-20 seconds after lock acquired and when it become unstuck it immediately errors out.

If I patch ntfs3 there: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/fs/ntfs3/file.c?h=v5.19-rc5&id=88084a3df1672e131ddc1b4e39eeacfd39864acf#n400 by removing EAGAIN error and waiting for lock release with inode_lock(lock) then all is good and I always have this output:

[ 2834.565633] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1201)] ntfs_create_inode start: 0
[ 2834.565690] ntfs3: [ntfs_new_inode (fs/ntfs3/fsntfs.c:1653)] insert_inode_locked: 563524
[ 2834.565696] ntfs3: [ntfs_new_inode (fs/ntfs3/fsntfs.c:1659)] insert_inode_locked success: 563524
[ 2834.565719] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1654)] unlock_new_inode: 563524
[ 2834.565723] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1657)] ntfs_create_inode stop: 563524
[ 2834.621050] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:399)] before inode_trylock: 563524
[ 2834.621054] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:406)] inode_trylock failed, using inode_lock: 563524
[ 2834.621069] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:410)] inode_lock acquired: 563524
[ 2836.089175] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:414)] inode_unlock: 563524

But that most likely isn't good, as inode_lock could potentially hang all threads that way if locks are never releasing...

TLDR There are two problems: 1) Something is briefly holding inode locked after file creation finished and ntfs3 unlocked it... And at first glance at ntfs3's module locks code it doesn't seem to be ntfs3 module as it clearly releasing lock and I didn't find any code where it could reacquire lock again. Also my printks seems slightly offset this race and with them I have a higher chance to acquire mmap's inode lock on first try, in that lucky case libtorrent doesn't have any issues. 2) Something continuously trying to mmap and successed. But libtorrent sees only first EAGAIN? (Just guessing because not looked in libtorrent's code what really happens there). And why that weird 10-20s UI hang after all disk activity finished long ago?

P.S. I tried with file_pool_size = 1 and that change nothing. UI prevents me to set it to 0.

UPDATE: Setting aio_threads = 1, seems to fix the issue and mmap calls don't contend between themselves. Also Increased debug of ntfs3 module with the problem (thats with default aio_threads = 10):

[11636.494935] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1201)] start: 0
[11636.494964] ntfs3: [ntfs_new_inode (fs/ntfs3/fsntfs.c:1653)] insert_inode_locked: 563524
[11636.494967] ntfs3: [ntfs_new_inode (fs/ntfs3/fsntfs.c:1659)] insert_inode_locked success: 563524
[11636.494980] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1654)] unlock_new_inode: 563524
[11636.494982] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1657)] stop: 563524
[11636.494986] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.494988] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.494993] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.494996] ntfs3: [ntfs_extend (fs/ntfs3/file.c:466)] start: 563524
[11636.496443] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.496452] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.506460] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.506474] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.508336] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.508342] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.517530] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.517539] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.519151] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.519161] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.520826] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.520835] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.528485] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.528495] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.530038] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.530045] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.532023] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.532030] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.552534] ntfs3: [ntfs_extend (fs/ntfs3/file.c:506)] stop err 0: 563524
[11636.552539] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552552] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552553] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552553] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552555] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552557] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552558] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552574] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552575] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552587] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552587] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552586] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552589] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552590] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552592] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552591] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552594] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552605] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552609] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552616] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.552617] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552618] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.552619] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552622] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552624] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552626] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552630] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552631] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552633] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552633] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552637] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552638] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552643] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.552645] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.552646] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552650] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552652] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552654] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552655] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552676] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552679] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552683] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552683] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552686] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552686] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552691] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552693] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552695] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552695] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552698] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552699] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552702] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552704] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552704] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552714] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552720] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552722] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552723] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552724] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552726] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.552729] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552729] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.552729] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11636.552733] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11636.552734] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552739] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552741] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552742] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552744] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552744] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552749] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552752] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552753] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552756] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552756] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552760] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552760] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552763] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552764] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552775] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552778] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552779] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552782] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552785] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552784] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552787] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552791] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552798] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552799] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552802] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552802] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552803] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552805] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552806] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552806] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552809] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552810] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552815] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552818] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552823] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552824] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552826] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552827] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552830] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552832] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552838] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552838] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552843] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552846] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552847] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552849] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552851] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552853] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552863] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552867] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552878] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552881] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552884] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552885] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552885] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552885] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552888] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11636.552889] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552892] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:433)] inode_trylock failed: 563524
[11636.552896] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err -11: 563524
[11636.552900] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552904] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552914] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11636.552916] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:517)] start: 563524
[11636.552921] ntfs3: [ntfs_truncate (fs/ntfs3/file.c:568)] stop: 563524
[11636.552922] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11636.552921] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11636.552925] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11636.552928] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:441)] inode_lock acquired: 563524
[11636.552930] ntfs3: [ntfs_extend_initialized_size (fs/ntfs3/file.c:124)] start: 563524
[11636.552933] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11636.552936] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11638.241317] ntfs3: [ntfs_extend_initialized_size (fs/ntfs3/file.c:198)] stop: 563524
[11638.241323] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:445)] inode_unlock: 563524
[11638.241325] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err 0: 563524
[11638.241341] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11638.241346] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err 0: 563524
[11638.241377] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11638.241379] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524
[11638.241451] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1304)] start: 563524
[11638.241454] ntfs3: [ntfs_file_release (fs/ntfs3/file.c:1317)] stop err 0: 563524

And with aio_threads = 1:

[11700.064339] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1201)] start: 0
[11700.064396] ntfs3: [ntfs_new_inode (fs/ntfs3/fsntfs.c:1653)] insert_inode_locked: 563524
[11700.064401] ntfs3: [ntfs_new_inode (fs/ntfs3/fsntfs.c:1659)] insert_inode_locked success: 563524
[11700.064423] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1654)] unlock_new_inode: 563524
[11700.064427] ntfs3: [ntfs_create_inode (fs/ntfs3/inode.c:1657)] stop: 563524
[11700.064435] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1265)] start: 563524
[11700.064438] ntfs3: [ntfs_file_open (fs/ntfs3/file.c:1291)] stop: 563524
[11700.064448] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:821)] start: 563524
[11700.064452] ntfs3: [ntfs_extend (fs/ntfs3/file.c:466)] start: 563524
[11700.117486] ntfs3: [ntfs_extend (fs/ntfs3/file.c:506)] stop err 0: 563524
[11700.117493] ntfs3: [ntfs3_setattr (fs/ntfs3/file.c:873)] stop err 0: 563524
[11700.117514] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:386)] start: 563524
[11700.117517] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:430)] before inode_trylock: 563524
[11700.117519] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:441)] inode_lock acquired: 563524
[11700.117520] ntfs3: [ntfs_extend_initialized_size (fs/ntfs3/file.c:124)] start: 563524
[11701.708268] ntfs3: [ntfs_extend_initialized_size (fs/ntfs3/file.c:198)] stop: 563524
[11701.708274] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:445)] inode_unlock: 563524
[11701.708276] ntfs3: [ntfs_file_mmap (fs/ntfs3/file.c:453)] stop err 0: 563524

[arvidn]

iirc, the way the multi-threaded mmap disk io works is that when it needs access to a file, it first checks if some other thread has already mapped the file. If not, the file is mapped and then it's inserted in the (cross-thread) pool of file mappings. At that point, if some other thread also mapped the same file and won the race to insert it, the new map is closed and the one in the pool is used.

It appears the ntfs driver doesn't like that approach. It might be worth having a state in the file_view_pool indicating that there's a thread currently working on mapping the file, so other threads can just wait on that mapping.

[CkNoSFeRaTU]

I conducted a couple of race tests and it seems that issue is not with contending mmaps themselves as seemed at first. It seems you can mmap however times you want simultaneosly as long as file is not currently changing its file size and marked as dirty. And the problem is that libtorrent tries to concurrently extend file size prior to mmap which is needed as you can't mmap zero sized files. So yeah If you eliminate concurrency during initial file extend and subsequent mmap setup then ntfs3 should be happy.

Tests I did: test 1) Create a file with zero length and open multiple file handles to it. Start a race where one thread is writing to file with simple write call and so increasing its size. Anothers continually checking that file size became non-zero with fstat and if it is then try to mmap. Result is you can't mmap until that write call finished even if fstat already reporting that file size changed.

test 2) That one more like what's happening in our case. Create a file with zero length. Start a race where each thread is opening file handle to that file and issue truncate. Then when it finished try to mmap. Result is that first threads will fail to mmap. That doesn't happen if there are only one thread.

[arvidn]

@CkNoSFeRaTU Any chance you could test this patch? https://github.com/arvidn/libtorrent/pull/6958

[CkNoSFeRaTU]

Brifly tested it against linux-next kernel. qbittorrent's UI is still freezing like hell on every file allocation. But "Resource temporarily unavailable" issue seems to be gone as when UI become unstuck it continues to download.

I still see that some inode_trylocks are failing. But now in ntfs_file_write_iter and not file_mmap. But there they return EAGAIN only if "No wait AIO" (IOCB_NOWAIT flag) is requested. Otherwise they block with inode_lock and wait for lock release which is the case with libtorrent...

[ghost]

Is this considered fixed in latest libtorrent?

[crimist]

I believe this issue can be closed as there are no unavailable errors anymore. However, I am having the same issue where the UI freezes after adding a large torrent on ntfs drive using ntfs3 kernel driver. I'm guessing this is because the IO is performed on the UI thread? Should I open another issue for this?

[pinanew]

There is similar problem: ntfs3: sda2: ino=579cd, "test.bin" mmap(write) compressed not supported but I think it's 100% ntfs3 problem.