Hi Krzysztof,
On Mon, Jan 9, 2023 at 3:46 AM Krzysztof Kozlowski
<[email protected]> wrote:
>
> On 09/01/2023 09:14, Krzysztof Kozlowski wrote:
> > On 08/01/2023 18:09, Trond Myklebust wrote:
> >> Hi Krzysztof,
> >>
> >>> On Jan 8, 2023, at 08:25, Krzysztof Kozlowski <[email protected]> wrote:
> >>>
> >>> [You don't often get email from [email protected]. Learn why this is important at https://aka.ms/LearnAboutSenderIdentification]
> >>>
> >>> On 07/01/2023 16:44, Krzysztof Kozlowski wrote:
> >>>> Hi,
> >>>>
> >>>> Bisect identified commit 7fd461c47c6c ("NFSv4.2: Change the default
> >>>> KConfig value for READ_PLUS") as one leading to NULL pointer exception
> >>>> when mounting NFS root on NFSv4 client:
> >>>>
> >>>> [ 25.739003] systemd[1]: Set hostname to <odroidhc1>.
> >>>> [ 25.771714] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid
> >>>> argument
> >>>> [ 26.199478] 8<--- cut here ---
> >>>> [ 26.201366] Unable to handle kernel NULL pointer dereference at
> >>>> virtual address 00000004
> >>>> ...
> >>>> [ 26.555522] mmiocpy from xdr_inline_decode+0xec/0x16c
> >>>> [ 26.560628] xdr_inline_decode from nfs4_xdr_dec_read_plus+0x178/0x358
> >>>> [ 26.567130] nfs4_xdr_dec_read_plus from call_decode+0x204/0x304
> >>>>
> >>>> Full OOPS attached. Full log available here:
> >>>> https://krzk.eu/#/builders/21/builds/3901/steps/15/logs/serial0
> >>>>
> >>>> Disabling NFS_V4_2_READ_PLUS fixes the issue, so obviously the commit is
> >>>> not the cause, but rather making it default caused the regression.
> >>>>
> >>>> I did not make the bisect yet which commit introduced it, if every
> >>>> config includes NFS_V4_2_READ_PLUS.
> >>>
> >>> When every kernel is built with NFS_V4_2_READ_PLUS, bisect pointed to:
> >>> d3b00a802c84 ("NFS: Replace the READ_PLUS decoding code")
> >>>
> >>> commit d3b00a802c845a6021148ce2e669b5a0b5729959
> >>> Author: Anna Schumaker <[email protected]>
> >>> Date: Thu Jul 21 14:21:34 2022 -0400
> >>>
> >>> NFS: Replace the READ_PLUS decoding code
> >>>
> >>> We now take a 2-step process that allows us to place data and hole
> >>> segments directly at their final position in the xdr_stream without
> >>> needing to do a bunch of redundant copies to expand holes. Due to the
> >>> variable lengths of each segment, the xdr metadata might cross page
> >>> boundaries which I account for by setting a small scratch buffer so
> >>> xdr_inline_decode() won't fail.
> >>>
> >>> Signed-off-by: Anna Schumaker <[email protected]>
> >>> Signed-off-by: Trond Myklebust <[email protected]>
> >>>
> >>> With a trace:
> >>> [ 25.898462] systemd[1]: Set hostname to <odroidhc1>.
> >>> [ 25.933746] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid
> >>> argument
> >>> [ 25.986237] random: crng init done
> >>> [ 26.264564] 8<--- cut here ---
> >>> [ 26.266823] Unable to handle kernel NULL pointer dereference at
> >>> virtual address 00000fe8
> >>> ...
> >>> [ 26.597263] nfs4_xdr_dec_read_plus from call_decode+0x204/0x304
> >>> [ 26.603222] call_decode from __rpc_execute+0xd0/0x890
> >>> [ 26.608328] __rpc_execute from rpc_async_schedule+0x1c/0x34
> >>> [ 26.613960] rpc_async_schedule from process_one_work+0x294/0x790
> >>> [ 26.620030] process_one_work from worker_thread+0x54/0x518
> >>> [ 26.625570] worker_thread from kthread+0xf4/0x128
> >>> [ 26.630336] kthread from ret_from_fork+0x14/0x2c
> >>>
> >>
> >> Is this test being run against a 6.2-rc2 server, or is it an older server platform? We know there were bugs in older server implementations, so the question is whether this might be a problem with handling a bad/corrupt RPC reply from the server, or whether it is happening against code that is supposed to have been fixed?
> >
> > I would say that buggy server should not cause NULL pointer dereferences
> > on the client. Otherwise this is a perfect recipe for a rogue server in
> > the network to start crashing clients and running exploits... Imagine a
> > compromised machine (through some other means) in a local company
> > network running now a server with NFS share "HR salary data" or "HR
> > planned layoffs", where unsuspected people in that network access it
> > leading to exploit of NFS code on their side...
> >
> > Server is Raspberry Pi 3 kernel: 5.10.92-2-rpi-legacy-ARCH
> >
> > Which points that it is not latest stable, so anyway I need to update.
>
> I updated the kernel to 5.15.84-3-rpi-ARCH which is pretty close to
> latest stable and I can reproduce the issue. Therefore:
> 1. It is visible on two stable (one new, one old) kernels on the server,
> 2. Buggy or rogue server should not cause NULL pointer on remote devices...
I'm still working on this issue, but I haven't been able to reproduce
it with my setup at all yet. I was hoping I could ask you a couple of
questions?
- Are both client and server run on a Raspberry Pi 3?
- Is there a specific workload that triggers the bug, or is it just
during boot when using nfsroot?
- Would it be possible to get a Wireshark network trace of the crash
(you'll have to run this on the server due to nfsroot).
- Can you share your export options from /etc/exports and the mount
options that the client uses?
Thanks,
Anna
>
> Best regards,
> Krzysztof
>
On 22/01/2023 23:25, Anna Schumaker wrote:
> Hi Krzysztof,
>
> On Mon, Jan 9, 2023 at 3:46 AM Krzysztof Kozlowski
> <[email protected]> wrote:
>>
>> On 09/01/2023 09:14, Krzysztof Kozlowski wrote:
>>> On 08/01/2023 18:09, Trond Myklebust wrote:
>>>> Hi Krzysztof,
>>>>
>>>>> On Jan 8, 2023, at 08:25, Krzysztof Kozlowski <[email protected]> wrote:
>>>>>
>>>>> [You don't often get email from [email protected]. Learn why this is important at https://aka.ms/LearnAboutSenderIdentification]
>>>>>
>>>>> On 07/01/2023 16:44, Krzysztof Kozlowski wrote:
>>>>>> Hi,
>>>>>>
>>>>>> Bisect identified commit 7fd461c47c6c ("NFSv4.2: Change the default
>>>>>> KConfig value for READ_PLUS") as one leading to NULL pointer exception
>>>>>> when mounting NFS root on NFSv4 client:
>>>>>>
>>>>>> [ 25.739003] systemd[1]: Set hostname to <odroidhc1>.
>>>>>> [ 25.771714] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid
>>>>>> argument
>>>>>> [ 26.199478] 8<--- cut here ---
>>>>>> [ 26.201366] Unable to handle kernel NULL pointer dereference at
>>>>>> virtual address 00000004
>>>>>> ...
>>>>>> [ 26.555522] mmiocpy from xdr_inline_decode+0xec/0x16c
>>>>>> [ 26.560628] xdr_inline_decode from nfs4_xdr_dec_read_plus+0x178/0x358
>>>>>> [ 26.567130] nfs4_xdr_dec_read_plus from call_decode+0x204/0x304
>>>>>>
>>>>>> Full OOPS attached. Full log available here:
>>>>>> https://krzk.eu/#/builders/21/builds/3901/steps/15/logs/serial0
>>>>>>
>>>>>> Disabling NFS_V4_2_READ_PLUS fixes the issue, so obviously the commit is
>>>>>> not the cause, but rather making it default caused the regression.
>>>>>>
>>>>>> I did not make the bisect yet which commit introduced it, if every
>>>>>> config includes NFS_V4_2_READ_PLUS.
>>>>>
>>>>> When every kernel is built with NFS_V4_2_READ_PLUS, bisect pointed to:
>>>>> d3b00a802c84 ("NFS: Replace the READ_PLUS decoding code")
>>>>>
>>>>> commit d3b00a802c845a6021148ce2e669b5a0b5729959
>>>>> Author: Anna Schumaker <[email protected]>
>>>>> Date: Thu Jul 21 14:21:34 2022 -0400
>>>>>
>>>>> NFS: Replace the READ_PLUS decoding code
>>>>>
>>>>> We now take a 2-step process that allows us to place data and hole
>>>>> segments directly at their final position in the xdr_stream without
>>>>> needing to do a bunch of redundant copies to expand holes. Due to the
>>>>> variable lengths of each segment, the xdr metadata might cross page
>>>>> boundaries which I account for by setting a small scratch buffer so
>>>>> xdr_inline_decode() won't fail.
>>>>>
>>>>> Signed-off-by: Anna Schumaker <[email protected]>
>>>>> Signed-off-by: Trond Myklebust <[email protected]>
>>>>>
>>>>> With a trace:
>>>>> [ 25.898462] systemd[1]: Set hostname to <odroidhc1>.
>>>>> [ 25.933746] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid
>>>>> argument
>>>>> [ 25.986237] random: crng init done
>>>>> [ 26.264564] 8<--- cut here ---
>>>>> [ 26.266823] Unable to handle kernel NULL pointer dereference at
>>>>> virtual address 00000fe8
>>>>> ...
>>>>> [ 26.597263] nfs4_xdr_dec_read_plus from call_decode+0x204/0x304
>>>>> [ 26.603222] call_decode from __rpc_execute+0xd0/0x890
>>>>> [ 26.608328] __rpc_execute from rpc_async_schedule+0x1c/0x34
>>>>> [ 26.613960] rpc_async_schedule from process_one_work+0x294/0x790
>>>>> [ 26.620030] process_one_work from worker_thread+0x54/0x518
>>>>> [ 26.625570] worker_thread from kthread+0xf4/0x128
>>>>> [ 26.630336] kthread from ret_from_fork+0x14/0x2c
>>>>>
>>>>
>>>> Is this test being run against a 6.2-rc2 server, or is it an older server platform? We know there were bugs in older server implementations, so the question is whether this might be a problem with handling a bad/corrupt RPC reply from the server, or whether it is happening against code that is supposed to have been fixed?
>>>
>>> I would say that buggy server should not cause NULL pointer dereferences
>>> on the client. Otherwise this is a perfect recipe for a rogue server in
>>> the network to start crashing clients and running exploits... Imagine a
>>> compromised machine (through some other means) in a local company
>>> network running now a server with NFS share "HR salary data" or "HR
>>> planned layoffs", where unsuspected people in that network access it
>>> leading to exploit of NFS code on their side...
>>>
>>> Server is Raspberry Pi 3 kernel: 5.10.92-2-rpi-legacy-ARCH
>>>
>>> Which points that it is not latest stable, so anyway I need to update.
>>
>> I updated the kernel to 5.15.84-3-rpi-ARCH which is pretty close to
>> latest stable and I can reproduce the issue. Therefore:
>> 1. It is visible on two stable (one new, one old) kernels on the server,
>> 2. Buggy or rogue server should not cause NULL pointer on remote devices...
>
> I'm still working on this issue, but I haven't been able to reproduce
> it with my setup at all yet. I was hoping I could ask you a couple of
> questions?
>
> - Are both client and server run on a Raspberry Pi 3?
No, server is Rpi3, client is Odroid HC1.
> - Is there a specific workload that triggers the bug, or is it just
> during boot when using nfsroot?
No specific workload - mounting system with nfsroot. You have there full
logs as it is reproducible every time.
> - Would it be possible to get a Wireshark network trace of the crash
> (you'll have to run this on the server due to nfsroot).
I'll check.
> - Can you share your export options from /etc/exports and the mount
> options that the client uses?
exports are the same since like 5 years or more:
/srv/nfs/odroidhc1 192.168.1.0/24(rw,async,no_root_squash,no_subtree_check)
/srv/nfs/odroidhc1-home
192.168.1.0/24(rw,async,no_root_squash,no_subtree_check)
>
> Thanks,
> Anna
>
>>
>> Best regards,
>> Krzysztof
>>
Best regards,
Krzysztof
Hi Krzysztof,
On Mon, Jan 23, 2023 at 2:58 AM Krzysztof Kozlowski
<[email protected]> wrote:
>
> On 22/01/2023 23:25, Anna Schumaker wrote:
> > Hi Krzysztof,
> >
> > On Mon, Jan 9, 2023 at 3:46 AM Krzysztof Kozlowski
> > <[email protected]> wrote:
> >>
> >> On 09/01/2023 09:14, Krzysztof Kozlowski wrote:
> >>> On 08/01/2023 18:09, Trond Myklebust wrote:
> >>>> Hi Krzysztof,
> >>>>
> >>>>> On Jan 8, 2023, at 08:25, Krzysztof Kozlowski <[email protected]> wrote:
> >>>>>
> >>>>> [You don't often get email from [email protected]. Learn why this is important at https://aka.ms/LearnAboutSenderIdentification]
> >>>>>
> >>>>> On 07/01/2023 16:44, Krzysztof Kozlowski wrote:
> >>>>>> Hi,
> >>>>>>
> >>>>>> Bisect identified commit 7fd461c47c6c ("NFSv4.2: Change the default
> >>>>>> KConfig value for READ_PLUS") as one leading to NULL pointer exception
> >>>>>> when mounting NFS root on NFSv4 client:
> >>>>>>
> >>>>>> [ 25.739003] systemd[1]: Set hostname to <odroidhc1>.
> >>>>>> [ 25.771714] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid
> >>>>>> argument
> >>>>>> [ 26.199478] 8<--- cut here ---
> >>>>>> [ 26.201366] Unable to handle kernel NULL pointer dereference at
> >>>>>> virtual address 00000004
> >>>>>> ...
> >>>>>> [ 26.555522] mmiocpy from xdr_inline_decode+0xec/0x16c
> >>>>>> [ 26.560628] xdr_inline_decode from nfs4_xdr_dec_read_plus+0x178/0x358
> >>>>>> [ 26.567130] nfs4_xdr_dec_read_plus from call_decode+0x204/0x304
> >>>>>>
> >>>>>> Full OOPS attached. Full log available here:
> >>>>>> https://krzk.eu/#/builders/21/builds/3901/steps/15/logs/serial0
> >>>>>>
> >>>>>> Disabling NFS_V4_2_READ_PLUS fixes the issue, so obviously the commit is
> >>>>>> not the cause, but rather making it default caused the regression.
> >>>>>>
> >>>>>> I did not make the bisect yet which commit introduced it, if every
> >>>>>> config includes NFS_V4_2_READ_PLUS.
> >>>>>
> >>>>> When every kernel is built with NFS_V4_2_READ_PLUS, bisect pointed to:
> >>>>> d3b00a802c84 ("NFS: Replace the READ_PLUS decoding code")
> >>>>>
> >>>>> commit d3b00a802c845a6021148ce2e669b5a0b5729959
> >>>>> Author: Anna Schumaker <[email protected]>
> >>>>> Date: Thu Jul 21 14:21:34 2022 -0400
> >>>>>
> >>>>> NFS: Replace the READ_PLUS decoding code
> >>>>>
> >>>>> We now take a 2-step process that allows us to place data and hole
> >>>>> segments directly at their final position in the xdr_stream without
> >>>>> needing to do a bunch of redundant copies to expand holes. Due to the
> >>>>> variable lengths of each segment, the xdr metadata might cross page
> >>>>> boundaries which I account for by setting a small scratch buffer so
> >>>>> xdr_inline_decode() won't fail.
> >>>>>
> >>>>> Signed-off-by: Anna Schumaker <[email protected]>
> >>>>> Signed-off-by: Trond Myklebust <[email protected]>
> >>>>>
> >>>>> With a trace:
> >>>>> [ 25.898462] systemd[1]: Set hostname to <odroidhc1>.
> >>>>> [ 25.933746] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid
> >>>>> argument
> >>>>> [ 25.986237] random: crng init done
> >>>>> [ 26.264564] 8<--- cut here ---
> >>>>> [ 26.266823] Unable to handle kernel NULL pointer dereference at
> >>>>> virtual address 00000fe8
> >>>>> ...
> >>>>> [ 26.597263] nfs4_xdr_dec_read_plus from call_decode+0x204/0x304
> >>>>> [ 26.603222] call_decode from __rpc_execute+0xd0/0x890
> >>>>> [ 26.608328] __rpc_execute from rpc_async_schedule+0x1c/0x34
> >>>>> [ 26.613960] rpc_async_schedule from process_one_work+0x294/0x790
> >>>>> [ 26.620030] process_one_work from worker_thread+0x54/0x518
> >>>>> [ 26.625570] worker_thread from kthread+0xf4/0x128
> >>>>> [ 26.630336] kthread from ret_from_fork+0x14/0x2c
> >>>>>
> >>>>
> >>>> Is this test being run against a 6.2-rc2 server, or is it an older server platform? We know there were bugs in older server implementations, so the question is whether this might be a problem with handling a bad/corrupt RPC reply from the server, or whether it is happening against code that is supposed to have been fixed?
> >>>
> >>> I would say that buggy server should not cause NULL pointer dereferences
> >>> on the client. Otherwise this is a perfect recipe for a rogue server in
> >>> the network to start crashing clients and running exploits... Imagine a
> >>> compromised machine (through some other means) in a local company
> >>> network running now a server with NFS share "HR salary data" or "HR
> >>> planned layoffs", where unsuspected people in that network access it
> >>> leading to exploit of NFS code on their side...
> >>>
> >>> Server is Raspberry Pi 3 kernel: 5.10.92-2-rpi-legacy-ARCH
> >>>
> >>> Which points that it is not latest stable, so anyway I need to update.
> >>
> >> I updated the kernel to 5.15.84-3-rpi-ARCH which is pretty close to
> >> latest stable and I can reproduce the issue. Therefore:
> >> 1. It is visible on two stable (one new, one old) kernels on the server,
> >> 2. Buggy or rogue server should not cause NULL pointer on remote devices...
> >
> > I'm still working on this issue, but I haven't been able to reproduce
> > it with my setup at all yet. I was hoping I could ask you a couple of
> > questions?
> >
> > - Are both client and server run on a Raspberry Pi 3?
>
> No, server is Rpi3, client is Odroid HC1.
>
> > - Is there a specific workload that triggers the bug, or is it just
> > during boot when using nfsroot?
>
> No specific workload - mounting system with nfsroot. You have there full
> logs as it is reproducible every time.
>
> > - Would it be possible to get a Wireshark network trace of the crash
> > (you'll have to run this on the server due to nfsroot).
>
> I'll check.
Any luck getting the wireshark trace? I don't have access to the
Odroid HC1 board, so all my attempts at reproducing the problem have
been with qemu & libvirt, which doesn't seem to be hitting this issue.
I was also wondering if it would be possible to turn on KASAN in your
kernel, which should give us a little more info?
Thanks,
Anna
>
> > - Can you share your export options from /etc/exports and the mount
> > options that the client uses?
>
> exports are the same since like 5 years or more:
>
> /srv/nfs/odroidhc1 192.168.1.0/24(rw,async,no_root_squash,no_subtree_check)
> /srv/nfs/odroidhc1-home
> 192.168.1.0/24(rw,async,no_root_squash,no_subtree_check)
>
>
> >
> > Thanks,
> > Anna
> >
> >>
> >> Best regards,
> >> Krzysztof
> >>
>
> Best regards,
> Krzysztof
>
On 09/02/2023 19:22, Anna Schumaker wrote:
> Hi Krzysztof,
>
> On Mon, Jan 23, 2023 at 2:58 AM Krzysztof Kozlowski
> <[email protected]> wrote:
>>
>> On 22/01/2023 23:25, Anna Schumaker wrote:
>>> Hi Krzysztof,
>>>
>>> On Mon, Jan 9, 2023 at 3:46 AM Krzysztof Kozlowski
>>> <[email protected]> wrote:
>>>>
>>>> On 09/01/2023 09:14, Krzysztof Kozlowski wrote:
>>>>> On 08/01/2023 18:09, Trond Myklebust wrote:
>>>>>> Hi Krzysztof,
>>>>>>
>>>>>>> On Jan 8, 2023, at 08:25, Krzysztof Kozlowski <[email protected]> wrote:
>>>>>>>
>>>>>>> [You don't often get email from [email protected]. Learn why this is important at https://aka.ms/LearnAboutSenderIdentification]
>>>>>>>
>>>>>>> On 07/01/2023 16:44, Krzysztof Kozlowski wrote:
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> Bisect identified commit 7fd461c47c6c ("NFSv4.2: Change the default
>>>>>>>> KConfig value for READ_PLUS") as one leading to NULL pointer exception
>>>>>>>> when mounting NFS root on NFSv4 client:
>>>>>>>>
>>>>>>>> [ 25.739003] systemd[1]: Set hostname to <odroidhc1>.
>>>>>>>> [ 25.771714] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid
>>>>>>>> argument
>>>>>>>> [ 26.199478] 8<--- cut here ---
>>>>>>>> [ 26.201366] Unable to handle kernel NULL pointer dereference at
>>>>>>>> virtual address 00000004
>>>>>>>> ...
>>>>>>>> [ 26.555522] mmiocpy from xdr_inline_decode+0xec/0x16c
>>>>>>>> [ 26.560628] xdr_inline_decode from nfs4_xdr_dec_read_plus+0x178/0x358
>>>>>>>> [ 26.567130] nfs4_xdr_dec_read_plus from call_decode+0x204/0x304
>>>>>>>>
>>>>>>>> Full OOPS attached. Full log available here:
>>>>>>>> https://krzk.eu/#/builders/21/builds/3901/steps/15/logs/serial0
>>>>>>>>
>>>>>>>> Disabling NFS_V4_2_READ_PLUS fixes the issue, so obviously the commit is
>>>>>>>> not the cause, but rather making it default caused the regression.
>>>>>>>>
>>>>>>>> I did not make the bisect yet which commit introduced it, if every
>>>>>>>> config includes NFS_V4_2_READ_PLUS.
>>>>>>>
>>>>>>> When every kernel is built with NFS_V4_2_READ_PLUS, bisect pointed to:
>>>>>>> d3b00a802c84 ("NFS: Replace the READ_PLUS decoding code")
>>>>>>>
>>>>>>> commit d3b00a802c845a6021148ce2e669b5a0b5729959
>>>>>>> Author: Anna Schumaker <[email protected]>
>>>>>>> Date: Thu Jul 21 14:21:34 2022 -0400
>>>>>>>
>>>>>>> NFS: Replace the READ_PLUS decoding code
>>>>>>>
>>>>>>> We now take a 2-step process that allows us to place data and hole
>>>>>>> segments directly at their final position in the xdr_stream without
>>>>>>> needing to do a bunch of redundant copies to expand holes. Due to the
>>>>>>> variable lengths of each segment, the xdr metadata might cross page
>>>>>>> boundaries which I account for by setting a small scratch buffer so
>>>>>>> xdr_inline_decode() won't fail.
>>>>>>>
>>>>>>> Signed-off-by: Anna Schumaker <[email protected]>
>>>>>>> Signed-off-by: Trond Myklebust <[email protected]>
>>>>>>>
>>>>>>> With a trace:
>>>>>>> [ 25.898462] systemd[1]: Set hostname to <odroidhc1>.
>>>>>>> [ 25.933746] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid
>>>>>>> argument
>>>>>>> [ 25.986237] random: crng init done
>>>>>>> [ 26.264564] 8<--- cut here ---
>>>>>>> [ 26.266823] Unable to handle kernel NULL pointer dereference at
>>>>>>> virtual address 00000fe8
>>>>>>> ...
>>>>>>> [ 26.597263] nfs4_xdr_dec_read_plus from call_decode+0x204/0x304
>>>>>>> [ 26.603222] call_decode from __rpc_execute+0xd0/0x890
>>>>>>> [ 26.608328] __rpc_execute from rpc_async_schedule+0x1c/0x34
>>>>>>> [ 26.613960] rpc_async_schedule from process_one_work+0x294/0x790
>>>>>>> [ 26.620030] process_one_work from worker_thread+0x54/0x518
>>>>>>> [ 26.625570] worker_thread from kthread+0xf4/0x128
>>>>>>> [ 26.630336] kthread from ret_from_fork+0x14/0x2c
>>>>>>>
>>>>>>
>>>>>> Is this test being run against a 6.2-rc2 server, or is it an older server platform? We know there were bugs in older server implementations, so the question is whether this might be a problem with handling a bad/corrupt RPC reply from the server, or whether it is happening against code that is supposed to have been fixed?
>>>>>
>>>>> I would say that buggy server should not cause NULL pointer dereferences
>>>>> on the client. Otherwise this is a perfect recipe for a rogue server in
>>>>> the network to start crashing clients and running exploits... Imagine a
>>>>> compromised machine (through some other means) in a local company
>>>>> network running now a server with NFS share "HR salary data" or "HR
>>>>> planned layoffs", where unsuspected people in that network access it
>>>>> leading to exploit of NFS code on their side...
>>>>>
>>>>> Server is Raspberry Pi 3 kernel: 5.10.92-2-rpi-legacy-ARCH
>>>>>
>>>>> Which points that it is not latest stable, so anyway I need to update.
>>>>
>>>> I updated the kernel to 5.15.84-3-rpi-ARCH which is pretty close to
>>>> latest stable and I can reproduce the issue. Therefore:
>>>> 1. It is visible on two stable (one new, one old) kernels on the server,
>>>> 2. Buggy or rogue server should not cause NULL pointer on remote devices...
>>>
>>> I'm still working on this issue, but I haven't been able to reproduce
>>> it with my setup at all yet. I was hoping I could ask you a couple of
>>> questions?
>>>
>>> - Are both client and server run on a Raspberry Pi 3?
>>
>> No, server is Rpi3, client is Odroid HC1.
>>
>>> - Is there a specific workload that triggers the bug, or is it just
>>> during boot when using nfsroot?
>>
>> No specific workload - mounting system with nfsroot. You have there full
>> logs as it is reproducible every time.
>>
>>> - Would it be possible to get a Wireshark network trace of the crash
>>> (you'll have to run this on the server due to nfsroot).
>>
>> I'll check.
>
> Any luck getting the wireshark trace? I don't have access to the
> Odroid HC1 board, so all my attempts at reproducing the problem have
> been with qemu & libvirt, which doesn't seem to be hitting this issue.
I'll send pcap dump off list. Failure is in similar place:
[ 23.876714] systemd[1]: Hostname set to <odroidhc1>.
[ 24.061568] systemd[1]: bpf-lsm: BPF LSM hook not enabled in the
kernel, BPF LSM not supported
[ 24.078774] memfd_create() without MFD_EXEC nor MFD_NOEXEC_SEAL,
pid=1 'systemd'
[ 24.220531] 8<--- cut here ---
[ 24.222333] Unable to handle kernel NULL pointer dereference at
virtual address 00000004 when read
>
> I was also wondering if it would be possible to turn on KASAN in your
> kernel, which should give us a little more info?
I'll try with KASAN.
Best regards,
Krzysztof
On 10/02/2023 09:41, Krzysztof Kozlowski wrote:
>
>
>>
>> I was also wondering if it would be possible to turn on KASAN in your
>> kernel, which should give us a little more info?
>
> I'll try with KASAN.
Not much from the KASAN, except that kernel
continues to boot and runs:
[ 44.722846] vdd_vmem: disabling
[ 44.793465] systemd[1]: Hostname set to <odroidhc1>.
[ 45.357929] systemd[1]: bpf-lsm: BPF LSM hook not enabled in the kernel, BPF LSM not supported
[ 45.980476] ==================================================================
[ 45.986372] BUG: KASAN: null-ptr-deref in xdr_inline_decode+0x140/0x200
[ 45.992929] Read of size 4092 at addr 00000004 by task kworker/u16:3/71
[ 45.999513]
[ 46.000940] CPU: 6 PID: 71 Comm: kworker/u16:3 Not tainted 6.2.0-rc7-00018-g0983f6bf2bfc #222
[ 46.009504] Hardware name: Samsung Exynos (Flattened Device Tree)
[ 46.015542] Workqueue: rpciod rpc_async_schedule
[ 46.020123] unwind_backtrace from show_stack+0x10/0x14
[ 46.025323] show_stack from dump_stack_lvl+0x58/0x70
[ 46.030301] dump_stack_lvl from kasan_report+0xa8/0xe0
[ 46.035501] kasan_report from kasan_check_range+0x94/0x1a0
[ 46.041048] kasan_check_range from memcpy+0x28/0x68
[ 46.045985] memcpy from xdr_inline_decode+0x140/0x200
[ 46.051098] xdr_inline_decode from nfs4_xdr_dec_read_plus+0x298/0x5b8
[ 46.057602] nfs4_xdr_dec_read_plus from call_decode+0x39c/0x530
[ 46.063581] call_decode from __rpc_execute+0x1f4/0xc5c
[ 46.068776] __rpc_execute from rpc_async_schedule+0x2c/0x4c
[ 46.074411] rpc_async_schedule from process_one_work+0x51c/0xc44
[ 46.080478] process_one_work from worker_thread+0x9c/0x7c0
[ 46.086022] worker_thread from kthread+0x16c/0x1b8
[ 46.090872] kthread from ret_from_fork+0x14/0x2c
[ 46.095550] Exception stack(0xf0ba3fb0 to 0xf0ba3ff8)
[ 46.100580] 3fa0: 00000000 00000000 00000000 00000000
[ 46.108740] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 46.116885] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[ 46.123461] ==================================================================
[ 46.130774] Disabling lock debugging due to kernel taint
[ 50.848579] systemd[1]: Queued start job for default target Graphical Interface.
[ 50.877068] systemd[1]: Created slice Slice /system/getty.
Decoded stacktrace is (this is master branch):
[ 46.020123] unwind_backtrace from show_stack (arch/arm/kernel/traps.c:258)
[ 46.025323] show_stack from dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4))
[ 46.030301] dump_stack_lvl from kasan_report (mm/kasan/report.c:184 mm/kasan/report.c:519)
[ 46.035501] kasan_report from kasan_check_range (mm/kasan/generic.c:173 mm/kasan/generic.c:189)
[ 46.041048] kasan_check_range from memcpy (mm/kasan/shadow.c:65)
[ 46.045985] memcpy from xdr_inline_decode (net/sunrpc/xdr.c:1419 net/sunrpc/xdr.c:1454)
[ 46.051098] xdr_inline_decode from nfs4_xdr_dec_read_plus (fs/nfs/nfs42xdr.c:1063 fs/nfs/nfs42xdr.c:1149 fs/nfs/nfs42xdr.c:1360 fs/nfs/nfs42xdr.c:1343)
[ 46.057602] nfs4_xdr_dec_read_plus from call_decode (net/sunrpc/clnt.c:2595)
[ 46.063581] call_decode from __rpc_execute (include/asm-generic/bitops/generic-non-atomic.h:128 net/sunrpc/sched.c:954)
[ 46.068776] __rpc_execute from rpc_async_schedule (include/linux/sched/mm.h:336 net/sunrpc/sched.c:1035)
[ 46.074411] rpc_async_schedule from process_one_work (kernel/workqueue.c:2294)
[ 46.080478] process_one_work from worker_thread (include/linux/list.h:292 kernel/workqueue.c:2437)
[ 46.086022] worker_thread from kthread (kernel/kthread.c:376)
[ 46.090872] kthread from ret_from_fork (arch/arm/kernel/entry-common.S:149)
Best regards,
Krzysztof
Hi Krzysztof,
On Fri, Feb 10, 2023 at 3:53 AM Krzysztof Kozlowski
<[email protected]> wrote:
>
> On 10/02/2023 09:41, Krzysztof Kozlowski wrote:
> >
> >
> >>
> >> I was also wondering if it would be possible to turn on KASAN in your
> >> kernel, which should give us a little more info?
> >
> > I'll try with KASAN.
>
> Not much from the KASAN, except that kernel
> continues to boot and runs:
>
> [ 44.722846] vdd_vmem: disabling
> [ 44.793465] systemd[1]: Hostname set to <odroidhc1>.
> [ 45.357929] systemd[1]: bpf-lsm: BPF LSM hook not enabled in the kernel, BPF LSM not supported
> [ 45.980476] ==================================================================
> [ 45.986372] BUG: KASAN: null-ptr-deref in xdr_inline_decode+0x140/0x200
> [ 45.992929] Read of size 4092 at addr 00000004 by task kworker/u16:3/71
> [ 45.999513]
> [ 46.000940] CPU: 6 PID: 71 Comm: kworker/u16:3 Not tainted 6.2.0-rc7-00018-g0983f6bf2bfc #222
> [ 46.009504] Hardware name: Samsung Exynos (Flattened Device Tree)
> [ 46.015542] Workqueue: rpciod rpc_async_schedule
> [ 46.020123] unwind_backtrace from show_stack+0x10/0x14
> [ 46.025323] show_stack from dump_stack_lvl+0x58/0x70
> [ 46.030301] dump_stack_lvl from kasan_report+0xa8/0xe0
> [ 46.035501] kasan_report from kasan_check_range+0x94/0x1a0
> [ 46.041048] kasan_check_range from memcpy+0x28/0x68
> [ 46.045985] memcpy from xdr_inline_decode+0x140/0x200
> [ 46.051098] xdr_inline_decode from nfs4_xdr_dec_read_plus+0x298/0x5b8
> [ 46.057602] nfs4_xdr_dec_read_plus from call_decode+0x39c/0x530
> [ 46.063581] call_decode from __rpc_execute+0x1f4/0xc5c
> [ 46.068776] __rpc_execute from rpc_async_schedule+0x2c/0x4c
> [ 46.074411] rpc_async_schedule from process_one_work+0x51c/0xc44
> [ 46.080478] process_one_work from worker_thread+0x9c/0x7c0
> [ 46.086022] worker_thread from kthread+0x16c/0x1b8
> [ 46.090872] kthread from ret_from_fork+0x14/0x2c
> [ 46.095550] Exception stack(0xf0ba3fb0 to 0xf0ba3ff8)
> [ 46.100580] 3fa0: 00000000 00000000 00000000 00000000
> [ 46.108740] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> [ 46.116885] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
> [ 46.123461] ==================================================================
> [ 46.130774] Disabling lock debugging due to kernel taint
> [ 50.848579] systemd[1]: Queued start job for default target Graphical Interface.
> [ 50.877068] systemd[1]: Created slice Slice /system/getty.
>
>
> Decoded stacktrace is (this is master branch):
>
> [ 46.020123] unwind_backtrace from show_stack (arch/arm/kernel/traps.c:258)
> [ 46.025323] show_stack from dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4))
> [ 46.030301] dump_stack_lvl from kasan_report (mm/kasan/report.c:184 mm/kasan/report.c:519)
> [ 46.035501] kasan_report from kasan_check_range (mm/kasan/generic.c:173 mm/kasan/generic.c:189)
> [ 46.041048] kasan_check_range from memcpy (mm/kasan/shadow.c:65)
> [ 46.045985] memcpy from xdr_inline_decode (net/sunrpc/xdr.c:1419 net/sunrpc/xdr.c:1454)
Actually, this part is really useful. net/sunrpc/xdr.c:1419 points to
the memcpy in xdr_copy_to_scratch(), which has me wondering if I'm
incorrectly setting up the xdr scratch buffer that READ_PLUS uses for
decoding. Can you try this patch and let me know if it helps?
From ac2d6c501dbcdb306480edaee625b5496f1fb4f5 Mon Sep 17 00:00:00 2001
From: Anna Schumaker <[email protected]>
Date: Fri, 10 Feb 2023 15:50:22 -0500
Subject: [PATCH] NFSv4.2: Rework scratch handling for READ_PLUS
Instead of using a tiny scratch buffer, we should use a full scratch
page to match how other NFSv4 operations handle scratch data.
Signed-off-by: Anna Schumaker <[email protected]>
---
fs/nfs/nfs42xdr.c | 4 ++--
fs/nfs/nfs4proc.c | 14 ++++++++++----
include/linux/nfs_xdr.h | 1 +
3 files changed, 13 insertions(+), 6 deletions(-)
diff --git a/fs/nfs/nfs42xdr.c b/fs/nfs/nfs42xdr.c
index d80ee88ca996..702567d5b1db 100644
--- a/fs/nfs/nfs42xdr.c
+++ b/fs/nfs/nfs42xdr.c
@@ -1122,7 +1122,6 @@ static int decode_read_plus(struct xdr_stream
*xdr, struct nfs_pgio_res *res)
uint32_t segments;
struct read_plus_segment *segs;
int status, i;
- char scratch_buf[16];
__be32 *p;
status = decode_op_hdr(xdr, OP_READ_PLUS);
@@ -1143,7 +1142,6 @@ static int decode_read_plus(struct xdr_stream
*xdr, struct nfs_pgio_res *res)
if (!segs)
return -ENOMEM;
- xdr_set_scratch_buffer(xdr, &scratch_buf, sizeof(scratch_buf));
status = -EIO;
for (i = 0; i < segments; i++) {
status = decode_read_plus_segment(xdr, &segs[i]);
@@ -1348,6 +1346,8 @@ static int nfs4_xdr_dec_read_plus(struct rpc_rqst *rqstp,
struct compound_hdr hdr;
int status;
+ xdr_set_scratch_page(xdr, res->scratch);
+
status = decode_compound_hdr(xdr, &hdr);
if (status)
goto out;
diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c
index 40d749f29ed3..5c589d0bd9e9 100644
--- a/fs/nfs/nfs4proc.c
+++ b/fs/nfs/nfs4proc.c
@@ -5440,6 +5440,8 @@ static bool nfs4_read_plus_not_supported(struct
rpc_task *task,
static int nfs4_read_done(struct rpc_task *task, struct nfs_pgio_header *hdr)
{
+ if (hdr->res.scratch)
+ __free_page(hdr->res.scratch);
if (!nfs4_sequence_done(task, &hdr->res.seq_res))
return -EAGAIN;
if (nfs4_read_stateid_changed(task, &hdr->args))
@@ -5453,12 +5455,16 @@ static int nfs4_read_done(struct rpc_task
*task, struct nfs_pgio_header *hdr)
}
#if defined CONFIG_NFS_V4_2 && defined CONFIG_NFS_V4_2_READ_PLUS
-static void nfs42_read_plus_support(struct nfs_pgio_header *hdr,
+static bool nfs42_read_plus_support(struct nfs_pgio_header *hdr,
struct rpc_message *msg)
{
/* Note: We don't use READ_PLUS with pNFS yet */
- if (nfs_server_capable(hdr->inode, NFS_CAP_READ_PLUS) && !hdr->ds_clp)
+ if (nfs_server_capable(hdr->inode, NFS_CAP_READ_PLUS) && !hdr->ds_clp) {
msg->rpc_proc = &nfs4_procedures[NFSPROC4_CLNT_READ_PLUS];
+ hdr->res.scratch = alloc_page(GFP_KERNEL);
+ return hdr->res.scratch != NULL;
+ }
+ return false;
}
#else
static void nfs42_read_plus_support(struct nfs_pgio_header *hdr,
@@ -5473,8 +5479,8 @@ static void nfs4_proc_read_setup(struct
nfs_pgio_header *hdr,
hdr->timestamp = jiffies;
if (!hdr->pgio_done_cb)
hdr->pgio_done_cb = nfs4_read_done_cb;
- msg->rpc_proc = &nfs4_procedures[NFSPROC4_CLNT_READ];
- nfs42_read_plus_support(hdr, msg);
+ if (!nfs42_read_plus_support(hdr, msg))
+ msg->rpc_proc = &nfs4_procedures[NFSPROC4_CLNT_READ];
nfs4_init_sequence(&hdr->args.seq_args, &hdr->res.seq_res, 0, 0);
}
diff --git a/include/linux/nfs_xdr.h b/include/linux/nfs_xdr.h
index e86cf6642d21..6d821aaf0b1a 100644
--- a/include/linux/nfs_xdr.h
+++ b/include/linux/nfs_xdr.h
@@ -670,6 +670,7 @@ struct nfs_pgio_res {
struct {
unsigned int replen; /* used by read */
int eof; /* used by read */
+ struct page *scratch; /* used by read */
};
struct {
struct nfs_writeverf * verf; /* used by write */
--
2.39.1
Thanks,
Anna
> [ 46.051098] xdr_inline_decode from nfs4_xdr_dec_read_plus (fs/nfs/nfs42xdr.c:1063 fs/nfs/nfs42xdr.c:1149 fs/nfs/nfs42xdr.c:1360 fs/nfs/nfs42xdr.c:1343)
> [ 46.057602] nfs4_xdr_dec_read_plus from call_decode (net/sunrpc/clnt.c:2595)
> [ 46.063581] call_decode from __rpc_execute (include/asm-generic/bitops/generic-non-atomic.h:128 net/sunrpc/sched.c:954)
> [ 46.068776] __rpc_execute from rpc_async_schedule (include/linux/sched/mm.h:336 net/sunrpc/sched.c:1035)
> [ 46.074411] rpc_async_schedule from process_one_work (kernel/workqueue.c:2294)
> [ 46.080478] process_one_work from worker_thread (include/linux/list.h:292 kernel/workqueue.c:2437)
> [ 46.086022] worker_thread from kthread (kernel/kthread.c:376)
> [ 46.090872] kthread from ret_from_fork (arch/arm/kernel/entry-common.S:149)
>
>
> Best regards,
> Krzysztof
>
On 10/02/2023 21:55, Anna Schumaker wrote:
> Hi Krzysztof,
>
> On Fri, Feb 10, 2023 at 3:53 AM Krzysztof Kozlowski
> <[email protected]> wrote:
>>
>> On 10/02/2023 09:41, Krzysztof Kozlowski wrote:
>>>
>>>
>>>>
>>>> I was also wondering if it would be possible to turn on KASAN in your
>>>> kernel, which should give us a little more info?
>>>
>>> I'll try with KASAN.
>>
>> Not much from the KASAN, except that kernel
>> continues to boot and runs:
>>
>> [ 44.722846] vdd_vmem: disabling
>> [ 44.793465] systemd[1]: Hostname set to <odroidhc1>.
>> [ 45.357929] systemd[1]: bpf-lsm: BPF LSM hook not enabled in the kernel, BPF LSM not supported
>> [ 45.980476] ==================================================================
>> [ 45.986372] BUG: KASAN: null-ptr-deref in xdr_inline_decode+0x140/0x200
>> [ 45.992929] Read of size 4092 at addr 00000004 by task kworker/u16:3/71
>> [ 45.999513]
>> [ 46.000940] CPU: 6 PID: 71 Comm: kworker/u16:3 Not tainted 6.2.0-rc7-00018-g0983f6bf2bfc #222
>> [ 46.009504] Hardware name: Samsung Exynos (Flattened Device Tree)
>> [ 46.015542] Workqueue: rpciod rpc_async_schedule
>> [ 46.020123] unwind_backtrace from show_stack+0x10/0x14
>> [ 46.025323] show_stack from dump_stack_lvl+0x58/0x70
>> [ 46.030301] dump_stack_lvl from kasan_report+0xa8/0xe0
>> [ 46.035501] kasan_report from kasan_check_range+0x94/0x1a0
>> [ 46.041048] kasan_check_range from memcpy+0x28/0x68
>> [ 46.045985] memcpy from xdr_inline_decode+0x140/0x200
>> [ 46.051098] xdr_inline_decode from nfs4_xdr_dec_read_plus+0x298/0x5b8
>> [ 46.057602] nfs4_xdr_dec_read_plus from call_decode+0x39c/0x530
>> [ 46.063581] call_decode from __rpc_execute+0x1f4/0xc5c
>> [ 46.068776] __rpc_execute from rpc_async_schedule+0x2c/0x4c
>> [ 46.074411] rpc_async_schedule from process_one_work+0x51c/0xc44
>> [ 46.080478] process_one_work from worker_thread+0x9c/0x7c0
>> [ 46.086022] worker_thread from kthread+0x16c/0x1b8
>> [ 46.090872] kthread from ret_from_fork+0x14/0x2c
>> [ 46.095550] Exception stack(0xf0ba3fb0 to 0xf0ba3ff8)
>> [ 46.100580] 3fa0: 00000000 00000000 00000000 00000000
>> [ 46.108740] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
>> [ 46.116885] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
>> [ 46.123461] ==================================================================
>> [ 46.130774] Disabling lock debugging due to kernel taint
>> [ 50.848579] systemd[1]: Queued start job for default target Graphical Interface.
>> [ 50.877068] systemd[1]: Created slice Slice /system/getty.
>>
>>
>> Decoded stacktrace is (this is master branch):
>>
>> [ 46.020123] unwind_backtrace from show_stack (arch/arm/kernel/traps.c:258)
>> [ 46.025323] show_stack from dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4))
>> [ 46.030301] dump_stack_lvl from kasan_report (mm/kasan/report.c:184 mm/kasan/report.c:519)
>> [ 46.035501] kasan_report from kasan_check_range (mm/kasan/generic.c:173 mm/kasan/generic.c:189)
>> [ 46.041048] kasan_check_range from memcpy (mm/kasan/shadow.c:65)
>> [ 46.045985] memcpy from xdr_inline_decode (net/sunrpc/xdr.c:1419 net/sunrpc/xdr.c:1454)
>
> Actually, this part is really useful. net/sunrpc/xdr.c:1419 points to
> the memcpy in xdr_copy_to_scratch(), which has me wondering if I'm
> incorrectly setting up the xdr scratch buffer that READ_PLUS uses for
> decoding. Can you try this patch and let me know if it helps?
>
> From ac2d6c501dbcdb306480edaee625b5496f1fb4f5 Mon Sep 17 00:00:00 2001
> From: Anna Schumaker <[email protected]>
> Date: Fri, 10 Feb 2023 15:50:22 -0500
> Subject: [PATCH] NFSv4.2: Rework scratch handling for READ_PLUS
>
Patch is corrupted - maybe mail program reformatted it when sending:
Applying: NFSv4.2: Rework scratch handling for READ_PLUS
error: corrupt patch at line 12
Patch failed at 0001 NFSv4.2: Rework scratch handling for READ_PLUS
Best regards,
Krzysztof
On Sat, Feb 11, 2023 at 6:23 AM Krzysztof Kozlowski
<[email protected]> wrote:
>
> On 10/02/2023 21:55, Anna Schumaker wrote:
> > Hi Krzysztof,
> >
> > On Fri, Feb 10, 2023 at 3:53 AM Krzysztof Kozlowski
> > <[email protected]> wrote:
> >>
> >> On 10/02/2023 09:41, Krzysztof Kozlowski wrote:
> >>>
> >>>
> >>>>
> >>>> I was also wondering if it would be possible to turn on KASAN in your
> >>>> kernel, which should give us a little more info?
> >>>
> >>> I'll try with KASAN.
> >>
> >> Not much from the KASAN, except that kernel
> >> continues to boot and runs:
> >>
> >> [ 44.722846] vdd_vmem: disabling
> >> [ 44.793465] systemd[1]: Hostname set to <odroidhc1>.
> >> [ 45.357929] systemd[1]: bpf-lsm: BPF LSM hook not enabled in the kernel, BPF LSM not supported
> >> [ 45.980476] ==================================================================
> >> [ 45.986372] BUG: KASAN: null-ptr-deref in xdr_inline_decode+0x140/0x200
> >> [ 45.992929] Read of size 4092 at addr 00000004 by task kworker/u16:3/71
> >> [ 45.999513]
> >> [ 46.000940] CPU: 6 PID: 71 Comm: kworker/u16:3 Not tainted 6.2.0-rc7-00018-g0983f6bf2bfc #222
> >> [ 46.009504] Hardware name: Samsung Exynos (Flattened Device Tree)
> >> [ 46.015542] Workqueue: rpciod rpc_async_schedule
> >> [ 46.020123] unwind_backtrace from show_stack+0x10/0x14
> >> [ 46.025323] show_stack from dump_stack_lvl+0x58/0x70
> >> [ 46.030301] dump_stack_lvl from kasan_report+0xa8/0xe0
> >> [ 46.035501] kasan_report from kasan_check_range+0x94/0x1a0
> >> [ 46.041048] kasan_check_range from memcpy+0x28/0x68
> >> [ 46.045985] memcpy from xdr_inline_decode+0x140/0x200
> >> [ 46.051098] xdr_inline_decode from nfs4_xdr_dec_read_plus+0x298/0x5b8
> >> [ 46.057602] nfs4_xdr_dec_read_plus from call_decode+0x39c/0x530
> >> [ 46.063581] call_decode from __rpc_execute+0x1f4/0xc5c
> >> [ 46.068776] __rpc_execute from rpc_async_schedule+0x2c/0x4c
> >> [ 46.074411] rpc_async_schedule from process_one_work+0x51c/0xc44
> >> [ 46.080478] process_one_work from worker_thread+0x9c/0x7c0
> >> [ 46.086022] worker_thread from kthread+0x16c/0x1b8
> >> [ 46.090872] kthread from ret_from_fork+0x14/0x2c
> >> [ 46.095550] Exception stack(0xf0ba3fb0 to 0xf0ba3ff8)
> >> [ 46.100580] 3fa0: 00000000 00000000 00000000 00000000
> >> [ 46.108740] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> >> [ 46.116885] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
> >> [ 46.123461] ==================================================================
> >> [ 46.130774] Disabling lock debugging due to kernel taint
> >> [ 50.848579] systemd[1]: Queued start job for default target Graphical Interface.
> >> [ 50.877068] systemd[1]: Created slice Slice /system/getty.
> >>
> >>
> >> Decoded stacktrace is (this is master branch):
> >>
> >> [ 46.020123] unwind_backtrace from show_stack (arch/arm/kernel/traps.c:258)
> >> [ 46.025323] show_stack from dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4))
> >> [ 46.030301] dump_stack_lvl from kasan_report (mm/kasan/report.c:184 mm/kasan/report.c:519)
> >> [ 46.035501] kasan_report from kasan_check_range (mm/kasan/generic.c:173 mm/kasan/generic.c:189)
> >> [ 46.041048] kasan_check_range from memcpy (mm/kasan/shadow.c:65)
> >> [ 46.045985] memcpy from xdr_inline_decode (net/sunrpc/xdr.c:1419 net/sunrpc/xdr.c:1454)
> >
> > Actually, this part is really useful. net/sunrpc/xdr.c:1419 points to
> > the memcpy in xdr_copy_to_scratch(), which has me wondering if I'm
> > incorrectly setting up the xdr scratch buffer that READ_PLUS uses for
> > decoding. Can you try this patch and let me know if it helps?
> >
> > From ac2d6c501dbcdb306480edaee625b5496f1fb4f5 Mon Sep 17 00:00:00 2001
> > From: Anna Schumaker <[email protected]>
> > Date: Fri, 10 Feb 2023 15:50:22 -0500
> > Subject: [PATCH] NFSv4.2: Rework scratch handling for READ_PLUS
> >
>
> Patch is corrupted - maybe mail program reformatted it when sending:
>
> Applying: NFSv4.2: Rework scratch handling for READ_PLUS
> error: corrupt patch at line 12
> Patch failed at 0001 NFSv4.2: Rework scratch handling for READ_PLUS
That's weird. I wasn't expecting gmail to reformat the patch but I
guess it did. I've added it as an attachment so that shouldn't happen
again.
Sorry about that!
Anna
>
>
> Best regards,
> Krzysztof
>
On 12/02/2023 15:05, Anna Schumaker wrote:
>>> From ac2d6c501dbcdb306480edaee625b5496f1fb4f5 Mon Sep 17 00:00:00 2001
>>> From: Anna Schumaker <[email protected]>
>>> Date: Fri, 10 Feb 2023 15:50:22 -0500
>>> Subject: [PATCH] NFSv4.2: Rework scratch handling for READ_PLUS
>>>
>>
>> Patch is corrupted - maybe mail program reformatted it when sending:
>>
>> Applying: NFSv4.2: Rework scratch handling for READ_PLUS
>> error: corrupt patch at line 12
>> Patch failed at 0001 NFSv4.2: Rework scratch handling for READ_PLUS
>
> That's weird. I wasn't expecting gmail to reformat the patch but I
> guess it did. I've added it as an attachment so that shouldn't happen
> again.
Still null ptr (built on 420b2d4 with your patch):
[ 144.690844] mmiocpy from xdr_inline_decode (net/sunrpc/xdr.c:1419 net/sunrpc/xdr.c:1454)
[ 144.695950] xdr_inline_decode from nfs4_xdr_dec_read_plus (fs/nfs/nfs42xdr.c:1063 fs/nfs/nfs42xdr.c:1147 fs/nfs/nfs42xdr.c:1360 fs/nfs/nfs42xdr.c:1341)
[ 144.702452] nfs4_xdr_dec_read_plus from call_decode (net/sunrpc/clnt.c:2595)
[ 144.708429] call_decode from __rpc_execute (include/asm-generic/bitops/generic-non-atomic.h:128 net/sunrpc/sched.c:954)
[ 144.713538] __rpc_execute from rpc_async_schedule (include/linux/sched/mm.h:336 net/sunrpc/sched.c:1035)
[ 144.719170] rpc_async_schedule from process_one_work (include/linux/jump_label.h:260 include/linux/jump_label.h:270 include/trace/events/workqueue.h:108 kernel/workqueue.c:2294)
[ 144.725238] process_one_work from worker_thread (include/linux/list.h:292 kernel/workqueue.c:2437)
[ 144.730782] worker_thread from kthread (kernel/kthread.c:378)
[ 144.735547] kthread from ret_from_fork (arch/arm/kernel/entry-common.S:149)
Best regards,
Krzysztof
On Tue, Feb 14, 2023 at 6:08 AM Krzysztof Kozlowski
<[email protected]> wrote:
>
> On 12/02/2023 15:05, Anna Schumaker wrote:
> >>> From ac2d6c501dbcdb306480edaee625b5496f1fb4f5 Mon Sep 17 00:00:00 2001
> >>> From: Anna Schumaker <[email protected]>
> >>> Date: Fri, 10 Feb 2023 15:50:22 -0500
> >>> Subject: [PATCH] NFSv4.2: Rework scratch handling for READ_PLUS
> >>>
> >>
> >> Patch is corrupted - maybe mail program reformatted it when sending:
> >>
> >> Applying: NFSv4.2: Rework scratch handling for READ_PLUS
> >> error: corrupt patch at line 12
> >> Patch failed at 0001 NFSv4.2: Rework scratch handling for READ_PLUS
> >
> > That's weird. I wasn't expecting gmail to reformat the patch but I
> > guess it did. I've added it as an attachment so that shouldn't happen
> > again.
>
> Still null ptr (built on 420b2d4 with your patch):
>
> [ 144.690844] mmiocpy from xdr_inline_decode (net/sunrpc/xdr.c:1419 net/sunrpc/xdr.c:1454)
> [ 144.695950] xdr_inline_decode from nfs4_xdr_dec_read_plus (fs/nfs/nfs42xdr.c:1063 fs/nfs/nfs42xdr.c:1147 fs/nfs/nfs42xdr.c:1360 fs/nfs/nfs42xdr.c:1341)
> [ 144.702452] nfs4_xdr_dec_read_plus from call_decode (net/sunrpc/clnt.c:2595)
> [ 144.708429] call_decode from __rpc_execute (include/asm-generic/bitops/generic-non-atomic.h:128 net/sunrpc/sched.c:954)
> [ 144.713538] __rpc_execute from rpc_async_schedule (include/linux/sched/mm.h:336 net/sunrpc/sched.c:1035)
> [ 144.719170] rpc_async_schedule from process_one_work (include/linux/jump_label.h:260 include/linux/jump_label.h:270 include/trace/events/workqueue.h:108 kernel/workqueue.c:2294)
> [ 144.725238] process_one_work from worker_thread (include/linux/list.h:292 kernel/workqueue.c:2437)
> [ 144.730782] worker_thread from kthread (kernel/kthread.c:378)
> [ 144.735547] kthread from ret_from_fork (arch/arm/kernel/entry-common.S:149)
My 2cents...
From what I can tell read_plus only calls xdr_inline_decode() for
"numbers" (eof, #segs, type, offset, length) and we always expect that
__xdr_inline_decode() would return a a non-null "p". But if
__xdr_inline_decode() returned null, the code would call
xdr_copy_to_scratch() which would ultimately call the memcpy().
xdr_copy_to_scrach() expects the scratch buffer to be setup. However,
as I said, for the decode of numbers we don't set up the scratch
space. Which then leads to this oops. How, the reason the
__xdr_inline_decode() would return a null pointer if it ran out it's
provided xdr space which was provided #decode_read_plus_maxsz.
#define NFS42_READ_PLUS_DATA_SEGMENT_SIZE \
(1 /* data_content4 */ + \
2 /* data_info4.di_offset */ + \
1 /* data_info4.di_length */)
#define decode_read_plus_maxsz (op_decode_hdr_maxsz + \
1 /* rpr_eof */ + \
1 /* rpr_contents count */ + \
NFS42_READ_PLUS_DATA_SEGMENT_SIZE)
while a data segment needs (2) + (1), a hole segment needs to be (2) +
(2) (as both offset and lengths are longs.
while a "correct" maxsz is important for page alignment for reads, it
might means we are not providing enough space for when there are hole
segments? It seems weird that for the spec we have hole length and
data length of different types (long and int).
>
>
>
> Best regards,
> Krzysztof
>
Hi Krzysztof,
On Tue, Feb 14, 2023 at 6:02 AM Krzysztof Kozlowski
<[email protected]> wrote:
>
> On 12/02/2023 15:05, Anna Schumaker wrote:
> >>> From ac2d6c501dbcdb306480edaee625b5496f1fb4f5 Mon Sep 17 00:00:00 2001
> >>> From: Anna Schumaker <[email protected]>
> >>> Date: Fri, 10 Feb 2023 15:50:22 -0500
> >>> Subject: [PATCH] NFSv4.2: Rework scratch handling for READ_PLUS
> >>>
> >>
> >> Patch is corrupted - maybe mail program reformatted it when sending:
> >>
> >> Applying: NFSv4.2: Rework scratch handling for READ_PLUS
> >> error: corrupt patch at line 12
> >> Patch failed at 0001 NFSv4.2: Rework scratch handling for READ_PLUS
> >
> > That's weird. I wasn't expecting gmail to reformat the patch but I
> > guess it did. I've added it as an attachment so that shouldn't happen
> > again.
>
> Still null ptr (built on 420b2d4 with your patch):
We're through the merge window and at rc1 now, so I can spend more
time scratching my head over your bug again. We've come up with a
patch (attached) that adds a bunch of printks to show us what the
kernel thinks is going on. Do you mind trying it out and letting us
know what gets printed out? You'll need to make sure
CONFIG_NFS_V4_2_READ_PLUS is enabled when compiling the kernel.
Thanks,
Anna
>
> [ 144.690844] mmiocpy from xdr_inline_decode (net/sunrpc/xdr.c:1419 net/sunrpc/xdr.c:1454)
> [ 144.695950] xdr_inline_decode from nfs4_xdr_dec_read_plus (fs/nfs/nfs42xdr.c:1063 fs/nfs/nfs42xdr.c:1147 fs/nfs/nfs42xdr.c:1360 fs/nfs/nfs42xdr.c:1341)
> [ 144.702452] nfs4_xdr_dec_read_plus from call_decode (net/sunrpc/clnt.c:2595)
> [ 144.708429] call_decode from __rpc_execute (include/asm-generic/bitops/generic-non-atomic.h:128 net/sunrpc/sched.c:954)
> [ 144.713538] __rpc_execute from rpc_async_schedule (include/linux/sched/mm.h:336 net/sunrpc/sched.c:1035)
> [ 144.719170] rpc_async_schedule from process_one_work (include/linux/jump_label.h:260 include/linux/jump_label.h:270 include/trace/events/workqueue.h:108 kernel/workqueue.c:2294)
> [ 144.725238] process_one_work from worker_thread (include/linux/list.h:292 kernel/workqueue.c:2437)
> [ 144.730782] worker_thread from kthread (kernel/kthread.c:378)
> [ 144.735547] kthread from ret_from_fork (arch/arm/kernel/entry-common.S:149)
>
>
>
> Best regards,
> Krzysztof
>