2022-05-19 17:46:24

by He Zhe

[permalink] [raw]
Subject: warning for EOPNOTSUPP vfs_copy_file_range

Hi,

We are experiencing the following warning from
"WARN_ON_ONCE(ret == -EOPNOTSUPP);" in vfs_copy_file_range, from
64bf5ff58dff ("vfs: no fallback for ->copy_file_range")

# cat /sys/class/net/can0/phys_switch_id

WARNING: CPU: 7 PID: 673 at fs/read_write.c:1516 vfs_copy_file_range+0x380/0x440
Modules linked in: llce_can llce_logger llce_mailbox llce_core sch_fq_codel
openvswitch nsh nf_conncount nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4
CPU: 7 PID: 673 Comm: cat Not tainted 5.15.38-yocto-standard #1
Hardware name: Freescale S32G399A (DT)
pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
pc : vfs_copy_file_range+0x380/0x440
lr : vfs_copy_file_range+0x16c/0x440
sp : ffffffc00e0f3ce0
x29: ffffffc00e0f3ce0 x28: ffffff88157b5a40 x27: 0000000000000000
x26: ffffff8816ac3230 x25: ffffff881c060008 x24: 0000000000001000
x23: 0000000000000000 x22: 0000000000000000 x21: ffffff881cc99540
x20: ffffff881cc9a340 x19: ffffffffffffffa1 x18: ffffffffffffffff
x17: 0000000000000001 x16: 0000adfbb5178cde x15: ffffffc08e0f3647
x14: 0000000000000000 x13: 34613178302f3061 x12: 3178302b636e7973
x11: 0000000000058395 x10: 00000000fd1c5755 x9 : ffffffc008361950
x8 : ffffffc00a7d4d58 x7 : 0000000000000000 x6 : 0000000000000001
x5 : ffffffc009e81000 x4 : ffffffc009e817f8 x3 : 0000000000000000
x2 : 0000000000000000 x1 : ffffff88157b5a40 x0 : ffffffffffffffa1
Call trace:
 vfs_copy_file_range+0x380/0x440
 __do_sys_copy_file_range+0x178/0x3a4
 __arm64_sys_copy_file_range+0x34/0x4c
 invoke_syscall+0x5c/0x130
 el0_svc_common.constprop.0+0x68/0x124
 do_el0_svc+0x50/0xbc
 el0_svc+0x54/0x130
 el0t_64_sync_handler+0xa4/0x130
 el0t_64_sync+0x1a0/0x1a4
cat: /sys/class/net/can0/phys_switch_id: Operation not supported

And we found this is triggered by the following stack. Specifically, all
netdev_ops in CAN drivers we can find now do not have ndo_get_port_parent_id and
ndo_get_devlink_port, which makes phys_switch_id_show return -EOPNOTSUPP all the
way back to vfs_copy_file_range.

phys_switch_id_show+0xf4/0x11c
dev_attr_show+0x2c/0x6c
sysfs_kf_seq_show+0xb8/0x150
kernfs_seq_show+0x38/0x44
seq_read_iter+0x1c4/0x4c0
kernfs_fop_read_iter+0x44/0x50
generic_file_splice_read+0xdc/0x190
do_splice_to+0xa0/0xfc
splice_direct_to_actor+0xc4/0x250
do_splice_direct+0x94/0xe0
vfs_copy_file_range+0x16c/0x440
__do_sys_copy_file_range+0x178/0x3a4
__arm64_sys_copy_file_range+0x34/0x4c
invoke_syscall+0x5c/0x130
el0_svc_common.constprop.0+0x68/0x124
do_el0_svc+0x50/0xbc
el0_svc+0x54/0x130
el0t_64_sync_handler+0xa4/0x130
el0t_64_sync+0x1a0/0x1a4

According to the original commit log, this warning is for operational validity
checks to generic_copy_file_range(). The reading will eventually return as
not supported as printed above. But is this warning still necessary? If so we
might want to remove it to have a cleaner dmesg.


Thanks,
Zhe


2022-05-20 09:00:00

by Amir Goldstein

[permalink] [raw]
Subject: Re: warning for EOPNOTSUPP vfs_copy_file_range

