public inbox for linux-xfs@vger.kernel.org
 help / color / mirror / Atom feed
* [4.20-rc4 regression] generic/095 Concurrent mixed I/O hang on xfs based overlayfs
@ 2018-11-30  5:12 Murphy Zhou
  2018-11-30 12:15 ` Zorro Lang
  0 siblings, 1 reply; 5+ messages in thread
From: Murphy Zhou @ 2018-11-30  5:12 UTC (permalink / raw)
  To: linux-xfs; +Cc: linux-unionfs, zlang

Hi,

Hit a xfs regression issue by generic/095 on overlayfs.

It's easy to reproduce. Tests processes hang there and never return.
There are some warning in the dmesg.

SIGINT (Ctrl+C) can't kill the tests, neither does SIGTERM (kill).
However, SIGKILL (kill -9) can clean them up.

This happens when testing on v4 or v5 or reflink, with the same behaviour.
-m crc=0
-m crc=1,finobt=1,rmapbt=0,reflink=0 -i sparse=1
-m crc=1,finobt=1,rmapbt=1,reflink=1 -i sparse=1

This does not happen if ext4 as base fs for overlayfs.

Bisecting points to this commit:
	4721a601 iomap: dio data corruption and spurious errors when pipes fill

Test pass soon after this commit reverted.

# ps axjf
 1839  1862   S+    0:00  |  \_ /bin/bash ./bin/single -o -t generic/095
 1862  2005   S+    0:00  |      \_ /bin/bash ./check -T -overlay generic/095
 2005  2292   S+    0:00  |          \_ /bin/bash ./tests/generic/095
 2292  2516   Sl+   0:01  |              \_ /usr/bin/fio /tmp/2292.fio
 2516  2565   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
 2516  2566   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
 2516  2567   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
 2516  2568   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
 2516  2569   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio

# dmesg
[   50.285345] run fstests generic/095 at 2018-11-29 23:25:24
[   50.441180] XFS (loop1): Unmounting Filesystem
[   51.126243] XFS (loop1): Mounting V5 Filesystem
[   51.133348] XFS (loop1): Ending clean mount
[   51.646769] Page cache invalidation failure on direct I/O.  Possible data corruption due to collision with buffered I/O!
[   51.646878] Page cache invalidation failure on direct I/O.  Possible data corruption due to collision with buffered I/O!
[   51.647776] Page cache invalidation failure on direct I/O.  Possible data corruption due to collision with buffered I/O!
[   51.647779] File: /loopsch/ovl-mnt/file1 PID: 2568 Comm: fio
[   51.648148] Page cache invalidation failure on direct I/O.  Possible data corruption due to collision with buffered I/O!
[   51.648151] File: /loopsch/ovl-mnt/file1 PID: 2568 Comm: fio
[   51.657721] File: /loopsch/ovl-mnt/file1 PID: 2551 Comm: fio
[   51.707667] File: /loopsch/ovl-mnt/file2 PID: 2599 Comm: fio

# local.config
TEST_DEV=/dev/loop0
TEST_DIR=/loopmnt
SCRATCH_DEV=/dev/loop1
SCRATCH_MNT=/loopsch
FSTYP=xfs
MOUNT_OPTIONS=""
TEST_FS_MOUNT_OPTS=""
MKFS_OPTIONS=""

# cmd
./check -T -overlay generic/095

# xfstests version: git log --oneline -1
15b13f7f (HEAD -> master, origin/master, origin/imaster, origin/HEAD) ext4/021: Work with 64k block size

# xfsprogs version: git log --oneline -1
caa91046 (HEAD -> for-next, tag: v4.19.0, origin/master, origin/for-next, origin/HEAD) xfsprogs: Release v4.19.0

# xfs_io -V
xfs_io version 4.19.0

# xfs on loop device as base fs for overlayfs
/dev/loop1 on /loopsch type xfs (rw,relatime,seclabel,attr2,inode64,noquota)
meta-data=/dev/loop1             isize=512    agcount=4, agsize=983040 blks
         =                       sectsz=512   attr=2, projid32bit=1
         =                       crc=1        finobt=1, sparse=1, rmapbt=0
         =                       reflink=0
data     =                       bsize=4096   blocks=3932160, imaxpct=25
         =                       sunit=0      swidth=0 blks
naming   =version 2              bsize=4096   ascii-ci=0, ftype=1
log      =internal log           bsize=4096   blocks=2560, version=2
         =                       sectsz=512   sunit=0 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0

# overlayfs mount info:
/dev/loop0 on /loopmnt type xfs (rw,relatime,seclabel,attr2,inode64,noquota)
/loopmnt on /loopmnt/ovl-mnt type overlay (rw,relatime,context=system_u:object_r:root_t:s0,lowerdir=/loopmnt/ovl-lower,upperdir=/loopmnt/ovl-upper,workdir=/loopmnt/ovl-work)

# cat bs-log
git bisect start
# good: [edeca3a769ad28a9477798c3b1d8e0701db728e4] Merge tag 'sound-4.20-rc4' of git://git.kernel.org/pub/scm/linux/kernel/git/tiwai/sound
git bisect good edeca3a769ad28a9477798c3b1d8e0701db728e4
# bad: [d6d460b89378b1bc6715574cdafd748ba59d5a27] Merge tag 'dma-mapping-4.20-3' of git://git.infradead.org/users/hch/dma-mapping
git bisect bad d6d460b89378b1bc6715574cdafd748ba59d5a27
# good: [07093b76476903f820d83d56c3040e656fb4d9e3] net: gemini: Fix copy/paste error
git bisect good 07093b76476903f820d83d56c3040e656fb4d9e3
# good: [7c98a42618271210c60b79128b220107d35938d9] Merge tag 'ceph-for-4.20-rc4' of https://github.com/ceph/ceph-client
git bisect good 7c98a42618271210c60b79128b220107d35938d9
# bad: [e195ca6cb6f21633e56322d5aa11ed59cdb22fb2] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/hid/hid
git bisect bad e195ca6cb6f21633e56322d5aa11ed59cdb22fb2
# bad: [d146194f31c96f9b260c5a1cf1592d2e7f82a2e2] Merge tag 'arm64-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux
git bisect bad d146194f31c96f9b260c5a1cf1592d2e7f82a2e2
# good: [0929d8580071c6a1cec1a7916a8f674c243ceee1] iomap: FUA is wrong for DIO O_DSYNC writes into unwritten extents
git bisect good 0929d8580071c6a1cec1a7916a8f674c243ceee1
# bad: [8c110d43c6bca4b24dd13272a9d4e0ba6f2ec957] iomap: readpages doesn't zero page tail beyond EOF
git bisect bad 8c110d43c6bca4b24dd13272a9d4e0ba6f2ec957
# bad: [4721a6010990971440b4ffefbdf014976b8eda2f] iomap: dio data corruption and spurious errors when pipes fill
git bisect bad 4721a6010990971440b4ffefbdf014976b8eda2f
# good: [b450672fb66b4a991a5b55ee24209ac7ae7690ce] iomap: sub-block dio needs to zeroout beyond EOF
git bisect good b450672fb66b4a991a5b55ee24209ac7ae7690ce
# first bad commit: [4721a6010990971440b4ffefbdf014976b8eda2f] iomap: dio data corruption and spurious errors when pipes fill

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [4.20-rc4 regression] generic/095 Concurrent mixed I/O hang on xfs based overlayfs
  2018-11-30  5:12 [4.20-rc4 regression] generic/095 Concurrent mixed I/O hang on xfs based overlayfs Murphy Zhou
@ 2018-11-30 12:15 ` Zorro Lang
  2018-11-30 13:30   ` Amir Goldstein
  0 siblings, 1 reply; 5+ messages in thread
From: Zorro Lang @ 2018-11-30 12:15 UTC (permalink / raw)
  To: Murphy Zhou; +Cc: linux-xfs, linux-unionfs

On Fri, Nov 30, 2018 at 12:12:53AM -0500, Murphy Zhou wrote:
> Hi,
> 
> Hit a xfs regression issue by generic/095 on overlayfs.
> 
> It's easy to reproduce. Tests processes hang there and never return.
> There are some warning in the dmesg.
> 
> SIGINT (Ctrl+C) can't kill the tests, neither does SIGTERM (kill).
> However, SIGKILL (kill -9) can clean them up.
> 
> This happens when testing on v4 or v5 or reflink, with the same behaviour.
> -m crc=0
> -m crc=1,finobt=1,rmapbt=0,reflink=0 -i sparse=1
> -m crc=1,finobt=1,rmapbt=1,reflink=1 -i sparse=1
> 
> This does not happen if ext4 as base fs for overlayfs.
> 
> Bisecting points to this commit:
> 	4721a601 iomap: dio data corruption and spurious errors when pipes fill
> 
> Test pass soon after this commit reverted.
> 
> # ps axjf
>  1839  1862   S+    0:00  |  \_ /bin/bash ./bin/single -o -t generic/095
>  1862  2005   S+    0:00  |      \_ /bin/bash ./check -T -overlay generic/095
>  2005  2292   S+    0:00  |          \_ /bin/bash ./tests/generic/095
>  2292  2516   Sl+   0:01  |              \_ /usr/bin/fio /tmp/2292.fio
>  2516  2565   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
>  2516  2566   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
>  2516  2567   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
>  2516  2568   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
>  2516  2569   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio

Nice catch! I didn't tried overlayfs on XFS regression test this time. I never hit
issue on XFS singly, even on glusterfs(XFS underlying).

I just gave it a try. This bug is reproducible on xfs-linux git tree
xfs-4.20-fixes-2 HEAD. And by strace all fio processes, they all
keep outputing [1]. More details as [2]. Only overlayfs on XFS can
reproduce this bug, overlayfs on Ext4 can't.

Thanks,
Zorro

[1]
# strace -p $running_fio_process
...
...
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
splice(3, NULL, 5, [147456], 8192, 0)   = 0
...
...

[2]
# mount -l
...
/dev/sda3 on /mnt/ovl/test type xfs (rw,relatime,seclabel,attr2,inode64,sunit=512,swidth=512,noquota)
/dev/sda5 on /mnt/ovl/scratch type xfs (rw,relatime,seclabel,attr2,inode64,sunit=512,swidth=512,noquota)
/mnt/ovl/test on /mnt/xfstests/mnt1 type overlay (rw,relatime,context=system_u:object_r:nfs_t:s0,lowerdir=/mnt/ovl/test/ovl-lower,upperdir=/mnt/ovl/test/ovl-upper,workdir=/mnt/ovl/test/ovl-work)
/mnt/ovl/scratch on /mnt/xfstests/mnt2 type overlay (rw,relatime,context=system_u:object_r:nfs_t:s0,lowerdir=/mnt/ovl/scratch/ovl-lower,upperdir=/mnt/ovl/scratch/ovl-upper,workdir=/mnt/ovl/scratch/ovl-work)

# xfs_info /mnt/ovl/test
meta-data=/dev/sda3              isize=512    agcount=16, agsize=245760 blks
         =                       sectsz=512   attr=2, projid32bit=1
         =                       crc=1        finobt=1, sparse=1, rmapbt=0
         =                       reflink=0
data     =                       bsize=4096   blocks=3932160, imaxpct=25
         =                       sunit=64     swidth=64 blks
naming   =version 2              bsize=4096   ascii-ci=0, ftype=1
log      =internal log           bsize=4096   blocks=2560, version=2
         =                       sectsz=512   sunit=0 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0
# xfs_info /mnt/ovl/scratch
meta-data=/dev/sda5              isize=512    agcount=16, agsize=245760 blks
         =                       sectsz=512   attr=2, projid32bit=1
         =                       crc=1        finobt=1, sparse=1, rmapbt=0
         =                       reflink=0
data     =                       bsize=4096   blocks=3932160, imaxpct=25
         =                       sunit=64     swidth=64 blks
naming   =version 2              bsize=4096   ascii-ci=0, ftype=1
log      =internal log           bsize=4096   blocks=2560, version=2
         =                       sectsz=512   sunit=0 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0


> 
> # dmesg
> [   50.285345] run fstests generic/095 at 2018-11-29 23:25:24
> [   50.441180] XFS (loop1): Unmounting Filesystem
> [   51.126243] XFS (loop1): Mounting V5 Filesystem
> [   51.133348] XFS (loop1): Ending clean mount
> [   51.646769] Page cache invalidation failure on direct I/O.  Possible data corruption due to collision with buffered I/O!
> [   51.646878] Page cache invalidation failure on direct I/O.  Possible data corruption due to collision with buffered I/O!
> [   51.647776] Page cache invalidation failure on direct I/O.  Possible data corruption due to collision with buffered I/O!
> [   51.647779] File: /loopsch/ovl-mnt/file1 PID: 2568 Comm: fio
> [   51.648148] Page cache invalidation failure on direct I/O.  Possible data corruption due to collision with buffered I/O!
> [   51.648151] File: /loopsch/ovl-mnt/file1 PID: 2568 Comm: fio
> [   51.657721] File: /loopsch/ovl-mnt/file1 PID: 2551 Comm: fio
> [   51.707667] File: /loopsch/ovl-mnt/file2 PID: 2599 Comm: fio
> 
> # local.config
> TEST_DEV=/dev/loop0
> TEST_DIR=/loopmnt
> SCRATCH_DEV=/dev/loop1
> SCRATCH_MNT=/loopsch
> FSTYP=xfs
> MOUNT_OPTIONS=""
> TEST_FS_MOUNT_OPTS=""
> MKFS_OPTIONS=""
> 
> # cmd
> ./check -T -overlay generic/095
> 
> # xfstests version: git log --oneline -1
> 15b13f7f (HEAD -> master, origin/master, origin/imaster, origin/HEAD) ext4/021: Work with 64k block size
> 
> # xfsprogs version: git log --oneline -1
> caa91046 (HEAD -> for-next, tag: v4.19.0, origin/master, origin/for-next, origin/HEAD) xfsprogs: Release v4.19.0
> 
> # xfs_io -V
> xfs_io version 4.19.0
> 
> # xfs on loop device as base fs for overlayfs
> /dev/loop1 on /loopsch type xfs (rw,relatime,seclabel,attr2,inode64,noquota)
> meta-data=/dev/loop1             isize=512    agcount=4, agsize=983040 blks
>          =                       sectsz=512   attr=2, projid32bit=1
>          =                       crc=1        finobt=1, sparse=1, rmapbt=0
>          =                       reflink=0
> data     =                       bsize=4096   blocks=3932160, imaxpct=25
>          =                       sunit=0      swidth=0 blks
> naming   =version 2              bsize=4096   ascii-ci=0, ftype=1
> log      =internal log           bsize=4096   blocks=2560, version=2
>          =                       sectsz=512   sunit=0 blks, lazy-count=1
> realtime =none                   extsz=4096   blocks=0, rtextents=0
> 
> # overlayfs mount info:
> /dev/loop0 on /loopmnt type xfs (rw,relatime,seclabel,attr2,inode64,noquota)
> /loopmnt on /loopmnt/ovl-mnt type overlay (rw,relatime,context=system_u:object_r:root_t:s0,lowerdir=/loopmnt/ovl-lower,upperdir=/loopmnt/ovl-upper,workdir=/loopmnt/ovl-work)
> 
> # cat bs-log
> git bisect start
> # good: [edeca3a769ad28a9477798c3b1d8e0701db728e4] Merge tag 'sound-4.20-rc4' of git://git.kernel.org/pub/scm/linux/kernel/git/tiwai/sound
> git bisect good edeca3a769ad28a9477798c3b1d8e0701db728e4
> # bad: [d6d460b89378b1bc6715574cdafd748ba59d5a27] Merge tag 'dma-mapping-4.20-3' of git://git.infradead.org/users/hch/dma-mapping
> git bisect bad d6d460b89378b1bc6715574cdafd748ba59d5a27
> # good: [07093b76476903f820d83d56c3040e656fb4d9e3] net: gemini: Fix copy/paste error
> git bisect good 07093b76476903f820d83d56c3040e656fb4d9e3
> # good: [7c98a42618271210c60b79128b220107d35938d9] Merge tag 'ceph-for-4.20-rc4' of https://github.com/ceph/ceph-client
> git bisect good 7c98a42618271210c60b79128b220107d35938d9
> # bad: [e195ca6cb6f21633e56322d5aa11ed59cdb22fb2] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/hid/hid
> git bisect bad e195ca6cb6f21633e56322d5aa11ed59cdb22fb2
> # bad: [d146194f31c96f9b260c5a1cf1592d2e7f82a2e2] Merge tag 'arm64-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux
> git bisect bad d146194f31c96f9b260c5a1cf1592d2e7f82a2e2
> # good: [0929d8580071c6a1cec1a7916a8f674c243ceee1] iomap: FUA is wrong for DIO O_DSYNC writes into unwritten extents
> git bisect good 0929d8580071c6a1cec1a7916a8f674c243ceee1
> # bad: [8c110d43c6bca4b24dd13272a9d4e0ba6f2ec957] iomap: readpages doesn't zero page tail beyond EOF
> git bisect bad 8c110d43c6bca4b24dd13272a9d4e0ba6f2ec957
> # bad: [4721a6010990971440b4ffefbdf014976b8eda2f] iomap: dio data corruption and spurious errors when pipes fill
> git bisect bad 4721a6010990971440b4ffefbdf014976b8eda2f
> # good: [b450672fb66b4a991a5b55ee24209ac7ae7690ce] iomap: sub-block dio needs to zeroout beyond EOF
> git bisect good b450672fb66b4a991a5b55ee24209ac7ae7690ce
> # first bad commit: [4721a6010990971440b4ffefbdf014976b8eda2f] iomap: dio data corruption and spurious errors when pipes fill

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [4.20-rc4 regression] generic/095 Concurrent mixed I/O hang on xfs based overlayfs
  2018-11-30 12:15 ` Zorro Lang
