2017-03-13 01:44:16

by Matt Turner

[permalink] [raw]
Subject: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On a Broadcom BCM91250a MIPS system I can reliably trigger NFS
corruption on the first file read.

To demonstrate, I downloaded five identical copies of the gcc-5.4.0
source tarball. On the NFS server, they hash to the same value:

server distfiles # md5sum gcc-5.4.0.tar.bz2*
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4

On the MIPS system (the NFS client):

bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2.2
35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4

The first file read will contain some corruption, and it is persistent until...

bcm91250a-le distfiles # echo 1 > /proc/sys/vm/drop_caches
bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4

the caches are dropped, at which point it reads back properly.

Note that the corruption is different across reboots, both in the size
of the corruption and the location. I saw 1900~ and 1400~ byte
sequences corrupted on separate occasions, which don't correspond to
the system's 16kB page size.

I've tested kernels from v3.19 to 4.11-rc1+ (master branch from
today). All exhibit this behavior with differing frequencies. Earlier
kernels seem to reproduce the issue less often, while more recent
kernels reliably exhibit the problem every boot.

How can I further debug this?


2017-03-13 09:48:13

by James Hogan

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Sun, Mar 12, 2017 at 06:43:47PM -0700, Matt Turner wrote:
> On a Broadcom BCM91250a MIPS system I can reliably trigger NFS
> corruption on the first file read.
>
> To demonstrate, I downloaded five identical copies of the gcc-5.4.0
> source tarball. On the NFS server, they hash to the same value:
>
> server distfiles # md5sum gcc-5.4.0.tar.bz2*
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>
> On the MIPS system (the NFS client):
>
> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2.2
> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>
> The first file read will contain some corruption, and it is persistent until...
>
> bcm91250a-le distfiles # echo 1 > /proc/sys/vm/drop_caches
> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>
> the caches are dropped, at which point it reads back properly.
>
> Note that the corruption is different across reboots, both in the size
> of the corruption and the location. I saw 1900~ and 1400~ byte
> sequences corrupted on separate occasions, which don't correspond to
> the system's 16kB page size.
>
> I've tested kernels from v3.19 to 4.11-rc1+ (master branch from
> today). All exhibit this behavior with differing frequencies. Earlier
> kernels seem to reproduce the issue less often, while more recent
> kernels reliably exhibit the problem every boot.
>
> How can I further debug this?

It smells a bit like a DMA / caching issue.

Can you provide a full kernel log. That might provide some information
about caching that might be relevant (e.g. does dcache have aliases?).

Cheers
James


Attachments:
(No filename) (2.35 kB)
signature.asc (801.00 B)
Digital signature
Download all attachments

2017-03-13 17:18:12

by Matt Turner

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Mon, Mar 13, 2017 at 2:47 AM, James Hogan <[email protected]> wrote:
> On Sun, Mar 12, 2017 at 06:43:47PM -0700, Matt Turner wrote:
>> On a Broadcom BCM91250a MIPS system I can reliably trigger NFS
>> corruption on the first file read.
>>
>> To demonstrate, I downloaded five identical copies of the gcc-5.4.0
>> source tarball. On the NFS server, they hash to the same value:
>>
>> server distfiles # md5sum gcc-5.4.0.tar.bz2*
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>>
>> On the MIPS system (the NFS client):
>>
>> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2.2
>> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
>> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>>
>> The first file read will contain some corruption, and it is persistent until...
>>
>> bcm91250a-le distfiles # echo 1 > /proc/sys/vm/drop_caches
>> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>>
>> the caches are dropped, at which point it reads back properly.
>>
>> Note that the corruption is different across reboots, both in the size
>> of the corruption and the location. I saw 1900~ and 1400~ byte
>> sequences corrupted on separate occasions, which don't correspond to
>> the system's 16kB page size.
>>
>> I've tested kernels from v3.19 to 4.11-rc1+ (master branch from
>> today). All exhibit this behavior with differing frequencies. Earlier
>> kernels seem to reproduce the issue less often, while more recent
>> kernels reliably exhibit the problem every boot.
>>
>> How can I further debug this?
>
> It smells a bit like a DMA / caching issue.
>
> Can you provide a full kernel log. That might provide some information
> about caching that might be relevant (e.g. does dcache have aliases?).