On Thu, May 19, 2022 at 11:22 AM He Zhe <[email protected]> wrote:
>
> Hi,
>
> We are experiencing the following warning from
> "WARN_ON_ONCE(ret == -EOPNOTSUPP);" in vfs_copy_file_range, from
> 64bf5ff58dff ("vfs: no fallback for ->copy_file_range")
>
> # cat /sys/class/net/can0/phys_switch_id
>
> WARNING: CPU: 7 PID: 673 at fs/read_write.c:1516 vfs_copy_file_range+0x380/0x440
> Modules linked in: llce_can llce_logger llce_mailbox llce_core sch_fq_codel
> openvswitch nsh nf_conncount nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4
> CPU: 7 PID: 673 Comm: cat Not tainted 5.15.38-yocto-standard #1
> Hardware name: Freescale S32G399A (DT)
> pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
> pc : vfs_copy_file_range+0x380/0x440
> lr : vfs_copy_file_range+0x16c/0x440
> sp : ffffffc00e0f3ce0
> x29: ffffffc00e0f3ce0 x28: ffffff88157b5a40 x27: 0000000000000000
> x26: ffffff8816ac3230 x25: ffffff881c060008 x24: 0000000000001000
> x23: 0000000000000000 x22: 0000000000000000 x21: ffffff881cc99540
> x20: ffffff881cc9a340 x19: ffffffffffffffa1 x18: ffffffffffffffff
> x17: 0000000000000001 x16: 0000adfbb5178cde x15: ffffffc08e0f3647
> x14: 0000000000000000 x13: 34613178302f3061 x12: 3178302b636e7973
> x11: 0000000000058395 x10: 00000000fd1c5755 x9 : ffffffc008361950
> x8 : ffffffc00a7d4d58 x7 : 0000000000000000 x6 : 0000000000000001
> x5 : ffffffc009e81000 x4 : ffffffc009e817f8 x3 : 0000000000000000
> x2 : 0000000000000000 x1 : ffffff88157b5a40 x0 : ffffffffffffffa1
> Call trace:
> vfs_copy_file_range+0x380/0x440
> __do_sys_copy_file_range+0x178/0x3a4
> __arm64_sys_copy_file_range+0x34/0x4c
> invoke_syscall+0x5c/0x130
> el0_svc_common.constprop.0+0x68/0x124
> do_el0_svc+0x50/0xbc
> el0_svc+0x54/0x130
> el0t_64_sync_handler+0xa4/0x130
> el0t_64_sync+0x1a0/0x1a4
> cat: /sys/class/net/can0/phys_switch_id: Operation not supported
>
> And we found this is triggered by the following stack. Specifically, all
> netdev_ops in CAN drivers we can find now do not have ndo_get_port_parent_id and
> ndo_get_devlink_port, which makes phys_switch_id_show return -EOPNOTSUPP all the
> way back to vfs_copy_file_range.
>
> phys_switch_id_show+0xf4/0x11c
> dev_attr_show+0x2c/0x6c
> sysfs_kf_seq_show+0xb8/0x150
> kernfs_seq_show+0x38/0x44
> seq_read_iter+0x1c4/0x4c0
> kernfs_fop_read_iter+0x44/0x50
> generic_file_splice_read+0xdc/0x190
> do_splice_to+0xa0/0xfc
> splice_direct_to_actor+0xc4/0x250
> do_splice_direct+0x94/0xe0
> vfs_copy_file_range+0x16c/0x440
> __do_sys_copy_file_range+0x178/0x3a4
> __arm64_sys_copy_file_range+0x34/0x4c
> invoke_syscall+0x5c/0x130
> el0_svc_common.constprop.0+0x68/0x124
> do_el0_svc+0x50/0xbc
> el0_svc+0x54/0x130
> el0t_64_sync_handler+0xa4/0x130
> el0t_64_sync+0x1a0/0x1a4
>
> According to the original commit log, this warning is for operational validity
> checks to generic_copy_file_range(). The reading will eventually return as
> not supported as printed above. But is this warning still necessary? If so we
> might want to remove it to have a cleaner dmesg.
>

Sigh! Those filesystems have no business doing copy_file_range()

Here is a patch that Luis has been trying to push last year
to fix a problem with copy_file_range() from tracefs:

https://lore.kernel.org/linux-fsdevel/[email protected]/

Luis gave up on it, because no maintainer stepped up to take
the patch, but I think that is the right way to go.

Maybe this bug report can raise awareness to that old patch.

Al, could you have a look?

Thanks,
Amir.

2022-05-21 11:14:58

by Amir Goldstein

[permalink] [raw]
Subject: Re: warning for EOPNOTSUPP vfs_copy_file_range

On Fri, May 20, 2022 at 6:03 AM He Zhe <[email protected]> wrote:
>
>
>
> On 5/19/22 22:31, Luís Henriques wrote:
> > Amir Goldstein <[email protected]> writes:
> >
> >> On Thu, May 19, 2022 at 11:22 AM He Zhe <[email protected]> wrote:
> >>> Hi,
> >>>
> >>> We are experiencing the following warning from
> >>> "WARN_ON_ONCE(ret == -EOPNOTSUPP);" in vfs_copy_file_range, from
> >>> 64bf5ff58dff ("vfs: no fallback for ->copy_file_range")
> >>>
> >>> # cat /sys/class/net/can0/phys_switch_id
> >>>
> >>> WARNING: CPU: 7 PID: 673 at fs/read_write.c:1516 vfs_copy_file_range+0x380/0x440
> >>> Modules linked in: llce_can llce_logger llce_mailbox llce_core sch_fq_codel
> >>> openvswitch nsh nf_conncount nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4
> >>> CPU: 7 PID: 673 Comm: cat Not tainted 5.15.38-yocto-standard #1
> >>> Hardware name: Freescale S32G399A (DT)
> >>> pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
> >>> pc : vfs_copy_file_range+0x380/0x440
> >>> lr : vfs_copy_file_range+0x16c/0x440
> >>> sp : ffffffc00e0f3ce0
> >>> x29: ffffffc00e0f3ce0 x28: ffffff88157b5a40 x27: 0000000000000000
> >>> x26: ffffff8816ac3230 x25: ffffff881c060008 x24: 0000000000001000
> >>> x23: 0000000000000000 x22: 0000000000000000 x21: ffffff881cc99540
> >>> x20: ffffff881cc9a340 x19: ffffffffffffffa1 x18: ffffffffffffffff
> >>> x17: 0000000000000001 x16: 0000adfbb5178cde x15: ffffffc08e0f3647
> >>> x14: 0000000000000000 x13: 34613178302f3061 x12: 3178302b636e7973
> >>> x11: 0000000000058395 x10: 00000000fd1c5755 x9 : ffffffc008361950
> >>> x8 : ffffffc00a7d4d58 x7 : 0000000000000000 x6 : 0000000000000001
> >>> x5 : ffffffc009e81000 x4 : ffffffc009e817f8 x3 : 0000000000000000
> >>> x2 : 0000000000000000 x1 : ffffff88157b5a40 x0 : ffffffffffffffa1
> >>> Call trace:
> >>> vfs_copy_file_range+0x380/0x440
> >>> __do_sys_copy_file_range+0x178/0x3a4
> >>> __arm64_sys_copy_file_range+0x34/0x4c
> >>> invoke_syscall+0x5c/0x130
> >>> el0_svc_common.constprop.0+0x68/0x124
> >>> do_el0_svc+0x50/0xbc
> >>> el0_svc+0x54/0x130
> >>> el0t_64_sync_handler+0xa4/0x130
> >>> el0t_64_sync+0x1a0/0x1a4
> >>> cat: /sys/class/net/can0/phys_switch_id: Operation not supported
> >>>
> >>> And we found this is triggered by the following stack. Specifically, all
> >>> netdev_ops in CAN drivers we can find now do not have ndo_get_port_parent_id and
> >>> ndo_get_devlink_port, which makes phys_switch_id_show return -EOPNOTSUPP all the
> >>> way back to vfs_copy_file_range.
> >>>
> >>> phys_switch_id_show+0xf4/0x11c
> >>> dev_attr_show+0x2c/0x6c
> >>> sysfs_kf_seq_show+0xb8/0x150
> >>> kernfs_seq_show+0x38/0x44
> >>> seq_read_iter+0x1c4/0x4c0
> >>> kernfs_fop_read_iter+0x44/0x50
> >>> generic_file_splice_read+0xdc/0x190
> >>> do_splice_to+0xa0/0xfc
> >>> splice_direct_to_actor+0xc4/0x250
> >>> do_splice_direct+0x94/0xe0
> >>> vfs_copy_file_range+0x16c/0x440
> >>> __do_sys_copy_file_range+0x178/0x3a4
> >>> __arm64_sys_copy_file_range+0x34/0x4c
> >>> invoke_syscall+0x5c/0x130
> >>> el0_svc_common.constprop.0+0x68/0x124
> >>> do_el0_svc+0x50/0xbc
> >>> el0_svc+0x54/0x130
> >>> el0t_64_sync_handler+0xa4/0x130
> >>> el0t_64_sync+0x1a0/0x1a4
> >>>
> >>> According to the original commit log, this warning is for operational validity
> >>> checks to generic_copy_file_range(). The reading will eventually return as
> >>> not supported as printed above. But is this warning still necessary? If so we
> >>> might want to remove it to have a cleaner dmesg.
> >>>
> >> Sigh! Those filesystems have no business doing copy_file_range()
> >>
> >> Here is a patch that Luis has been trying to push last year
> >> to fix a problem with copy_file_range() from tracefs:
> >>
> >> https://lore.kernel.org/linux-fsdevel/[email protected]/
> > Yikes! It's been a while and I completely forgot about it. I can
> > definitely try to respin this patch if someone's interested in picking
> > it. I'll have to go re-read everything again and see what's missing and
> > what has changed in between.
>
> Thank you both for quick replies.
>
> It would be good if this could be sorted out, as folks who are not familiar with
> it might be confused by the call trace. But if this is supposed to cost a long
> time, maybe we can first solve the false positive warning for the drivers in this
> case, as it seems the "operational validity checks" was not for these drivers.
>

Yes, technically, you are right.
Userspace should not be able to trigger a code validity assertion.
But the reason that assertion is there is to warn us developers
if we had overlooked a logic case and IMO we did.
The entire concept of calling ->copy_file_range() on random
filesystems has more than one problem and I would like for the kernel to
stop doing that.

Thanks,
Amir.

2022-05-22 00:32:58

by Al Viro

[permalink] [raw]
Subject: Re: warning for EOPNOTSUPP vfs_copy_file_range

On Thu, May 19, 2022 at 04:53:15PM +0300, Amir Goldstein wrote:

> Luis gave up on it, because no maintainer stepped up to take
> the patch, but I think that is the right way to go.
>
> Maybe this bug report can raise awareness to that old patch.
>
> Al, could you have a look?

IIRC, you had objections to that variant back then...