@ 2018-11-30 13:30   ` Amir Goldstein
  2018-11-30 18:23     ` Darrick J. Wong
  0 siblings, 1 reply; 5+ messages in thread
From: Amir Goldstein @ 2018-11-30 13:30 UTC (permalink / raw)
  To: Darrick J. Wong; +Cc: jencce.kernel, linux-xfs, overlayfs, Zorro Lang, fstests

On Fri, Nov 30, 2018 at 2:13 PM Zorro Lang <zlang@redhat.com> wrote:
>
> On Fri, Nov 30, 2018 at 12:12:53AM -0500, Murphy Zhou wrote:
> > Hi,
> >
> > Hit a xfs regression issue by generic/095 on overlayfs.
> >
> > It's easy to reproduce. Tests processes hang there and never return.
> > There are some warning in the dmesg.
> >
> > SIGINT (Ctrl+C) can't kill the tests, neither does SIGTERM (kill).
> > However, SIGKILL (kill -9) can clean them up.
> >
> > This happens when testing on v4 or v5 or reflink, with the same behaviour.
> > -m crc=0
> > -m crc=1,finobt=1,rmapbt=0,reflink=0 -i sparse=1
> > -m crc=1,finobt=1,rmapbt=1,reflink=1 -i sparse=1
> >
> > This does not happen if ext4 as base fs for overlayfs.
> >
> > Bisecting points to this commit:
> >       4721a601 iomap: dio data corruption and spurious errors when pipes fill
> >
> > Test pass soon after this commit reverted.
> >
> > # ps axjf
> >  1839  1862   S+    0:00  |  \_ /bin/bash ./bin/single -o -t generic/095
> >  1862  2005   S+    0:00  |      \_ /bin/bash ./check -T -overlay generic/095
> >  2005  2292   S+    0:00  |          \_ /bin/bash ./tests/generic/095
> >  2292  2516   Sl+   0:01  |              \_ /usr/bin/fio /tmp/2292.fio
> >  2516  2565   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
> >  2516  2566   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
> >  2516  2567   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
> >  2516  2568   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
> >  2516  2569   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
>
> Nice catch! I didn't tried overlayfs on XFS regression test this time. I never hit
> issue on XFS singly, even on glusterfs(XFS underlying).
>
> I just gave it a try. This bug is reproducible on xfs-linux git tree
> xfs-4.20-fixes-2 HEAD. And by strace all fio processes, they all
> keep outputing [1]. More details as [2]. Only overlayfs on XFS can
> reproduce this bug, overlayfs on Ext4 can't.
>