Thanks for the reply. Please find attached dmesg from a clean boot
(which reproduced the problem).


Attachments:
dmesg (16.14 kB)

2017-03-15 09:52:28

by Ralf Baechle

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Mon, Mar 13, 2017 at 09:47:57AM +0000, James Hogan wrote:

> >
> > Note that the corruption is different across reboots, both in the size
> > of the corruption and the location. I saw 1900~ and 1400~ byte
> > sequences corrupted on separate occasions, which don't correspond to
> > the system's 16kB page size.
> >
> > I've tested kernels from v3.19 to 4.11-rc1+ (master branch from
> > today). All exhibit this behavior with differing frequencies. Earlier
> > kernels seem to reproduce the issue less often, while more recent
> > kernels reliably exhibit the problem every boot.
> >
> > How can I further debug this?
>
> It smells a bit like a DMA / caching issue.
>
> Can you provide a full kernel log. That might provide some information
> about caching that might be relevant (e.g. does dcache have aliases?).

The architecture of the BCM1250 SOC used for the BCM91250 boards are
fully coherent, S-cache and D-cache are physically indexed and tagged.
Only the VIVT (plus the usual ASID tagging) I-cache leaves space for
software to screw up cache management but that shouldn't matter for this
case, so I suggest to start looking into this from the NFS side.

Ralf

2017-12-08 07:01:15

by Matt Turner

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Sun, Mar 12, 2017 at 6:43 PM, Matt Turner <[email protected]> wrote:
> On a Broadcom BCM91250a MIPS system I can reliably trigger NFS
> corruption on the first file read.
>
> To demonstrate, I downloaded five identical copies of the gcc-5.4.0
> source tarball. On the NFS server, they hash to the same value:
>
> server distfiles # md5sum gcc-5.4.0.tar.bz2*
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>
> On the MIPS system (the NFS client):
>
> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2.2
> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>
> The first file read will contain some corruption, and it is persistent until...
>
> bcm91250a-le distfiles # echo 1 > /proc/sys/vm/drop_caches
> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>
> the caches are dropped, at which point it reads back properly.
>
> Note that the corruption is different across reboots, both in the size
> of the corruption and the location. I saw 1900~ and 1400~ byte
> sequences corrupted on separate occasions, which don't correspond to
> the system's 16kB page size.
>
> I've tested kernels from v3.19 to 4.11-rc1+ (master branch from
> today). All exhibit this behavior with differing frequencies. Earlier
> kernels seem to reproduce the issue less often, while more recent
> kernels reliably exhibit the problem every boot.
>
> How can I further debug this?

