| Message ID | 20191001200551.1513-1-josef@toxicpanda.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | btrfs/194: add a test for multi-subvolume fsyncing | expand |
On Wed, Oct 2, 2019 at 5:29 AM Josef Bacik <josef@toxicpanda.com> wrote: > > From: Josef Bacik <jbacik@fb.com> > > I discovered a problem in btrfs where we'd end up pointing at a block we > hadn't written out yet. This is triggered by a race when two different > files on two different subvolumes fsync. This test exercises this path > with dm-log-writes, and then replays the log at every FUA to verify the > file system is still mountable and the log is replayable. Please mention in the changelog, or in the test's description, the subject of the patch that fixes the problem. Otherwise people running the test and seeing failures will have a hard time figuring things out (think of QA teams for example, or anyone some weeks or months after, where context is lost and mailing list search is not that great). > > Signed-off-by: Josef Bacik <josef@toxicpanda.com> > --- > tests/btrfs/194 | 102 ++++++++++++++++++++++++++++++++++++++++++++ > tests/btrfs/194.out | 2 + > tests/btrfs/group | 1 + > 3 files changed, 105 insertions(+) > create mode 100755 tests/btrfs/194 > create mode 100644 tests/btrfs/194.out > > diff --git a/tests/btrfs/194 b/tests/btrfs/194 > new file mode 100755 > index 00000000..d5edb313 > --- /dev/null > +++ b/tests/btrfs/194 > @@ -0,0 +1,102 @@ > +#! /bin/bash > +# SPDX-License-Identifier: GPL-2.0 > +# Copyright (c) 2019 Facebook. All Rights Reserved. > +# > +# FS QA Test 194 > +# > +# Test multi subvolume fsync to test a bug where we'd end up pointing at a block > +# we haven't written. > +# > +# Will do log replay and check the filesystem. > +# > +seq=`basename $0` > +seqres=$RESULT_DIR/$seq > +echo "QA output created by $seq" > + > +here=`pwd` > +tmp=/tmp/$$ > +fio_config=$tmp.fio This isn't used anywhere. > +status=1 # failure is the default! > +trap "_cleanup; exit \$status" 0 1 2 3 15 > + > +_cleanup() > +{ > + cd / > + $KILLALL_PROG -KILL -q $FSSTRESS_PROG &> /dev/null This line can go away, the test doesn't use fsstress. > + _log_writes_cleanup &> /dev/null > + _dmthin_cleanup > + rm -f $tmp.* > +} > + > +# get standard environment, filters and checks > +. ./common/rc > +. ./common/filter > +. ./common/dmthin > +. ./common/dmlogwrites > + > +# remove previous $seqres.full before test > +rm -f $seqres.full > + > +# real QA test starts here > + > +# Modify as appropriate. > +_supported_fs generic > +_supported_os Linux > + > +# Use thin device as replay device, which requires $SCRATCH_DEV > +_require_scratch_nocheck > +# and we need extra device as log device > +_require_log_writes > +_require_dm_target thin-pool > + > +_require_fio All existing tests I could see, do "_require_fio $fio_config", where $fio_config is not empty. > + > +# Use a thin device to provide deterministic discard behavior. Discards are used > +# by the log replay tool for fast zeroing to prevent out-of-order replay issues. > +_test_unmount > +_dmthin_init $devsize $devsize $csize $lowspace > +_log_writes_init $DMTHIN_VOL_DEV > +_log_writes_mkfs >> $seqres.full 2>&1 > +_log_writes_mark mkfs > + > +_log_writes_mount > + > +# First create all the subvolumes > +for i in $(seq 0 49) > +do The style followed by fstests is "for i in $(seq 0 49); do", just like you did in the while loop below. > + $BTRFS_UTIL_PROG subvolume create "$SCRATCH_MNT/sub$i" > /dev/null > +done > + > +# Then run 100 fio jobs in parallel > +for i in $(seq 0 49) > +do Same here. > + fio --name=seq --readwrite=write --fallocate=none --bs=4k --fsync=1 \ > + --size=64k --filename="$SCRATCH_MNT/sub$i/file" \ > + > /dev/null 2>&1 & fio -> $FIO_PROG And then $FIO_PROG $fio_config, as all other tests using fio do. > +done > +wait > +_log_writes_unmount > + > +_log_writes_remove > +prev=$(_log_writes_mark_to_entry_number mkfs) > +[ -z "$prev" ] && _fail "failed to locate entry mark 'mkfs'" > +cur=$(_log_writes_find_next_fua $prev) > +[ -z "$cur" ] && _fail "failed to locate next FUA write" > + > +while [ ! -z "$cur" ]; do > + _log_writes_replay_log_range $cur $DMTHIN_VOL_DEV >> $seqres.full > + > + # We need to mount the fs because btrfsck won't bother checking the log. > + _dmthin_mount > + _dmthin_check_fs > + > + prev=$cur > + cur=$(_log_writes_find_next_fua $(($cur + 1))) > + [ -z "$cur" ] && break > +done > + > +echo "Silence is golden" > + > +# success, all done > +status=0 > +exit > diff --git a/tests/btrfs/194.out b/tests/btrfs/194.out > new file mode 100644 > index 00000000..7bfd50ff > --- /dev/null > +++ b/tests/btrfs/194.out > @@ -0,0 +1,2 @@ > +QA output created by 194 > +Silence is golden > diff --git a/tests/btrfs/group b/tests/btrfs/group > index b92cb12c..0d0e1bba 100644 > --- a/tests/btrfs/group > +++ b/tests/btrfs/group > @@ -196,3 +196,4 @@ > 191 auto quick send dedupe > 192 auto replay snapshot stress > 193 auto quick qgroup enospc limit > +194 auto metadata log volume Other than that it looks fine to me. However, on a VM with 8Gb of ram, I can't run the test: root 11:09:10 /home/fdmanana/git/hub/xfstests (master)> ./check btrfs/194 FSTYP -- btrfs PLATFORM -- Linux/x86_64 debian5 5.3.0-rc8-btrfs-next-58 #1 SMP Tue Sep 17 18:18:55 WEST 2019 MKFS_OPTIONS -- /dev/sdc MOUNT_OPTIONS -- /dev/sdc /home/fdmanana/btrfs-tests/scratch_1 btrfs/194 [failed, exit status 137]- output mismatch (see /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad) --- tests/btrfs/194.out 2019-10-02 10:51:45.485575789 +0100 +++ /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad 2019-10-02 11:12:11.382533722 +0100 @@ -1,2 +1,2 @@ QA output created by 194 -Silence is golden +./check: line 513: 1324 Killed bash -c "test -w ${OOM_SCORE_ADJ} && echo 250 > ${OOM_SCORE_ADJ}; exec ./$seq" ... (Run 'diff -u /home/fdmanana/git/hub/xfstests/tests/btrfs/194.out /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad' to see the entire diff) Ran: btrfs/194 Failures: btrfs/194 Failed 1 of 1 tests root 11:12:22 /home/fdmanana/git/hub/xfstests (master)> cat /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad QA output created by 194 ./check: line 513: 1324 Killed bash -c "test -w ${OOM_SCORE_ADJ} && echo 250 > ${OOM_SCORE_ADJ}; exec ./$seq" root 11:19:39 /home/fdmanana/git/hub/xfstests (master)> 8Gb is a very reasonable amount of ram. This is on a debug kernel (kmemleak, kasan, debug_pagealloc, etc, enabled). Not uncommon among developers at least (even 4Gb of ram is common). Thanks. > -- > 2.21.0 >
On Wed, Oct 02, 2019 at 11:22:40AM +0100, Filipe Manana wrote: > On Wed, Oct 2, 2019 at 5:29 AM Josef Bacik <josef@toxicpanda.com> wrote: > > > > From: Josef Bacik <jbacik@fb.com> > > > > I discovered a problem in btrfs where we'd end up pointing at a block we > > hadn't written out yet. This is triggered by a race when two different > > files on two different subvolumes fsync. This test exercises this path > > with dm-log-writes, and then replays the log at every FUA to verify the > > file system is still mountable and the log is replayable. > > Please mention in the changelog, or in the test's description, the > subject of the patch that fixes the problem. > Otherwise people running the test and seeing failures will have a hard > time figuring things out (think of QA teams > for example, or anyone some weeks or months after, where context is > lost and mailing list search is not that great). > > > > > Signed-off-by: Josef Bacik <josef@toxicpanda.com> > > --- > > tests/btrfs/194 | 102 ++++++++++++++++++++++++++++++++++++++++++++ > > tests/btrfs/194.out | 2 + > > tests/btrfs/group | 1 + > > 3 files changed, 105 insertions(+) > > create mode 100755 tests/btrfs/194 > > create mode 100644 tests/btrfs/194.out > > > > diff --git a/tests/btrfs/194 b/tests/btrfs/194 > > new file mode 100755 > > index 00000000..d5edb313 > > --- /dev/null > > +++ b/tests/btrfs/194 > > @@ -0,0 +1,102 @@ > > +#! /bin/bash > > +# SPDX-License-Identifier: GPL-2.0 > > +# Copyright (c) 2019 Facebook. All Rights Reserved. > > +# > > +# FS QA Test 194 > > +# > > +# Test multi subvolume fsync to test a bug where we'd end up pointing at a block > > +# we haven't written. > > +# > > +# Will do log replay and check the filesystem. > > +# > > +seq=`basename $0` > > +seqres=$RESULT_DIR/$seq > > +echo "QA output created by $seq" > > + > > +here=`pwd` > > +tmp=/tmp/$$ > > +fio_config=$tmp.fio > > This isn't used anywhere. > > > +status=1 # failure is the default! > > +trap "_cleanup; exit \$status" 0 1 2 3 15 > > + > > +_cleanup() > > +{ > > + cd / > > + $KILLALL_PROG -KILL -q $FSSTRESS_PROG &> /dev/null > > This line can go away, the test doesn't use fsstress. > > > + _log_writes_cleanup &> /dev/null > > + _dmthin_cleanup > > + rm -f $tmp.* > > +} > > + > > +# get standard environment, filters and checks > > +. ./common/rc > > +. ./common/filter > > +. ./common/dmthin > > +. ./common/dmlogwrites > > + > > +# remove previous $seqres.full before test > > +rm -f $seqres.full > > + > > +# real QA test starts here > > + > > +# Modify as appropriate. > > +_supported_fs generic > > +_supported_os Linux > > + > > +# Use thin device as replay device, which requires $SCRATCH_DEV > > +_require_scratch_nocheck > > +# and we need extra device as log device > > +_require_log_writes > > +_require_dm_target thin-pool > > + > > +_require_fio > > All existing tests I could see, do "_require_fio $fio_config", where > $fio_config is not empty. > Yeah you can pass in a config or not, if you don't it just checks to make sure you have fio available. I originally intended to do a config, but just went with the commandline since it's easier to do the individual files and I'm not using any esoteric fio options. <snip> > > Other than that it looks fine to me. > > However, on a VM with 8Gb of ram, I can't run the test: > > root 11:09:10 /home/fdmanana/git/hub/xfstests (master)> ./check btrfs/194 > FSTYP -- btrfs > PLATFORM -- Linux/x86_64 debian5 5.3.0-rc8-btrfs-next-58 #1 SMP > Tue Sep 17 18:18:55 WEST 2019 > MKFS_OPTIONS -- /dev/sdc > MOUNT_OPTIONS -- /dev/sdc /home/fdmanana/btrfs-tests/scratch_1 > > btrfs/194 [failed, exit status 137]- output mismatch (see > /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad) > --- tests/btrfs/194.out 2019-10-02 10:51:45.485575789 +0100 > +++ /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad > 2019-10-02 11:12:11.382533722 +0100 > @@ -1,2 +1,2 @@ > QA output created by 194 > -Silence is golden > +./check: line 513: 1324 Killed bash -c "test -w > ${OOM_SCORE_ADJ} && echo 250 > ${OOM_SCORE_ADJ}; exec ./$seq" > ... > (Run 'diff -u /home/fdmanana/git/hub/xfstests/tests/btrfs/194.out > /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad' to see > the entire diff) > Ran: btrfs/194 > Failures: btrfs/194 > Failed 1 of 1 tests > > root 11:12:22 /home/fdmanana/git/hub/xfstests (master)> cat > /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad > QA output created by 194 > ./check: line 513: 1324 Killed bash -c "test -w > ${OOM_SCORE_ADJ} && echo 250 > ${OOM_SCORE_ADJ}; exec ./$seq" > root 11:19:39 /home/fdmanana/git/hub/xfstests (master)> > > > 8Gb is a very reasonable amount of ram. This is on a debug kernel > (kmemleak, kasan, debug_pagealloc, etc, enabled). Not uncommon among > developers at least (even 4Gb of ram is common). Huh that's weird. Do you know what step of the test OOM'ed? Nothing we're doing here should be using that much memory. Thanks, Josef
On Wed, Oct 2, 2019 at 2:56 PM Josef Bacik <josef@toxicpanda.com> wrote: > > On Wed, Oct 02, 2019 at 11:22:40AM +0100, Filipe Manana wrote: > > On Wed, Oct 2, 2019 at 5:29 AM Josef Bacik <josef@toxicpanda.com> wrote: > > > > > > From: Josef Bacik <jbacik@fb.com> > > > > > > I discovered a problem in btrfs where we'd end up pointing at a block we > > > hadn't written out yet. This is triggered by a race when two different > > > files on two different subvolumes fsync. This test exercises this path > > > with dm-log-writes, and then replays the log at every FUA to verify the > > > file system is still mountable and the log is replayable. > > > > Please mention in the changelog, or in the test's description, the > > subject of the patch that fixes the problem. > > Otherwise people running the test and seeing failures will have a hard > > time figuring things out (think of QA teams > > for example, or anyone some weeks or months after, where context is > > lost and mailing list search is not that great). > > > > > > > > Signed-off-by: Josef Bacik <josef@toxicpanda.com> > > > --- > > > tests/btrfs/194 | 102 ++++++++++++++++++++++++++++++++++++++++++++ > > > tests/btrfs/194.out | 2 + > > > tests/btrfs/group | 1 + > > > 3 files changed, 105 insertions(+) > > > create mode 100755 tests/btrfs/194 > > > create mode 100644 tests/btrfs/194.out > > > > > > diff --git a/tests/btrfs/194 b/tests/btrfs/194 > > > new file mode 100755 > > > index 00000000..d5edb313 > > > --- /dev/null > > > +++ b/tests/btrfs/194 > > > @@ -0,0 +1,102 @@ > > > +#! /bin/bash > > > +# SPDX-License-Identifier: GPL-2.0 > > > +# Copyright (c) 2019 Facebook. All Rights Reserved. > > > +# > > > +# FS QA Test 194 > > > +# > > > +# Test multi subvolume fsync to test a bug where we'd end up pointing at a block > > > +# we haven't written. > > > +# > > > +# Will do log replay and check the filesystem. > > > +# > > > +seq=`basename $0` > > > +seqres=$RESULT_DIR/$seq > > > +echo "QA output created by $seq" > > > + > > > +here=`pwd` > > > +tmp=/tmp/$$ > > > +fio_config=$tmp.fio > > > > This isn't used anywhere. > > > > > +status=1 # failure is the default! > > > +trap "_cleanup; exit \$status" 0 1 2 3 15 > > > + > > > +_cleanup() > > > +{ > > > + cd / > > > + $KILLALL_PROG -KILL -q $FSSTRESS_PROG &> /dev/null > > > > This line can go away, the test doesn't use fsstress. > > > > > + _log_writes_cleanup &> /dev/null > > > + _dmthin_cleanup > > > + rm -f $tmp.* > > > +} > > > + > > > +# get standard environment, filters and checks > > > +. ./common/rc > > > +. ./common/filter > > > +. ./common/dmthin > > > +. ./common/dmlogwrites > > > + > > > +# remove previous $seqres.full before test > > > +rm -f $seqres.full > > > + > > > +# real QA test starts here > > > + > > > +# Modify as appropriate. > > > +_supported_fs generic > > > +_supported_os Linux > > > + > > > +# Use thin device as replay device, which requires $SCRATCH_DEV > > > +_require_scratch_nocheck > > > +# and we need extra device as log device > > > +_require_log_writes > > > +_require_dm_target thin-pool > > > + > > > +_require_fio > > > > All existing tests I could see, do "_require_fio $fio_config", where > > $fio_config is not empty. > > > > Yeah you can pass in a config or not, if you don't it just checks to make sure > you have fio available. I originally intended to do a config, but just went > with the commandline since it's easier to do the individual files and I'm not > using any esoteric fio options. > > <snip> > > > > > Other than that it looks fine to me. > > > > However, on a VM with 8Gb of ram, I can't run the test: > > > > root 11:09:10 /home/fdmanana/git/hub/xfstests (master)> ./check btrfs/194 > > FSTYP -- btrfs > > PLATFORM -- Linux/x86_64 debian5 5.3.0-rc8-btrfs-next-58 #1 SMP > > Tue Sep 17 18:18:55 WEST 2019 > > MKFS_OPTIONS -- /dev/sdc > > MOUNT_OPTIONS -- /dev/sdc /home/fdmanana/btrfs-tests/scratch_1 > > > > btrfs/194 [failed, exit status 137]- output mismatch (see > > /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad) > > --- tests/btrfs/194.out 2019-10-02 10:51:45.485575789 +0100 > > +++ /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad > > 2019-10-02 11:12:11.382533722 +0100 > > @@ -1,2 +1,2 @@ > > QA output created by 194 > > -Silence is golden > > +./check: line 513: 1324 Killed bash -c "test -w > > ${OOM_SCORE_ADJ} && echo 250 > ${OOM_SCORE_ADJ}; exec ./$seq" > > ... > > (Run 'diff -u /home/fdmanana/git/hub/xfstests/tests/btrfs/194.out > > /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad' to see > > the entire diff) > > Ran: btrfs/194 > > Failures: btrfs/194 > > Failed 1 of 1 tests > > > > root 11:12:22 /home/fdmanana/git/hub/xfstests (master)> cat > > /home/fdmanana/git/hub/xfstests/results//btrfs/194.out.bad > > QA output created by 194 > > ./check: line 513: 1324 Killed bash -c "test -w > > ${OOM_SCORE_ADJ} && echo 250 > ${OOM_SCORE_ADJ}; exec ./$seq" > > root 11:19:39 /home/fdmanana/git/hub/xfstests (master)> > > > > > > 8Gb is a very reasonable amount of ram. This is on a debug kernel > > (kmemleak, kasan, debug_pagealloc, etc, enabled). Not uncommon among > > developers at least (even 4Gb of ram is common). > > Huh that's weird. Do you know what step of the test OOM'ed? Nothing we're > doing here should be using that much memory. Thanks, It OOMs when spawning the fio processes (btw, noticed now, the comment mentions 100 process but the loop tries to spawn 50): https://pastebin.com/hDhhNL60 > > Josef
diff --git a/tests/btrfs/194 b/tests/btrfs/194 new file mode 100755 index 00000000..d5edb313 --- /dev/null +++ b/tests/btrfs/194 @@ -0,0 +1,102 @@ +#! /bin/bash +# SPDX-License-Identifier: GPL-2.0 +# Copyright (c) 2019 Facebook. All Rights Reserved. +# +# FS QA Test 194 +# +# Test multi subvolume fsync to test a bug where we'd end up pointing at a block +# we haven't written. +# +# Will do log replay and check the filesystem. +# +seq=`basename $0` +seqres=$RESULT_DIR/$seq +echo "QA output created by $seq" + +here=`pwd` +tmp=/tmp/$$ +fio_config=$tmp.fio +status=1 # failure is the default! +trap "_cleanup; exit \$status" 0 1 2 3 15 + +_cleanup() +{ + cd / + $KILLALL_PROG -KILL -q $FSSTRESS_PROG &> /dev/null + _log_writes_cleanup &> /dev/null + _dmthin_cleanup + rm -f $tmp.* +} + +# get standard environment, filters and checks +. ./common/rc +. ./common/filter +. ./common/dmthin +. ./common/dmlogwrites + +# remove previous $seqres.full before test +rm -f $seqres.full + +# real QA test starts here + +# Modify as appropriate. +_supported_fs generic +_supported_os Linux + +# Use thin device as replay device, which requires $SCRATCH_DEV +_require_scratch_nocheck +# and we need extra device as log device +_require_log_writes +_require_dm_target thin-pool + +_require_fio + +# Use a thin device to provide deterministic discard behavior. Discards are used +# by the log replay tool for fast zeroing to prevent out-of-order replay issues. +_test_unmount +_dmthin_init $devsize $devsize $csize $lowspace +_log_writes_init $DMTHIN_VOL_DEV +_log_writes_mkfs >> $seqres.full 2>&1 +_log_writes_mark mkfs + +_log_writes_mount + +# First create all the subvolumes +for i in $(seq 0 49) +do + $BTRFS_UTIL_PROG subvolume create "$SCRATCH_MNT/sub$i" > /dev/null +done + +# Then run 100 fio jobs in parallel +for i in $(seq 0 49) +do + fio --name=seq --readwrite=write --fallocate=none --bs=4k --fsync=1 \ + --size=64k --filename="$SCRATCH_MNT/sub$i/file" \ + > /dev/null 2>&1 & +done +wait +_log_writes_unmount + +_log_writes_remove +prev=$(_log_writes_mark_to_entry_number mkfs) +[ -z "$prev" ] && _fail "failed to locate entry mark 'mkfs'" +cur=$(_log_writes_find_next_fua $prev) +[ -z "$cur" ] && _fail "failed to locate next FUA write" + +while [ ! -z "$cur" ]; do + _log_writes_replay_log_range $cur $DMTHIN_VOL_DEV >> $seqres.full + + # We need to mount the fs because btrfsck won't bother checking the log. + _dmthin_mount + _dmthin_check_fs + + prev=$cur + cur=$(_log_writes_find_next_fua $(($cur + 1))) + [ -z "$cur" ] && break +done + +echo "Silence is golden" + +# success, all done +status=0 +exit diff --git a/tests/btrfs/194.out b/tests/btrfs/194.out new file mode 100644 index 00000000..7bfd50ff --- /dev/null +++ b/tests/btrfs/194.out @@ -0,0 +1,2 @@ +QA output created by 194 +Silence is golden diff --git a/tests/btrfs/group b/tests/btrfs/group index b92cb12c..0d0e1bba 100644 --- a/tests/btrfs/group +++ b/tests/btrfs/group @@ -196,3 +196,4 @@ 191 auto quick send dedupe 192 auto replay snapshot stress 193 auto quick qgroup enospc limit +194 auto metadata log volume