Darrick,

This is my cue to insert a rant. You already know what I am going to rant about.

I cannot force you to add a check -overlay xfstests run to your pull
request validation
routine. I can offer assistance in any questions you may have and I can offer
support for check -overlay infrastructure if it breaks or if it needs
improvements.

I have checked on several recent point releases that check -overlay does not
regress any tests compared to xfs reflink configuration, and when I
found a regression
(mostly in overlayfs code, but also in xfs code sometimes) I reported
and/or fixed it.
But I do not have the resources to validate every xfs merge and
certainly not xfs-next.

There is a large group of tests that is expected to notrun, which
makes running the
-overlay test a lot faster than any given xfs configuration and IMO
running just a single
xfs reflink config with -overlay would give a pretty good test coverage.

So what do you say?...

Thanks,
Amir.

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [4.20-rc4 regression] generic/095 Concurrent mixed I/O hang on xfs based overlayfs
  2018-11-30 13:30   ` Amir Goldstein
@ 2018-11-30 18:23     ` Darrick J. Wong
  2018-12-01  9:24       ` Amir Goldstein
  0 siblings, 1 reply; 5+ messages in thread
From: Darrick J. Wong @ 2018-11-30 18:23 UTC (permalink / raw)
  To: Amir Goldstein, Dave Chinner
  Cc: jencce.kernel, linux-xfs, overlayfs, Zorro Lang, fstests

[add dave to cc]

On Fri, Nov 30, 2018 at 03:30:54PM +0200, Amir Goldstein wrote:
> On Fri, Nov 30, 2018 at 2:13 PM Zorro Lang <zlang@redhat.com> wrote:
> >
> > On Fri, Nov 30, 2018 at 12:12:53AM -0500, Murphy Zhou wrote:
> > > Hi,
> > >
> > > Hit a xfs regression issue by generic/095 on overlayfs.
> > >
> > > It's easy to reproduce. Tests processes hang there and never return.
> > > There are some warning in the dmesg.
> > >
> > > SIGINT (Ctrl+C) can't kill the tests, neither does SIGTERM (kill).
> > > However, SIGKILL (kill -9) can clean them up.
> > >
> > > This happens when testing on v4 or v5 or reflink, with the same behaviour.
> > > -m crc=0
> > > -m crc=1,finobt=1,rmapbt=0,reflink=0 -i sparse=1
> > > -m crc=1,finobt=1,rmapbt=1,reflink=1 -i sparse=1
> > >
> > > This does not happen if ext4 as base fs for overlayfs.
> > >
> > > Bisecting points to this commit:
> > >       4721a601 iomap: dio data corruption and spurious errors when pipes fill
> > >
> > > Test pass soon after this commit reverted.

UGH.

Ok, I ran g/095 on overlayfs and saw tons of this in the output:

XFS: Assertion failed: ret < 0 || ret == count, file: fs/xfs/xfs_file.c, line: 558

So, revert just this part of 4721a601:

	/*
	 * Splicing to pipes can fail on a full pipe. We have to
	 * swallow this to make it look like a short IO
	 * otherwise the higher splice layers will completely
	 * mishandle the error and stop moving data.
	 */
	if (ret == -EFAULT)
		ret = 0;

Does it work then?

No, because now we just bounce the EAGAIN out to userspace, recreating
the original problem where fsx dies.  I then stapled on some trace
printks to monitor what was going on, noticing that every time we tried
to do a directio read into the pipe, the stack trace was:

=> xfs_file_dio_aio_read (ffffffffa01b92a4)
=> xfs_file_read_iter (ffffffffa01b976a)
=> generic_file_splice_read (ffffffff812686da)
=> splice_direct_to_actor (ffffffff812689b6)
=> do_splice_direct (ffffffff81268b9f)
=> vfs_copy_file_range (ffffffff81230217)
=> __x64_sys_copy_file_range (ffffffff812305b1)
=> do_syscall_64 (ffffffff81002850)
=> entry_SYSCALL_64_after_hwframe (ffffffff8180007d)

Next I began looking at what those three splice functions actually do.
splice_direct_to_actor does (very roughly paraphrased):

while (len) {
	ret = do_splice_to(...len...) /* read data into pipe */
	if (ret < 0)
		goto out_release;
	actor(...ret) /* write data from pipe into file */
	len -= ret;
}

I observed that the pipe size is 64k.  The call do_splice_to() has a
length of 720k, so we allocate all the pipe buffers available, then
return EFAULT/EAGAIN.  We bounce straight out of this to userspace,
having not called ->actor (which empties the pipe by writing the
data), so we immediately EFAULT again, and now *anything* trying to use
current->pipe finds it is all jam up.

I think the solution here is that splice_direct_to_actor must clamp the
length argument to do_splice_to() to (buffers - nr_bufs) << PAGE_SHIFT.
It doesn't make sense to try to read more data than will fit in the
pipe, since the emptying process is synchronous with the reads.

So I tried it, and it seems to work with fsx and it makes generic/095
pass on overlayfs again.  I'll send that patch to the list shortly.

> > > # ps axjf
> > >  1839  1862   S+    0:00  |  \_ /bin/bash ./bin/single -o -t generic/095
> > >  1862  2005   S+    0:00  |      \_ /bin/bash ./check -T -overlay generic/095
> > >  2005  2292   S+    0:00  |          \_ /bin/bash ./tests/generic/095
> > >  2292  2516   Sl+   0:01  |              \_ /usr/bin/fio /tmp/2292.fio
> > >  2516  2565   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
> > >  2516  2566   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
> > >  2516  2567   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
> > >  2516  2568   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
> > >  2516  2569   Rs    6:02  |                  \_ /usr/bin/fio /tmp/2292.fio
> >
> > Nice catch! I didn't tried overlayfs on XFS regression test this time. I never hit
> > issue on XFS singly, even on glusterfs(XFS underlying).
> >
> > I just gave it a try. This bug is reproducible on xfs-linux git tree
> > xfs-4.20-fixes-2 HEAD. And by strace all fio processes, they all
> > keep outputing [1]. More details as [2]. Only overlayfs on XFS can
> > reproduce this bug, overlayfs on Ext4 can't.
> >
> 
> Darrick,
> 
> This is my cue to insert a rant. You already know what I am going to rant about.
> 
> I cannot force you to add a check -overlay xfstests run to your pull
> request validation
> routine. I can offer assistance in any questions you may have and I can offer
> support for check -overlay infrastructure if it breaks or if it needs
> improvements.
> 
> I have checked on several recent point releases that check -overlay does not
> regress any tests compared to xfs reflink configuration, and when I
> found a regression
> (mostly in overlayfs code, but also in xfs code sometimes) I reported
> and/or fixed it.
> But I do not have the resources to validate every xfs merge and
> certainly not xfs-next.
> 
> There is a large group of tests that is expected to notrun, which
> makes running the
> -overlay test a lot faster than any given xfs configuration and IMO
> running just a single
> xfs reflink config with -overlay would give a pretty good test coverage.
> 
> So what do you say?...

Frankly I'd rather push the kernelci/0day/lf/whoever folks to kick off
fstests across all the major filesystems after the daily for-next merge
so that we can all see if there are regressions over the previous day's
test.  IOWs, rather than loading ourselves down with more testing
burden, let's make it more public.

I've received occasional reports from the 0day robot, but I'm not sure
if it's testing consistently because it only ever seems to emit
complaints, not "I love your branch and even better nothing regressed!".

That said, this *does* confirm Zorro's earlier point that I should give
him a week to test xfs for-next before pushing to Linus.

Sorry everyone, and especially Zorro & Amir...

--D

> Thanks,
> Amir.

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [4.20-rc4 regression] generic/095 Concurrent mixed I/O hang on xfs based overlayfs
  2018-11-30 18:23     ` Darrick J. Wong