I think I was wrong about the statement about kernels v3.19 to
4.11-rc1+. I found out I couldn't reproduce with 4.7-rc1 and then
bisected to 4cd13c21b207e80ddb1144c576500098f2d5f882 ("softirq: Let
ksoftirqd do its job"). Still reproduces with current tip of Linus'
tree.

Any ideas? The board's ethernet is an uncommon device supported by
CONFIG_SB1250_MAC. Something about the ethernet driver maybe?

2017-12-08 07:54:28

by Matt Turner

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Thu, Dec 7, 2017 at 11:00 PM, Matt Turner <[email protected]> wrote:
> On Sun, Mar 12, 2017 at 6:43 PM, Matt Turner <[email protected]> wrote:
>> On a Broadcom BCM91250a MIPS system I can reliably trigger NFS
>> corruption on the first file read.
>>
>> To demonstrate, I downloaded five identical copies of the gcc-5.4.0
>> source tarball. On the NFS server, they hash to the same value:
>>
>> server distfiles # md5sum gcc-5.4.0.tar.bz2*
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>>
>> On the MIPS system (the NFS client):
>>
>> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2.2
>> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
>> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>>
>> The first file read will contain some corruption, and it is persistent until...
>>
>> bcm91250a-le distfiles # echo 1 > /proc/sys/vm/drop_caches
>> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>>
>> the caches are dropped, at which point it reads back properly.
>>
>> Note that the corruption is different across reboots, both in the size
>> of the corruption and the location. I saw 1900~ and 1400~ byte
>> sequences corrupted on separate occasions, which don't correspond to
>> the system's 16kB page size.
>>
>> I've tested kernels from v3.19 to 4.11-rc1+ (master branch from
>> today). All exhibit this behavior with differing frequencies. Earlier
>> kernels seem to reproduce the issue less often, while more recent
>> kernels reliably exhibit the problem every boot.
>>
>> How can I further debug this?
>
> I think I was wrong about the statement about kernels v3.19 to
> 4.11-rc1+. I found out I couldn't reproduce with 4.7-rc1 and then
> bisected to 4cd13c21b207e80ddb1144c576500098f2d5f882 ("softirq: Let
> ksoftirqd do its job"). Still reproduces with current tip of Linus'
> tree.
>
> Any ideas? The board's ethernet is an uncommon device supported by
> CONFIG_SB1250_MAC. Something about the ethernet driver maybe?

With the patch reverted on master (reverts cleanly), NFS corruption no
longer happens.

2017-12-08 13:42:53

by Eric Dumazet

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Thu, Dec 7, 2017 at 11:54 PM, Matt Turner <[email protected]> wrote:
> On Thu, Dec 7, 2017 at 11:00 PM, Matt Turner <[email protected]> wrote:
>> On Sun, Mar 12, 2017 at 6:43 PM, Matt Turner <[email protected]> wrote:
>>> On a Broadcom BCM91250a MIPS system I can reliably trigger NFS
>>> corruption on the first file read.
>>>
>>> To demonstrate, I downloaded five identical copies of the gcc-5.4.0
>>> source tarball. On the NFS server, they hash to the same value:
>>>
>>> server distfiles # md5sum gcc-5.4.0.tar.bz2*
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>>>
>>> On the MIPS system (the NFS client):
>>>
>>> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2.2
>>> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
>>> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>>> 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>>>
>>> The first file read will contain some corruption, and it is persistent until...
>>>
>>> bcm91250a-le distfiles # echo 1 > /proc/sys/vm/drop_caches
>>> bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>>> 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>>>
>>> the caches are dropped, at which point it reads back properly.
>>>
>>> Note that the corruption is different across reboots, both in the size
>>> of the corruption and the location. I saw 1900~ and 1400~ byte
>>> sequences corrupted on separate occasions, which don't correspond to
>>> the system's 16kB page size.
>>>
>>> I've tested kernels from v3.19 to 4.11-rc1+ (master branch from
>>> today). All exhibit this behavior with differing frequencies. Earlier
>>> kernels seem to reproduce the issue less often, while more recent
>>> kernels reliably exhibit the problem every boot.
>>>
>>> How can I further debug this?
>>
>> I think I was wrong about the statement about kernels v3.19 to
>> 4.11-rc1+. I found out I couldn't reproduce with 4.7-rc1 and then
>> bisected to 4cd13c21b207e80ddb1144c576500098f2d5f882 ("softirq: Let
>> ksoftirqd do its job"). Still reproduces with current tip of Linus'
>> tree.
>>
>> Any ideas? The board's ethernet is an uncommon device supported by
>> CONFIG_SB1250_MAC. Something about the ethernet driver maybe?
>
> With the patch reverted on master (reverts cleanly), NFS corruption no
> longer happens.

Hi Matt.

Thanks for bisecting.

Patch simply exposes an existing bug more often by changing the way
driver functions are scheduled.

Which is probably a good thing.

sbmac_intr() looks extremely suspicious to me.

A NAPI driver hard interrupt should simply schedule NAPI.

Apparently, if sbmac_intr() can not grab NAPIF_STATE_SCHED bit, it
directly calls sbdma_rx_process() from
hard interrupt context.

Insane really.

2017-12-08 13:52:51

by Eric Dumazet

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Fri, 2017-12-08 at 05:42 -0800, Eric Dumazet wrote:
> On Thu, Dec 7, 2017 at 11:54 PM, Matt Turner <[email protected]>
> wrote:
> > On Thu, Dec 7, 2017 at 11:00 PM, Matt Turner <[email protected]>
> > wrote:
> > > On Sun, Mar 12, 2017 at 6:43 PM, Matt Turner <[email protected]>
> > > wrote:
> > > > On a Broadcom BCM91250a MIPS system I can reliably trigger NFS
> > > > corruption on the first file read.
> > > >
> > > > To demonstrate, I downloaded five identical copies of the gcc-
> > > > 5.4.0
> > > > source tarball. On the NFS server, they hash to the same value:
> > > >
> > > > server distfiles # md5sum gcc-5.4.0.tar.bz2*
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.1
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.2
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.3
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.4
> > > >
> > > > On the MIPS system (the NFS client):
> > > >
> > > > bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2.2
> > > > 35346975989954df8a8db2b034da610d  gcc-5.4.0.tar.bz2.2
> > > > bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.1
> > > > 35346975989954df8a8db2b034da610d  gcc-5.4.0.tar.bz2.2
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.3
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.4
> > > >
> > > > The first file read will contain some corruption, and it is
> > > > persistent until...
> > > >
> > > > bcm91250a-le distfiles # echo 1 > /proc/sys/vm/drop_caches
> > > > bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.1
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.2
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.3
> > > > 4c626ac2a83ef30dfb9260e6f59c2b30  gcc-5.4.0.tar.bz2.4
> > > >
> > > > the caches are dropped, at which point it reads back properly.
> > > >
> > > > Note that the corruption is different across reboots, both in
> > > > the size
> > > > of the corruption and the location. I saw 1900~ and 1400~ byte
> > > > sequences corrupted on separate occasions, which don't
> > > > correspond to
> > > > the system's 16kB page size.
> > > >
> > > > I've tested kernels from v3.19 to 4.11-rc1+ (master branch from
> > > > today). All exhibit this behavior with differing frequencies.
> > > > Earlier
> > > > kernels seem to reproduce the issue less often, while more
> > > > recent
> > > > kernels reliably exhibit the problem every boot.
> > > >
> > > > How can I further debug this?
> > >
> > > I think I was wrong about the statement about kernels v3.19 to
> > > 4.11-rc1+. I found out I couldn't reproduce with 4.7-rc1 and then
> > > bisected to 4cd13c21b207e80ddb1144c576500098f2d5f882 ("softirq:
> > > Let
> > > ksoftirqd do its job"). Still reproduces with current tip of
> > > Linus'
> > > tree.
> > >
> > > Any ideas? The board's ethernet is an uncommon device supported
> > > by
> > > CONFIG_SB1250_MAC. Something about the ethernet driver maybe?
> >
> > With the patch reverted on master (reverts cleanly), NFS corruption
> > no
> > longer happens.
>
> Hi Matt.
>
> Thanks for bisecting.
>
> Patch simply exposes an existing bug more often by changing the way
> driver functions are scheduled.
>
> Which is probably a good thing.
>
> sbmac_intr() looks extremely suspicious to me.
>
> A NAPI driver hard interrupt should simply schedule NAPI.
>
> Apparently, if sbmac_intr() can not grab NAPIF_STATE_SCHED bit, it
> directly calls sbdma_rx_process() from
> hard interrupt context.
>
> Insane really.

Please try this fix (not compiled on my x86 laptop, and I had no coffee
yet, so it might have some trivial errors)

diff --git a/drivers/net/ethernet/broadcom/sb1250-mac.c b/drivers/net/ethernet/broadcom/sb1250-mac.c
index ecdef42f0ae63641419a603f0b4eec2fc213c334..3ddd9ca469b280e70509b22fd7d3f449c81fbedc 100644
--- a/drivers/net/ethernet/broadcom/sb1250-mac.c
+++ b/drivers/net/ethernet/broadcom/sb1250-mac.c
@@ -287,8 +287,6 @@ static int sbdma_add_rcvbuffer(struct sbmac_softc *sc, struct sbmacdma *d,
static int sbdma_add_txbuffer(struct sbmacdma *d, struct sk_buff *m);
static void sbdma_emptyring(struct sbmacdma *d);
static void sbdma_fillring(struct sbmac_softc *sc, struct sbmacdma *d);
-static int sbdma_rx_process(struct sbmac_softc *sc, struct sbmacdma *d,
- int work_to_do, int poll);
static void sbdma_tx_process(struct sbmac_softc *sc, struct sbmacdma *d,
int poll);
static int sbmac_initctx(struct sbmac_softc *s);
@@ -1063,7 +1061,7 @@ static void sbmac_netpoll(struct net_device *netdev)
********************************************************************* */

static int sbdma_rx_process(struct sbmac_softc *sc, struct sbmacdma *d,
- int work_to_do, int poll)
+ int work_to_do)
{
struct net_device *dev = sc->sbm_dev;
int curidx;
@@ -1076,7 +1074,6 @@ static int sbdma_rx_process(struct sbmac_softc *sc, struct sbmacdma *d,

prefetch(d);

-again:
/* Check if the HW dropped any frames */
dev->stats.rx_fifo_errors
+= __raw_readq(sc->sbm_rxdma.sbdma_oodpktlost) & 0xffff;
@@ -1169,10 +1166,7 @@ static int sbdma_rx_process(struct sbmac_softc *sc, struct sbmacdma *d,
}
prefetch(sb->data);
prefetch((const void *)(((char *)sb->data)+32));
- if (poll)
- dropped = netif_receive_skb(sb);
- else
- dropped = netif_rx(sb);
+ dropped = netif_receive_skb(sb);

if (dropped == NET_RX_DROP) {
dev->stats.rx_dropped++;
@@ -1201,10 +1195,6 @@ static int sbdma_rx_process(struct sbmac_softc *sc, struct sbmacdma *d,
d->sbdma_remptr = SBDMA_NEXTBUF(d,sbdma_remptr);
work_done++;
}
- if (!poll) {
- work_to_do = 32;
- goto again; /* collect fifo drop statistics again */
- }
done:
return work_done;
}
@@ -2006,11 +1996,6 @@ static irqreturn_t sbmac_intr(int irq,void *dev_instance)
__napi_schedule(&sc->napi);
/* Depend on the exit from poll to reenable intr */
}
- else {
- /* may leave some packets behind */
- sbdma_rx_process(sc,&(sc->sbm_rxdma),
- SBMAC_MAX_RXDESCR * 2, 0);
- }
}
return IRQ_RETVAL(handled);
}
@@ -2529,7 +2514,7 @@ static int sbmac_poll(struct napi_struct *napi, int budget)
struct sbmac_softc *sc = container_of(napi, struct sbmac_softc, napi);
int work_done;

