2022-05-19 16:10:24

by Luis Henriques

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

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.

Cheers,
--
Luís

> 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-20 08:30:19

by Paul Gortmaker

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

[Re: warning for EOPNOTSUPP vfs_copy_file_range] On 19/05/2022 (Thu 15: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

[...]

> > 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.

If it helps any, you don't need CAN bus or anything complicated. I was
able to reproduce it with the loopback device on linux-next of today
with a new userspace (from Yocto) that actively uses copy_file_range()

Note that a cp or redirect is needed to trigger the copy - with the
new userspace requiremet. Or write your own reproducer that goes at the
syscall directly on an old userspace (untested by me).

root@qemux86-64:/sys/class/net/lo# cat phys_switch_id
cat: phys_switch_id: Operation not supported
root@qemux86-64:/sys/class/net/lo# cat phys_switch_id > /tmp/foo
[ 87.527506] ------------[ cut here ]------------
[ 87.527675] WARNING: CPU: 2 PID: 238 at /home/paul/git/linux-head/fs/read_write.c:1511 vfs_copy_file_range+0x47c/0x4e0

Paul.
--

>
> Cheers,
> --
> Lu?s
>
> > 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 21:07:49

by He Zhe

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



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.

Regards,
Zhe

>
> Cheers,