@ 2018-12-01  9:24       ` Amir Goldstein
  0 siblings, 0 replies; 5+ messages in thread
From: Amir Goldstein @ 2018-12-01  9:24 UTC (permalink / raw)
  To: Darrick J. Wong
  Cc: Dave Chinner, jencce.kernel, linux-xfs, overlayfs, Zorro Lang,
	fstests

> > Darrick,
> >
> > This is my cue to insert a rant. You already know what I am going to rant about.
> >
> > I cannot force you to add a check -overlay xfstests run to your pull
> > request validation
> > routine. I can offer assistance in any questions you may have and I can offer
> > support for check -overlay infrastructure if it breaks or if it needs
> > improvements.
> >
> > I have checked on several recent point releases that check -overlay does not
> > regress any tests compared to xfs reflink configuration, and when I
> > found a regression
> > (mostly in overlayfs code, but also in xfs code sometimes) I reported
> > and/or fixed it.
> > But I do not have the resources to validate every xfs merge and
> > certainly not xfs-next.
> >
> > There is a large group of tests that is expected to notrun, which
> > makes running the
> > -overlay test a lot faster than any given xfs configuration and IMO
> > running just a single
> > xfs reflink config with -overlay would give a pretty good test coverage.
> >
> > So what do you say?...
>
> Frankly I'd rather push the kernelci/0day/lf/whoever folks to kick off
> fstests across all the major filesystems after the daily for-next merge
> so that we can all see if there are regressions over the previous day's
> test.  IOWs, rather than loading ourselves down with more testing
> burden, let's make it more public.
>
> I've received occasional reports from the 0day robot, but I'm not sure
> if it's testing consistently because it only ever seems to emit
> complaints, not "I love your branch and even better nothing regressed!".
>

That would indeed be great if we had some more knowledge about
what is being tested by 0day and friends.

Regardless, check -overlay had already found several bugs in XFS code
(I can look it up, but you know what I mean), so I argue that it would be
beneficial to you as XFS maintainer and not only to overlayfs users if
you run check -overlay on pull request branches.
Consider overlayfs as a unit test for some of the XFS VFS interfaces
that are harder (or impossible) to hit from userspace.
Besides, as I said, the cost of running check -overlay on a single reflink
config is relatively cheap, so please consider running it occasionally to be
a head of those type of bugs.

> That said, this *does* confirm Zorro's earlier point that I should give
> him a week to test xfs for-next before pushing to Linus.
>

It looks like between Zorro and yourself, overlayfs+xfs bugs should not
be slipping in to master anymore, so I'm happy with the way things are :-)

Thanks,
Amir.

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2018-12-01 20:36 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2018-11-30  5:12 [4.20-rc4 regression] generic/095 Concurrent mixed I/O hang on xfs based overlayfs Murphy Zhou
2018-11-30 12:15 ` Zorro Lang
2018-11-30 13:30   ` Amir Goldstein
2018-11-30 18:23     ` Darrick J. Wong
2018-12-01  9:24       ` Amir Goldstein

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox