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

[Eric Dumazet]

On Thu, Dec 7, 2017 at 11:54 PM, Matt Turner <mattst88@xxxxxxxxx> wrote:
> On Thu, Dec 7, 2017 at 11:00 PM, Matt Turner <mattst88@xxxxxxxxx> wrote:
>> On Sun, Mar 12, 2017 at 6:43 PM, Matt Turner <mattst88@xxxxxxxxx> 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.