- work_done = sbdma_rx_process(sc, &(sc->sbm_rxdma), budget, 1);
+ work_done = sbdma_rx_process(sc, &(sc->sbm_rxdma), budget);
sbdma_tx_process(sc, &(sc->sbm_txdma), 1);

if (work_done < budget) {


2017-12-08 20:27:10

by Matt Turner

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Fri, Dec 8, 2017 at 5:52 AM, Eric Dumazet <[email protected]> wrote:
> On Fri, 2017-12-08 at 05:42 -0800, Eric Dumazet wrote:
>> On Thu, Dec 7, 2017 at 11:54 PM, Matt Turner <[email protected]>
>> wrote:
>> > On Thu, Dec 7, 2017 at 11:00 PM, Matt Turner <[email protected]>
>> > wrote:
>> > > On Sun, Mar 12, 2017 at 6:43 PM, Matt Turner <[email protected]>
>> > > wrote:
>> > > > On a Broadcom BCM91250a MIPS system I can reliably trigger NFS
>> > > > corruption on the first file read.
>> > > >
>> > > > To demonstrate, I downloaded five identical copies of the gcc-
>> > > > 5.4.0
>> > > > source tarball. On the NFS server, they hash to the same value:
>> > > >
>> > > > server distfiles # md5sum gcc-5.4.0.tar.bz2*
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>> > > >
>> > > > On the MIPS system (the NFS client):
>> > > >
>> > > > bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2.2
>> > > > 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
>> > > > bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>> > > > 35346975989954df8a8db2b034da610d gcc-5.4.0.tar.bz2.2
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>> > > >
>> > > > The first file read will contain some corruption, and it is
>> > > > persistent until...
>> > > >
>> > > > bcm91250a-le distfiles # echo 1 > /proc/sys/vm/drop_caches
>> > > > bcm91250a-le distfiles # md5sum gcc-5.4.0.tar.bz2*
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.1
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.2
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.3
>> > > > 4c626ac2a83ef30dfb9260e6f59c2b30 gcc-5.4.0.tar.bz2.4
>> > > >
>> > > > the caches are dropped, at which point it reads back properly.
>> > > >
>> > > > Note that the corruption is different across reboots, both in
>> > > > the size
>> > > > of the corruption and the location. I saw 1900~ and 1400~ byte
>> > > > sequences corrupted on separate occasions, which don't
>> > > > correspond to
>> > > > the system's 16kB page size.
>> > > >
>> > > > I've tested kernels from v3.19 to 4.11-rc1+ (master branch from
>> > > > today). All exhibit this behavior with differing frequencies.
>> > > > Earlier
>> > > > kernels seem to reproduce the issue less often, while more
>> > > > recent
>> > > > kernels reliably exhibit the problem every boot.
>> > > >
>> > > > How can I further debug this?
>> > >
>> > > I think I was wrong about the statement about kernels v3.19 to
>> > > 4.11-rc1+. I found out I couldn't reproduce with 4.7-rc1 and then
>> > > bisected to 4cd13c21b207e80ddb1144c576500098f2d5f882 ("softirq:
>> > > Let
>> > > ksoftirqd do its job"). Still reproduces with current tip of
>> > > Linus'
>> > > tree.
>> > >
>> > > Any ideas? The board's ethernet is an uncommon device supported
>> > > by
>> > > CONFIG_SB1250_MAC. Something about the ethernet driver maybe?
>> >
>> > With the patch reverted on master (reverts cleanly), NFS corruption
>> > no
>> > longer happens.
>>
>> Hi Matt.
>>
>> Thanks for bisecting.
>>
>> Patch simply exposes an existing bug more often by changing the way
>> driver functions are scheduled.
>>
>> Which is probably a good thing.
>>
>> sbmac_intr() looks extremely suspicious to me.
>>
>> A NAPI driver hard interrupt should simply schedule NAPI.
>>
>> Apparently, if sbmac_intr() can not grab NAPIF_STATE_SCHED bit, it
>> directly calls sbdma_rx_process() from
>> hard interrupt context.
>>
>> Insane really.
>
> Please try this fix (not compiled on my x86 laptop, and I had no coffee
> yet, so it might have some trivial errors)

Thanks for the quick reply!

I tried the patch on top of master, but unfortunately the corruption
still occurs.

2017-12-08 21:16:30

by Eric Dumazet

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Fri, 2017-12-08 at 12:26 -0800, Matt Turner wrote:
>
> Thanks for the quick reply!
>
> I tried the patch on top of master, but unfortunately the corruption
> still occurs.

You might try replacing in sbdma_add_rcvbuffer()

sb_new = netdev_alloc_skb(dev, size);

by 

sb_new = alloc_skb(size, GFP_ATOMIC);

Maybe the device does not like having a frame spanning 2 pages.


2017-12-09 21:04:08

by Matt Turner

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Fri, Dec 8, 2017 at 1:16 PM, Eric Dumazet <[email protected]> wrote:
> On Fri, 2017-12-08 at 12:26 -0800, Matt Turner wrote:
>>
>> Thanks for the quick reply!
>>
>> I tried the patch on top of master, but unfortunately the corruption
>> still occurs.
>
> You might try replacing in sbdma_add_rcvbuffer()
>
> sb_new = netdev_alloc_skb(dev, size);
>
> by
>
> sb_new = alloc_skb(size, GFP_ATOMIC);
>
> Maybe the device does not like having a frame spanning 2 pages.

No such luck. I also gave changing the page size from 16K to 4K a shot
without success.

2017-12-09 21:37:10

by Eric Dumazet

[permalink] [raw]
Subject: Re: NFS corruption, fixed by echo 1 > /proc/sys/vm/drop_caches -- next debugging steps?

On Sat, 2017-12-09 at 13:03 -0800, Matt Turner wrote:
> On Fri, Dec 8, 2017 at 1:16 PM, Eric Dumazet <[email protected]>
> wrote:
> > On Fri, 2017-12-08 at 12:26 -0800, Matt Turner wrote:
> > >
> > > Thanks for the quick reply!
> > >
> > > I tried the patch on top of master, but unfortunately the
> > > corruption
> > > still occurs.
> >
> > You might try replacing in sbdma_add_rcvbuffer()
> >
> > sb_new = netdev_alloc_skb(dev, size);
> >
> > by
> >
> > sb_new = alloc_skb(size, GFP_ATOMIC);
> >
> > Maybe the device does not like having a frame spanning 2 pages.
>
> No such luck. I also gave changing the page size from 16K to 4K a
> shot
> without success.


If your hist is SMP, could you try running it with one CPU only ?

Sorry, I have no more ideas :/