On Mon 02-06-25 16:52:22, Luis Henriques wrote:
> On Mon, Jun 02 2025, Luis Henriques wrote:
> > Hi Christian,
> >
> > On Fri, Feb 07 2025, Christian Brauner wrote:
> >
> >> Before 2011 there was no meaningful synchronization between
> >> read/readdir/write/seek. Only in commit
> >> ef3d0fd27e90 ("vfs: do (nearly) lockless generic_file_llseek")
> >> synchronization was added for SEEK_CUR by taking f_lock around
> >> vfs_setpos().
> >>
> >> Then in 2014 full synchronization between read/readdir/write/seek was
> >> added in commit 9c225f2655e3 ("vfs: atomic f_pos accesses as per POSIX")
> >> by introducing f_pos_lock for regular files with FMODE_ATOMIC_POS and
> >> for directories. At that point taking f_lock became unnecessary for such
> >> files.
> >>
> >> So only acquire f_lock for SEEK_CUR if this isn't a file that would have
> >> acquired f_pos_lock if necessary.
> >
> > I'm seeing the splat below with current master. It's unlikely to be
> > related with this patch, but with recent overlayfs changes. I'm just
> > dropping it here before looking, as maybe it has already been reported.
>
> OK, just to confirm that it looks like this is indeed due to this patch.
> I can reproduce it easily, and I'm not sure why I haven't seen it before.
Thanks for report! Curious. This is:
VFS_WARN_ON_ONCE((file_count(file) > 1) &&
!mutex_is_locked(&file->f_pos_lock));
Based on the fact this is ld(1) I expect this is a regular file.
Christian, cannot it happen that we race with dup2() so file_count is
increased after we've checked it in fdget_pos() and before we get to this
assert?
Honza
> > [ 133.133745] ------------[ cut here ]------------
> > [ 133.133855] WARNING: CPU: 6 PID: 246 at fs/file.c:1201 file_seek_cur_needs_f_lock+0x4a/0x60
> > [ 133.133940] Modules linked in: virtiofs fuse
> > [ 133.134009] CPU: 6 UID: 1000 PID: 246 Comm: ld Not tainted 6.15.0+ #124 PREEMPT(full)
> > [ 133.134110] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014
> > [ 133.134235] RIP: 0010:file_seek_cur_needs_f_lock+0x4a/0x60
> > [ 133.134286] Code: 00 48 ba fe ff ff ff ff ff ff bf 48 83 e8 01 48 39 c2 73 06 b8 01 00 00 00 c3 48 81 c7 90 00 00 00 e8 da 0e db ff 84 c0 75 ea <0f> 0b b8 01 00 00 00 c3 31 c0 c3 66 66 2e 0f 1f 84 00 00 00 00 00
> > [ 133.134471] RSP: 0018:ffffc90000e67ea0 EFLAGS: 00010246
> > [ 133.134526] RAX: 0000000000000000 RBX: fffffffffffffc01 RCX: 7fffffffffffffff
> > [ 133.134683] RDX: bffffffffffffffe RSI: fffffffffffffc01 RDI: ffff888101bd1e90
> > [ 133.135430] RBP: ffff888101bd1e00 R08: 00000000002a3988 R09: 0000000000000000
> > [ 133.136172] R10: ffffc90000e67ed0 R11: 0000000000000000 R12: 7fffffffffffffff
> > [ 133.136351] R13: ffff888101bd1e00 R14: ffff888105d823c0 R15: 0000000000000001
> > [ 133.136433] FS: 00007fd7880d2b28(0000) GS:ffff8884ad411000(0000) knlGS:0000000000000000
> > [ 133.136516] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [ 133.136586] CR2: 0000559b3af3a520 CR3: 0000000103cb1000 CR4: 0000000000750eb0
> > [ 133.136667] PKRU: 55555554
> > [ 133.136694] Call Trace:
> > [ 133.136720] <TASK>
> > [ 133.136747] generic_file_llseek_size+0x93/0x120
> > [ 133.136802] ovl_llseek+0x86/0xf0
> > [ 133.136844] ksys_lseek+0x39/0x90
> > [ 133.136884] do_syscall_64+0x73/0x2c0
> > [ 133.136932] entry_SYSCALL_64_after_hwframe+0x4b/0x53
> > [ 133.136994] RIP: 0033:0x7fd788098262
> > [ 133.137034] Code: 48 63 d2 48 63 ff 4d 63 c0 b8 09 01 00 00 0f 05 48 89 c7 e8 8a 80 fd ff 48 83 c4 08 c3 48 63 ff 48 63 d2 b8 08 00 00 00 0f 05 <48> 89 c7 e9 70 80 fd ff 8d 47 27 53 89 fb 83 f8 4e 76 27 b8 ec ff
> > [ 133.137223] RSP: 002b:00007fffffaf82c8 EFLAGS: 00000283 ORIG_RAX: 0000000000000008
> > [ 133.137302] RAX: ffffffffffffffda RBX: 00007fd787ba1010 RCX: 00007fd788098262
> > [ 133.137385] RDX: 0000000000000001 RSI: fffffffffffffc01 RDI: 000000000000000f
> > [ 133.137465] RBP: 0000000000000000 R08: 0000000000000064 R09: 00007fd787c3c6a0
> > [ 133.137545] R10: 000000000000000e R11: 0000000000000283 R12: 00007fffffafa694
> > [ 133.137625] R13: 0000000000000039 R14: 0000000000000038 R15: 00007fffffafaa79
> > [ 133.137708] </TASK>
> > [ 133.137736] irq event stamp: 1034649
> > [ 133.137776] hardirqs last enabled at (1034657): [<ffffffff8133c642>] __up_console_sem+0x52/0x60
> > [ 133.137872] hardirqs last disabled at (1034664): [<ffffffff8133c627>] __up_console_sem+0x37/0x60
> > [ 133.137966] softirqs last enabled at (1012640): [<ffffffff812c4884>] irq_exit_rcu+0x74/0x110
> > [ 133.138064] softirqs last disabled at (1012633): [<ffffffff812c4884>] irq_exit_rcu+0x74/0x110
> > [ 133.138161] ---[ end trace 0000000000000000 ]---
--
Jan Kara <jack@xxxxxxxx>
SUSE Labs, CR
