fstests: log-writes: Add support to output human readable flags
PATCH 1/3 fstests: log-writes: Add support to output human readable flags
Also change the flag numeric output to hex.
--- src/log-writes/log-writes.c | 70 ++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 63 insertions(+), 7 deletions(-)
src/log-writes/log-writes.c +63 -7
@@ -120,6 +120,58 @@ int log_discard(struct log *log, struct log_write_entry *entry)return 0 ; } +#define DEFINE_LOG_FLAGS_STR_ENTRY (x) \ + {LOG_##x##_FLAG, #x} + +struct flags_to_str_entry { +u64 flags; +const char *str; +} log_flags_table[] = { +DEFINE_LOG_FLAGS_STR_ENTRY (FLUSH ), +DEFINE_LOG_FLAGS_STR_ENTRY (FUA ), +DEFINE_LOG_FLAGS_STR_ENTRY (DISCARD ), +DEFINE_LOG_FLAGS_STR_ENTRY (MARK ) +}; + +#define ARRAY_SIZE (x) (sizeof(x) / sizeof((x)[0])) +#define LOG_FLAGS_BUF_SIZE 128 +/* +* Convert numeric flags to human readable flags. +* @flags: numeric flags +* @buf: output buffer for human readable string. +* must have enough space (LOG_FLAGS_BUF_SIZE) to contain all +* the string +*/ +static void entry_flags_to_str (u64 flags,char *buf) +{ +int empty =1 ; +int left_len; +int i; + + buf[0 ] ='\0' ; +for (i =0 ; i <ARRAY_SIZE (log_flags_table); i++) { +if (flags & log_flags_table[i].flags) { +if (!empty) +strncat (buf,"|" ,LOG_FLAGS_BUF_SIZE ); + empty =0 ; +strncat (buf, log_flags_table[i].str,LOG_FLAGS_BUF_SIZE ); + flags &= ~log_flags_table[i].flags; + } + } +if (flags) { +if (!empty) +strncat (buf,"|" ,LOG_FLAGS_BUF_SIZE ); + empty =0 ; + left_len =LOG_FLAGS_BUF_SIZE -strnlen (buf, +LOG_FLAGS_BUF_SIZE ); +if (left_len >0 ) +snprintf (buf +strnlen (buf,LOG_FLAGS_BUF_SIZE ), + left_len,"UNKNOWN.%llu" , flags); + } +if (empty) +strncpy (buf,"NONE" ,LOG_FLAGS_BUF_SIZE ); +} +/* * @log: the log we are replaying. * @entry: entry to be replayed.
@@ -179,6 +231,7 @@ int log_replay_next_entry(struct log *log, struct log_write_entry *entry,size_t read_size = read_data ? log->sectorsize :sizeof (struct log_write_entry );char *buf; +char flags_buf[LOG_FLAGS_BUF_SIZE ];ssize_t ret;off_t offset;int skip =0 ;
@@ -210,19 +263,20 @@ int log_replay_next_entry(struct log *log, struct log_write_entry *entry, log->cur_pos += read_size; } + flags =le64_to_cpu (entry->flags); +entry_flags_to_str (flags, flags_buf); skip =log_should_skip (log, entry);if (log_writes_verbose >1 || (log_writes_verbose && !skip)) { -printf ("%s %d@%llu: sector %llu, size %llu, flags %llu\n" , +printf ("%s %d@%llu: sector %llu, size %llu, flags 0x%llx(%s)\n" , skip ?"skipping" :"replaying" , (int )log->cur_entry -1 , log->cur_pos / log->sectorsize, (unsigned long long )le64_to_cpu (entry->sector), (unsigned long long )size, - (unsigned long long )le64_to_cpu (entry->flags)); + (unsigned long long )flags, flags_buf); }if (!size)return 0 ; - flags =le64_to_cpu (entry->flags);if (flags &LOG_DISCARD_FLAG )return log_discard (log, entry);
@@ -301,7 +355,7 @@ int log_seek_entry(struct log *log, u64 entry_num)return -1 ; }if (log_writes_verbose >1 ) - printf("seek entry %d@%llu: %llu, size %llu, flags %llu\n", + printf("seek entry %d@%llu: %llu, size %llu, flags 0x%llx\n", (int)i, log->cur_pos / log->sectorsize, (unsigned long long)le64_to_cpu(entry.sector), (unsigned long long)le64_to_cpu(entry.nr_sectors),
@@ -339,6 +393,7 @@ int log_seek_next_entry(struct log *log, struct log_write_entry *entry,size_t read_size = read_data ? log->sectorsize :sizeof (struct log_write_entry );u64 flags; +char flags_buf[LOG_FLAGS_BUF_SIZE ];ssize_t ret;if (log->cur_entry >= log->nr_entries)
@@ -366,14 +421,15 @@ int log_seek_next_entry(struct log *log, struct log_write_entry *entry, }else { log->cur_pos += read_size; } + flags =le64_to_cpu (entry->flags); +entry_flags_to_str (flags, flags_buf);if (log_writes_verbose >1 ) -printf ("seek entry %d@%llu: %llu, size %llu, flags %llu\n" , +printf ("seek entry %d@%llu: %llu, size %llu, flags 0x%llx(%s)\n" , (int )log->cur_entry -1 , log->cur_pos / log->sectorsize, (unsigned long long )le64_to_cpu (entry->sector), (unsigned long long )le64_to_cpu (entry->nr_sectors), - (unsigned long long )le64_to_cpu (entry->flags)); + (unsigned long long )flags, flags_buf); - flags =le64_to_cpu (entry->flags); read_size =le64_to_cpu (entry->nr_sectors) * log->sectorsize;if (!read_size || (flags &LOG_DISCARD_FLAG ))return 0 ;
Signature · 1 line
2.15.1
PATCH 2/3 fstests: log-writes: Add support for METADATA flag
--- src/log-writes/log-writes.c | 3 ++- src/log-writes/log-writes.h | 9 +++++---- 2 files changed, 7 insertions(+), 5 deletions(-)
src/log-writes/log-writes.c +2 -1
@@ -130,7 +130,8 @@ struct flags_to_str_entry {DEFINE_LOG_FLAGS_STR_ENTRY (FLUSH ),DEFINE_LOG_FLAGS_STR_ENTRY (FUA ),DEFINE_LOG_FLAGS_STR_ENTRY (DISCARD ), - DEFINE_LOG_FLAGS_STR_ENTRY(MARK) +DEFINE_LOG_FLAGS_STR_ENTRY (MARK ), + DEFINE_LOG_FLAGS_STR_ENTRY(METADATA) };#define ARRAY_SIZE (x) (sizeof(x) / sizeof((x)[0]))
src/log-writes/log-writes.h +5 -4
@@ -20,10 +20,11 @@ typedef __u32 u32;/* * Constants copied from kernel file drivers/md/dm-log-writes.c */ -#define LOG_FLUSH_FLAG (1 << 0) -#define LOG_FUA_FLAG (1 << 1) -#define LOG_DISCARD_FLAG (1 << 2) -#define LOG_MARK_FLAG (1 << 3) +#define LOG_FLUSH_FLAG (1 << 0) +#define LOG_FUA_FLAG (1 << 1) +#define LOG_DISCARD_FLAG (1 << 2) +#define LOG_MARK_FLAG (1 << 3) +#define LOG_METADATA_FLAG (1 << 4)#define WRITE_LOG_VERSION 1#define WRITE_LOG_MAGIC 0x6a736677736872
Signature · 1 line
2.15.1
PATCH 3/3 fstests: btrfs: Add test case to check v1 space cache corruption
In reply to Qu WenruoThere are some btrfs corruption report in mail list for a while, although such corruption is pretty rare and almost impossible to reproduce, with dm-log-writes we found it's highly related to v1 space cache.
Unlike journal based filesystems, btrfs completely rely on metadata CoW to protect itself from power loss.
Which needs extent allocator to avoid allocate extents on existing extent range.
Btrfs also uses free space cache to speed up such allocation.
However there is a problem, v1 space cache is not protected by data CoW, and can be corrupted during power loss.
So btrfs do extra check on free space cache, verifying its own in-file csum, generation and free space recorded in cache and extent tree.
The problem is, under heavy concurrency, v1 space cache can be corrupted even under normal operations without power loss.
And we believe corrupted space cache can break btrfs metadata CoW and leads to the rare corruption in next power loss.
The most obvious symptom will be difference in free space:
This will be caught by kernel, but such check is quite weak, and if the net free space change is 0 in one transaction, the corrupted cache can be loaded by kernel.
In this case, btrfs check would report things like :
------
block group 298844160 has wrong amount of free space failed to load free space cache for block group 298844160
------
But considering the test case are using notreelog, btrfs won't do sub-transaction commit which doesn't increase generation, each transaction should be consistent, and nothing should be reported at all.
Further more, we can even found corrupted file extents like:
------
root 5 inode 261 errors 100, file extent discount Found file extent holes:
start: 962560, len: 32768
ERROR: errors found in fs roots
------
--- common/dmlogwrites | 72 +++++++++++++++++++++++++++ tests/btrfs/159 | 141 ++++++++++++++++++++++++++++++++++++++++++++++++++++ tests/btrfs/159.out | 2 + tests/btrfs/group | 1 + 4 files changed, 216 insertions(+) create mode 100755 tests/btrfs/159 create mode 100644 tests/btrfs/159.out
common/dmlogwrites +72 -0
@@ -126,3 +126,75 @@ _log_writes_cleanup() $UDEV_SETTLE_PROG >/dev/null 2>&1 _log_writes_remove } + +# Convert log writes mark to entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_mark_to_entry_number() +{ + local _mark=$1 + local ret + + [ -z "$_mark" ] && _fail \ + "mark must be given for _log_writes_mark_to_entry_number" + + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --end-mark $_mark 2> /dev/null) + [ -z "$ret" ] && return + ret=$(echo "$ret" | cut -f1 -d\@) + echo "mark $_mark has entry number $ret" >> $seqres.full + echo "$ret" +} + +# Find next fua write entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_find_next_fua() +{ + local _start_entry=$1 + local ret + + if [ -z "$_start_entry" ]; then + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua 2> /dev/null) + else + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua --start-entry $_start_entry 2> /dev/null) + fi + [ -z "$ret" ] && return + + ret=$(echo "$ret" | cut -f1 -d\@) + echo "next fua is entry number $ret" >> $seqres.full + echo "$ret" +} + +# Replay log range to specified entry +# $1: End entry. The last entry will *NOT* be replayed +# $2: Start entry. If not specified, start from the first entry. +_log_writes_replay_log_entry_range() +{ + local _end=$1 + local _start=$2 + + [ -z "$_end" ] && _fail \ + "end entry must be specified for _log_writes_replay_log_entry_range" + + if [[ "$_start" && "$_start" -gt "$_end" ]]; then + _fail \ + "wrong parameter order for _log_writes_replay_log_entry_range:start=$_start end=$_end" + fi + + # Original replay-log won't replay the last entry. So increase entry + # number here to ensure the end entry to be replayed + if [ -z "$_start" ]; then + echo "=== replay to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --limit $_end -v \ + >> $seqres.full 2>&1 + else + echo "=== replay from $_start to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --start-entry $_start \ + --limit $(($_end - $_start)) -v \ + >> $seqres.full 2>&1 + fi + [ $? -ne 0 ] && _fail "replay failed" +}
tests/btrfs/159 new file +141 -0
141 lines not on this page · raw message
tests/btrfs/159.out new file +2 -0
@@ -0,0 +1,2 @@ +QA output created by 159 +Silence is golden
tests/btrfs/group +1 -0
@@ -161,3 +161,4 @@ 156 auto quick trim 157 auto quick raid 158 auto quick raid scrub +159 auto
Signature · 1 line
2.15.1
Re: [PATCH 3/3] fstests: btrfs: Add test case to check v1 space cache corruption
Quoted 37 lines · Qu Wenruo
There are some btrfs corruption report in mail list for a while, although such corruption is pretty rare and almost impossible to reproduce, with dm-log-writes we found it's highly related to v1 space cache.
Unlike journal based filesystems, btrfs completely rely on metadata CoW to protect itself from power loss.
Which needs extent allocator to avoid allocate extents on existing extent range.
Btrfs also uses free space cache to speed up such allocation.However there is a problem, v1 space cache is not protected by data CoW, and can be corrupted during power loss.
So btrfs do extra check on free space cache, verifying its own in-file csum, generation and free space recorded in cache and extent tree.The problem is, under heavy concurrency, v1 space cache can be corrupted even under normal operations without power loss.
And we believe corrupted space cache can break btrfs metadata CoW and leads to the rare corruption in next power loss.The most obvious symptom will be difference in free space:
This will be caught by kernel, but such check is quite weak, and if the net free space change is 0 in one transaction, the corrupted cache can be loaded by kernel.
In this case, btrfs check would report things like :
------
block group 298844160 has wrong amount of free space failed to load free space cache for block group 298844160
------But considering the test case are using notreelog, btrfs won't do sub-transaction commit which doesn't increase generation, each transaction should be consistent, and nothing should be reported at all.
Quoted 8 lines
Further more, we can even found corrupted file extents like:
------
root 5 inode 261 errors 100, file extent discount Found file extent holes:start: 962560, len: 32768ERROR: errors found in fs roots
------
So what is the expectation from this test on upstream btrfs? Probable failure? reliable failure?
Are there random seeds to fsstress that can make the test fail reliably? Or does failure also depend on IO timing and other uncontrolled parameters?
Quoted 102 lines
Signed-off-by Qu Wenruo <[email protected]>--- common/dmlogwrites | 72 +++++++++++++++++++++++++++ tests/btrfs/159 | 141 ++++++++++++++++++++++++++++++++++++++++++++++++++++ tests/btrfs/159.out | 2 + tests/btrfs/group | 1 + 4 files changed, 216 insertions(+) create mode 100755 tests/btrfs/159 create mode 100644 tests/btrfs/159.outcommon/dmlogwrites +72
-0@@ -126,3 +126,75 @@ _log_writes_cleanup() $UDEV_SETTLE_PROG >/dev/null 2>&1 _log_writes_remove } + +# Convert log writes mark to entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_mark_to_entry_number() +{ + local _mark=$1 + local ret + + [ -z "$_mark" ] && _fail \ + "mark must be given for _log_writes_mark_to_entry_number" + + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --end-mark $_mark 2> /dev/null) + [ -z "$ret" ] && return + ret=$(echo "$ret" | cut -f1 -d\@) + echo "mark $_mark has entry number $ret" >> $seqres.full + echo "$ret" +} + +# Find next fua write entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_find_next_fua() +{ + local _start_entry=$1 + local ret + + if [ -z "$_start_entry" ]; then + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua 2> /dev/null) + else + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua --start-entry $_start_entry 2> /dev/null) + fi + [ -z "$ret" ] && return + + ret=$(echo "$ret" | cut -f1 -d\@) + echo "next fua is entry number $ret" >> $seqres.full + echo "$ret" +} + +# Replay log range to specified entry +# $1: End entry. The last entry will *NOT* be replayed +# $2: Start entry. If not specified, start from the first entry. +_log_writes_replay_log_entry_range() +{ + local _end=$1 + local _start=$2 + + [ -z "$_end" ] && _fail \ + "end entry must be specified for _log_writes_replay_log_entry_range" + + if [[ "$_start" && "$_start" -gt "$_end" ]]; then + _fail \ + "wrong parameter order for _log_writes_replay_log_entry_range:start=$_start end=$_end" + fi + + # Original replay-log won't replay the last entry. So increase entry + # number here to ensure the end entry to be replayed + if [ -z "$_start" ]; then + echo "=== replay to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --limit $_end -v \ + >> $seqres.full 2>&1 + else + echo "=== replay from $_start to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --start-entry $_start \ + --limit $(($_end - $_start)) -v \ + >> $seqres.full 2>&1 + fi + [ $? -ne 0 ] && _fail "replay failed" +}tests/btrfs/159 new file +6
-0@@ -0,0 +1,141 @@ +#! /bin/bash +# FS QA Test 159 +# +# Test case for btrfs v1 space cache corruption +# +# Btrfs has some unexpected corruption after power loss, during the
tests/btrfs/159 line 16
Quoted 10 lines
tests/btrfs/159 new file +10
-0+# investigation, the problem leads to v1 space cache corruption, which +# could be loaded by kernel without detection. +# +# Kernel has 3 detection for corrupted space cache, checksum, generation +# and free space, however the last one is a weak one. If in the one transaction +# no net space change it can be loaded by kernel and break up metadata CoW, +# leading serious corruption. +# +#----------------------------------------------------------------------- +# Copyright (c) SUSE. All Rights Reserved.
2018
Quoted 86 lines
tests/btrfs/159 new file +86
-0+# +# This program is free software; you can redistribute it and/or +# modify it under the terms of the GNU General Public License as +# published by the Free Software Foundation. +# +# This program is distributed in the hope that it would be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write the Free Software Foundation, +# Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +#----------------------------------------------------------------------- +# + +seq=`basename $0` +seqres=$RESULT_DIR/$seq +echo "QA output created by $seq" + +here=`pwd` +tmp=/tmp/$$ +status=1 # failure is the default! +trap "_cleanup; exit \$status" 0 1 2 3 15 + +_cleanup() +{ + cd / + rm -f $tmp.* + _log_writes_cleanup +} + +# get standard environment, filters and checks +. ./common/rc +. ./common/dmlogwrites +. ./common/filter + +# remove previous $seqres.full before test +rm -f $seqres.full + +# Small workload is enough to trigger the problem +workload=$(( 512 * $LOAD_FACTOR )) +nr_threads=$(($($here/src/feature -o) * $LOAD_FACTOR)) + +# Modify as appropriate. +_supported_fs btrfs +_supported_os Linux +_require_log_writes +_require_scratch + +_log_writes_init +_log_writes_mkfs >> $seqres.full 2>&1 + +# Here we don't want to create space cache yet +_log_writes_mount -o nospace_cache + +# The SINGLE profile data chunk created by mkfs is too small (8M) so btrfs +# won't create space cache for it. +# We need a data chunk large enough so btrfs create space cache for it and +# store the cache in itself. +_run_btrfs_util_prog balance start --full-balance "$SCRATCH_MNT" + +_log_writes_unmount +_log_writes_mark mkfs + +# Disable tree log, so btrfs will always do full transaction commit +# It's OK to use tree log, but it will cause extra super block update which +# doesn't increase generation. +_log_writes_mount -o space_cache=v1,notreelog +run_check $FSSTRESS_PROG -w -n $workload -p $nr_threads -d $SCRATCH_MNT \ + $FSSTRESS_AVOID > /dev/null 2>&1 +_log_writes_unmount + +_log_writes_remove +# Here we manually iterate through the log entries, as we need extra check +# on the output of btrfs check. And we could have detailed replay log in +# $seqres.full +prev=$(_log_writes_mark_to_entry_number mkfs) +if [ -z "$prev" ]; then + _fail "failed to locate log writes mark 'mkfs'" +fi + +# Here we only checks the result *AFTER* FUA writes, and no tree log, so +# everything should be valid. +cur=$(_log_writes_find_next_fua $prev) +[ -z "$cur" ] && _fail "failed to locate next fua write"
tests/btrfs/159 line 112
Quoted 10 lines
tests/btrfs/159 new file +10
-0+ +# log-replay will not replay the last item, so manually increase it by one +cur=$(($cur + 1)) + +_log_writes_replay_log_entry_range $prev >> $seqres.full 2>&1 +while [ ! -z "$cur" ]; do + _log_writes_replay_log_entry_range $cur $prev + # Catch the btrfs check output into temp file, as we need to + # grep the output to find the cache corruption + $BTRFS_UTIL_PROG check --check-data-csum $SCRATCH_DEV &> $tmp.fsck
So by making this a btrfs specific test you avoid the need to mount/umount and revert to $prev. Right?
Please spell out the missing pieces for making a generic variant to this test, so if anyone wants to pick it up they have a good starting point. Or maybe you still intend to post a generic test as well?
Quoted 42 lines
tests/btrfs/159 new file +29
-0+ + # Cache passed generation,csum and free space check but corrupted + # will be reported as error + if [ $? -ne 0 ]; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found corruption" + fi + + # Mount option has ruled out any possible factors affect space cache + # And we are at the FUA writes, no generation related problem should + # happen anyway + if grep -q -e 'failed to load free space cache' $tmp.fsck; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found invalid space cache" + fi + + prev=$cur + cur=$(_log_writes_find_next_fua $prev) + [ -z $cur ] && break + + # Same as above + cur=$(($cur + 1)) +done + +echo "Silence is golden" + +# success, all done +status=0 +exittests/btrfs/159.out new file +2
-0@@ -0,0 +1,2 @@ +QA output created by 159 +Silence is goldentests/btrfs/group +0
-0
tests/btrfs/group line 164
Quoted 4 lines
tests/btrfs/group +1
-0@@ -161,3 +161,4 @@ 156 auto quick trim 157 auto quick raid 158 auto quick raid scrub +159 auto
Please add to "replay" group.
How long does the test run? Is it not quick?
Thanks,
Amir.
Re: [PATCH 3/3] fstests: btrfs: Add test case to check v1 space cache corruption
Quoted 47 lines · Amir Goldstein
Quoted 37 lines · Qu Wenruo
There are some btrfs corruption report in mail list for a while, although such corruption is pretty rare and almost impossible to reproduce, with dm-log-writes we found it's highly related to v1 space cache.
Unlike journal based filesystems, btrfs completely rely on metadata CoW to protect itself from power loss.
Which needs extent allocator to avoid allocate extents on existing extent range.
Btrfs also uses free space cache to speed up such allocation.However there is a problem, v1 space cache is not protected by data CoW, and can be corrupted during power loss.
So btrfs do extra check on free space cache, verifying its own in-file csum, generation and free space recorded in cache and extent tree.The problem is, under heavy concurrency, v1 space cache can be corrupted even under normal operations without power loss.
And we believe corrupted space cache can break btrfs metadata CoW and leads to the rare corruption in next power loss.The most obvious symptom will be difference in free space:
This will be caught by kernel, but such check is quite weak, and if the net free space change is 0 in one transaction, the corrupted cache can be loaded by kernel.
In this case, btrfs check would report things like :
------
block group 298844160 has wrong amount of free space failed to load free space cache for block group 298844160
------But considering the test case are using notreelog, btrfs won't do sub-transaction commit which doesn't increase generation, each transaction should be consistent, and nothing should be reported at all.
Quoted 8 lines
Further more, we can even found corrupted file extents like:
------
root 5 inode 261 errors 100, file extent discount Found file extent holes:start: 962560, len: 32768ERROR: errors found in fs roots
------
Quoted 2 lines
So what is the expectation from this test on upstream btrfs? Probable failure? reliable failure?
Reliable failure, as the root reason is not fully exposed yet.
Quoted 1 line
Are there random seeds to fsstress that can make the test fail reliably?
Since concurrency is involved, I don't think seed would help much.
Quoted 1 line
Or does failure also depend on IO timing and other uncontrolled parameters?
Currently the concurrency would be the main factor.
Quoted 6 lines
tests/btrfs/159 line 16
Quoted 3 lines
tests/btrfs/159 new file +3
-0+# +#----------------------------------------------------------------------- +# Copyright (c) SUSE. All Rights Reserved.2018>
Quoted 1 line
+#
[snip]
Quoted 10 lines
tests/btrfs/159 line 112
Quoted 7 lines
tests/btrfs/159 new file +7
-0+ +_log_writes_replay_log_entry_range $prev >> $seqres.full 2>&1 +while [ ! -z "$cur" ]; do + _log_writes_replay_log_entry_range $cur $prev + # Catch the btrfs check output into temp file, as we need to + # grep the output to find the cache corruption + $BTRFS_UTIL_PROG check --check-data-csum $SCRATCH_DEV &> $tmp.fsckSo by making this a btrfs specific test you avoid the need to mount/umount and revert to $prev. Right?
Yes. Especially notreelog mount option disables journal-like behavior.
Quoted 4 lines
Please spell out the missing pieces for making a generic variant to this test, so if anyone wants to pick it up they have a good starting point. Or maybe you still intend to post a generic test as well?
I'm still working on the generic test, but the priority is the btrfs corruption fixing.
For the missing pieces, we need dm-snapshot to make journal based filesystems to replay their log without polluting the original device.
Despite that, current code should illustrate the framework.
Quoted 50 lines
Quoted 43 lines
tests/btrfs/159 new file +29
-0+ + # Cache passed generation,csum and free space check but corrupted + # will be reported as error + if [ $? -ne 0 ]; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found corruption" + fi + + # Mount option has ruled out any possible factors affect space cache + # And we are at the FUA writes, no generation related problem should + # happen anyway + if grep -q -e 'failed to load free space cache' $tmp.fsck; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found invalid space cache" + fi + + prev=$cur + cur=$(_log_writes_find_next_fua $prev) + [ -z $cur ] && break + + # Same as above + cur=$(($cur + 1)) +done + +echo "Silence is golden" + +# success, all done +status=0 +exittests/btrfs/159.out new file +2
-0@@ -0,0 +1,2 @@ +QA output created by 159 +Silence is goldentests/btrfs/group +0
-0tests/btrfs/group line 164
Quoted 4 lines
tests/btrfs/group +1
-0@@ -161,3 +161,4 @@ 156 auto quick trim 157 auto quick raid 158 auto quick raid scrub +159 autoPlease add to "replay" group.
Quoted 1 line
How long does the test run? Is it not quick?
It's quick, less than one minute.
But since it's using LOAD_FACTOR, fast doesn't seem proper here.
Thanks,
Qu
Quoted 8 lines
Thanks,
Amir.
--
To unsubscribe from this list: send the line "unsubscribe fstests" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 3/3] fstests: btrfs: Add test case to check v1 space cache corruption
In reply to Qu WenruoQuoted 1 line · Qu Wenruo
There are some btrfs corruption report in mail list for a while,
There have been for years (well, since ever) many reports of different types of corruptions.
Which kind of corruption are you referring to?
Quoted 10 lines
although such corruption is pretty rare and almost impossible to reproduce, with dm-log-writes we found it's highly related to v1 space cache.
Unlike journal based filesystems, btrfs completely rely on metadata CoW to protect itself from power loss.
Which needs extent allocator to avoid allocate extents on existing extent range.
Btrfs also uses free space cache to speed up such allocation.
Quoted 7 lines
However there is a problem, v1 space cache is not protected by data CoW, and can be corrupted during power loss.
So btrfs do extra check on free space cache, verifying its own in-file csum, generation and free space recorded in cache and extent tree.The problem is, under heavy concurrency, v1 space cache can be corrupted even under normal operations without power loss.
How?
Quoted 2 lines
And we believe corrupted space cache can break btrfs metadata CoW and leads to the rare corruption in next power loss.
Which kind of corruption?
Quoted 6 lines
The most obvious symptom will be difference in free space:
This will be caught by kernel, but such check is quite weak, and if the net free space change is 0 in one transaction, the corrupted cache can be loaded by kernel.
How can that happen? The only case I'm aware of, explained below, always leads to a difference (space cache has less free space then what we actually have if we check the extent tree).
Quoted 6 lines
In this case, btrfs check would report things like :
------
block group 298844160 has wrong amount of free space failed to load free space cache for block group 298844160
------
This is normal, but not very common, due to tiny races that exists between committing a transaction (writing the free space caches) and running dellaloc for example (since reserving an extent while running dealloc doesn't joing/start a transaction).
Quoted 11 lines
But considering the test case are using notreelog, btrfs won't do sub-transaction commit which doesn't increase generation, each transaction should be consistent, and nothing should be reported at all.
Further more, we can even found corrupted file extents like:
------
root 5 inode 261 errors 100, file extent discount Found file extent holes:start: 962560, len: 32768ERROR: errors found in fs roots
Why do you think that's a corruption? Does it cause data loss or any user visible issue?
Having file extent holes not inserted happens when mixing buffered and direct IO writes to a file (and fsstress does that), for example:
create file
buffered write at offset 0, length 64K
direct IO write at offset at offset 64K, length 4K transaction commit
power loss
after this we got a missing 64K hole extent at offset 0 (at btrfs_file_write_iter we only add hole extents if the start offset is greater then the current i_size)
But this does not cause any problem for the user or the fs itself, and it's supposed to be like that in the NO_HOLES mode which one day (probably) will be the default mode.
Quoted 263 lines
------
Signed-off-by Qu Wenruo <[email protected]>--- common/dmlogwrites | 72 +++++++++++++++++++++++++++ tests/btrfs/159 | 141 ++++++++++++++++++++++++++++++++++++++++++++++++++++ tests/btrfs/159.out | 2 + tests/btrfs/group | 1 + 4 files changed, 216 insertions(+) create mode 100755 tests/btrfs/159 create mode 100644 tests/btrfs/159.outcommon/dmlogwrites +72
-0@@ -126,3 +126,75 @@ _log_writes_cleanup() $UDEV_SETTLE_PROG >/dev/null 2>&1 _log_writes_remove } + +# Convert log writes mark to entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_mark_to_entry_number() +{ + local _mark=$1 + local ret + + [ -z "$_mark" ] && _fail \ + "mark must be given for _log_writes_mark_to_entry_number" + + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --end-mark $_mark 2> /dev/null) + [ -z "$ret" ] && return + ret=$(echo "$ret" | cut -f1 -d\@) + echo "mark $_mark has entry number $ret" >> $seqres.full + echo "$ret" +} + +# Find next fua write entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_find_next_fua() +{ + local _start_entry=$1 + local ret + + if [ -z "$_start_entry" ]; then + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua 2> /dev/null) + else + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua --start-entry $_start_entry 2> /dev/null) + fi + [ -z "$ret" ] && return + + ret=$(echo "$ret" | cut -f1 -d\@) + echo "next fua is entry number $ret" >> $seqres.full + echo "$ret" +} + +# Replay log range to specified entry +# $1: End entry. The last entry will *NOT* be replayed +# $2: Start entry. If not specified, start from the first entry. +_log_writes_replay_log_entry_range() +{ + local _end=$1 + local _start=$2 + + [ -z "$_end" ] && _fail \ + "end entry must be specified for _log_writes_replay_log_entry_range" + + if [[ "$_start" && "$_start" -gt "$_end" ]]; then + _fail \ + "wrong parameter order for _log_writes_replay_log_entry_range:start=$_start end=$_end" + fi + + # Original replay-log won't replay the last entry. So increase entry + # number here to ensure the end entry to be replayed + if [ -z "$_start" ]; then + echo "=== replay to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --limit $_end -v \ + >> $seqres.full 2>&1 + else + echo "=== replay from $_start to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --start-entry $_start \ + --limit $(($_end - $_start)) -v \ + >> $seqres.full 2>&1 + fi + [ $? -ne 0 ] && _fail "replay failed" +}tests/btrfs/159 new file +141
-0@@ -0,0 +1,141 @@ +#! /bin/bash +# FS QA Test 159 +# +# Test case for btrfs v1 space cache corruption +# +# Btrfs has some unexpected corruption after power loss, during the +# investigation, the problem leads to v1 space cache corruption, which +# could be loaded by kernel without detection. +# +# Kernel has 3 detection for corrupted space cache, checksum, generation +# and free space, however the last one is a weak one. If in the one transaction +# no net space change it can be loaded by kernel and break up metadata CoW, +# leading serious corruption. +# +#----------------------------------------------------------------------- +# Copyright (c) SUSE. All Rights Reserved. +# +# This program is free software; you can redistribute it and/or +# modify it under the terms of the GNU General Public License as +# published by the Free Software Foundation. +# +# This program is distributed in the hope that it would be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write the Free Software Foundation, +# Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +#----------------------------------------------------------------------- +# + +seq=`basename $0` +seqres=$RESULT_DIR/$seq +echo "QA output created by $seq" + +here=`pwd` +tmp=/tmp/$$ +status=1 # failure is the default! +trap "_cleanup; exit \$status" 0 1 2 3 15 + +_cleanup() +{ + cd / + rm -f $tmp.* + _log_writes_cleanup +} + +# get standard environment, filters and checks +. ./common/rc +. ./common/dmlogwrites +. ./common/filter + +# remove previous $seqres.full before test +rm -f $seqres.full + +# Small workload is enough to trigger the problem +workload=$(( 512 * $LOAD_FACTOR )) +nr_threads=$(($($here/src/feature -o) * $LOAD_FACTOR)) + +# Modify as appropriate. +_supported_fs btrfs +_supported_os Linux +_require_log_writes +_require_scratch + +_log_writes_init +_log_writes_mkfs >> $seqres.full 2>&1 + +# Here we don't want to create space cache yet +_log_writes_mount -o nospace_cache + +# The SINGLE profile data chunk created by mkfs is too small (8M) so btrfs +# won't create space cache for it. +# We need a data chunk large enough so btrfs create space cache for it and +# store the cache in itself. +_run_btrfs_util_prog balance start --full-balance "$SCRATCH_MNT" + +_log_writes_unmount +_log_writes_mark mkfs + +# Disable tree log, so btrfs will always do full transaction commit +# It's OK to use tree log, but it will cause extra super block update which +# doesn't increase generation. +_log_writes_mount -o space_cache=v1,notreelog +run_check $FSSTRESS_PROG -w -n $workload -p $nr_threads -d $SCRATCH_MNT \ + $FSSTRESS_AVOID > /dev/null 2>&1 +_log_writes_unmount + +_log_writes_remove +# Here we manually iterate through the log entries, as we need extra check +# on the output of btrfs check. And we could have detailed replay log in +# $seqres.full +prev=$(_log_writes_mark_to_entry_number mkfs) +if [ -z "$prev" ]; then + _fail "failed to locate log writes mark 'mkfs'" +fi + +# Here we only checks the result *AFTER* FUA writes, and no tree log, so +# everything should be valid. +cur=$(_log_writes_find_next_fua $prev) +[ -z "$cur" ] && _fail "failed to locate next fua write" + +# log-replay will not replay the last item, so manually increase it by one +cur=$(($cur + 1)) + +_log_writes_replay_log_entry_range $prev >> $seqres.full 2>&1 +while [ ! -z "$cur" ]; do + _log_writes_replay_log_entry_range $cur $prev + # Catch the btrfs check output into temp file, as we need to + # grep the output to find the cache corruption + $BTRFS_UTIL_PROG check --check-data-csum $SCRATCH_DEV &> $tmp.fsck + + # Cache passed generation,csum and free space check but corrupted + # will be reported as error + if [ $? -ne 0 ]; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found corruption" + fi + + # Mount option has ruled out any possible factors affect space cache + # And we are at the FUA writes, no generation related problem should + # happen anyway + if grep -q -e 'failed to load free space cache' $tmp.fsck; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found invalid space cache" + fi + + prev=$cur + cur=$(_log_writes_find_next_fua $prev) + [ -z $cur ] && break + + # Same as above + cur=$(($cur + 1)) +done + +echo "Silence is golden" + +# success, all done +status=0 +exittests/btrfs/159.out new file +2
-0@@ -0,0 +1,2 @@ +QA output created by 159 +Silence is goldentests/btrfs/group +1
-1@@ -161,3 +161,4 @@ 156 auto quick trim 157 auto quick raid 158 auto quick raid scrub +159 auto --2.15.1
--
To unsubscribe from this list: send the line "unsubscribe fstests" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Signature · 3 lines
Filipe David Manana, “Whether you think you can, or you think you can't — you're right.”
Re: [PATCH 3/3] fstests: btrfs: Add test case to check v1 space cache corruption
Quoted 6 lines · Filipe Manana
Quoted 1 line · Qu Wenruo
There are some btrfs corruption report in mail list for a while,
There have been for years (well, since ever) many reports of different types of corruptions.
Which kind of corruption are you referring to?
Transid error.
Quoted 16 lines
Quoted 16 lines
although such corruption is pretty rare and almost impossible to reproduce, with dm-log-writes we found it's highly related to v1 space cache.
Unlike journal based filesystems, btrfs completely rely on metadata CoW to protect itself from power loss.
Which needs extent allocator to avoid allocate extents on existing extent range.
Btrfs also uses free space cache to speed up such allocation.However there is a problem, v1 space cache is not protected by data CoW, and can be corrupted during power loss.
So btrfs do extra check on free space cache, verifying its own in-file csum, generation and free space recorded in cache and extent tree.
Quoted 4 lines
Quoted 2 lines
The problem is, under heavy concurrency, v1 space cache can be corrupted even under normal operations without power loss.
How?
At FUA writes, we can get v1 space cache who can pass checksum and generation check, but has difference in free space.
Quoted 5 lines
Quoted 3 lines
And we believe corrupted space cache can break btrfs metadata CoW and leads to the rare corruption in next power loss.
Which kind of corruption?
Transid related error.
Quoted 19 lines
Quoted 7 lines
The most obvious symptom will be difference in free space:
This will be caught by kernel, but such check is quite weak, and if the net free space change is 0 in one transaction, the corrupted cache can be loaded by kernel.
How can that happen? The only case I'm aware of, explained below, always leads to a difference (space cache has less free space then what we actually have if we check the extent tree).
Quoted 6 lines
In this case, btrfs check would report things like :
------
block group 298844160 has wrong amount of free space failed to load free space cache for block group 298844160
------
Quoted 4 lines
This is normal, but not very common, due to tiny races that exists between committing a transaction (writing the free space caches) and running dellaloc for example (since reserving an extent while running dealloc doesn't joing/start a transaction).
This race explains a lot.
But could that cause corrupted cache to be loaded after power loss, and break metadata CoW?
At least for the time point when FUA happens, the free space cache can pass both csum and generation, we only have free space difference to prevent it to be loaded.
Quoted 13 lines
Quoted 6 lines
But considering the test case are using notreelog, btrfs won't do sub-transaction commit which doesn't increase generation, each transaction should be consistent, and nothing should be reported at all.
Quoted 6 lines
Further more, we can even found corrupted file extents like:
------
root 5 inode 261 errors 100, file extent discount Found file extent holes:start: 962560, len: 32768ERROR: errors found in fs roots
Quoted 2 lines
Why do you think that's a corruption? Does it cause data loss or any user visible issue?
It breaks the rule that we shouldn't have the hole in file extents.
IIRC Nikolay is trying to use inode_lock_shared() to solve this race.
Quoted 13 lines
Having file extent holes not inserted happens when mixing buffered and direct IO writes to a file (and fsstress does that), for example:
create file
buffered write at offset 0, length 64K
direct IO write at offset at offset 64K, length 4K transaction commit
power loss
after this we got a missing 64K hole extent at offset 0 (atbtrfs_file_write_iterwe only add hole extents if the start offset is greater then the currenti_size)
Quoted 3 lines
But this does not cause any problem for the user or the fs itself, and it's supposed to be like that in the
NO_HOLESmode which one day (probably) will be the default mode.
At least before that happens, we should follow the current schema of file extents.
If we just ignore problems that won't cause data loss and keeps them, there will never be a good on-disk format schema.
Thanks,
Qu
Quoted 267 lines
Quoted 264 lines
------
Signed-off-by Qu Wenruo <[email protected]>--- common/dmlogwrites | 72 +++++++++++++++++++++++++++ tests/btrfs/159 | 141 ++++++++++++++++++++++++++++++++++++++++++++++++++++ tests/btrfs/159.out | 2 + tests/btrfs/group | 1 + 4 files changed, 216 insertions(+) create mode 100755 tests/btrfs/159 create mode 100644 tests/btrfs/159.outcommon/dmlogwrites +72
-0@@ -126,3 +126,75 @@ _log_writes_cleanup() $UDEV_SETTLE_PROG >/dev/null 2>&1 _log_writes_remove } + +# Convert log writes mark to entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_mark_to_entry_number() +{ + local _mark=$1 + local ret + + [ -z "$_mark" ] && _fail \ + "mark must be given for _log_writes_mark_to_entry_number" + + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --end-mark $_mark 2> /dev/null) + [ -z "$ret" ] && return + ret=$(echo "$ret" | cut -f1 -d\@) + echo "mark $_mark has entry number $ret" >> $seqres.full + echo "$ret" +} + +# Find next fua write entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_find_next_fua() +{ + local _start_entry=$1 + local ret + + if [ -z "$_start_entry" ]; then + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua 2> /dev/null) + else + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua --start-entry $_start_entry 2> /dev/null) + fi + [ -z "$ret" ] && return + + ret=$(echo "$ret" | cut -f1 -d\@) + echo "next fua is entry number $ret" >> $seqres.full + echo "$ret" +} + +# Replay log range to specified entry +# $1: End entry. The last entry will *NOT* be replayed +# $2: Start entry. If not specified, start from the first entry. +_log_writes_replay_log_entry_range() +{ + local _end=$1 + local _start=$2 + + [ -z "$_end" ] && _fail \ + "end entry must be specified for _log_writes_replay_log_entry_range" + + if [[ "$_start" && "$_start" -gt "$_end" ]]; then + _fail \ + "wrong parameter order for _log_writes_replay_log_entry_range:start=$_start end=$_end" + fi + + # Original replay-log won't replay the last entry. So increase entry + # number here to ensure the end entry to be replayed + if [ -z "$_start" ]; then + echo "=== replay to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --limit $_end -v \ + >> $seqres.full 2>&1 + else + echo "=== replay from $_start to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --start-entry $_start \ + --limit $(($_end - $_start)) -v \ + >> $seqres.full 2>&1 + fi + [ $? -ne 0 ] && _fail "replay failed" +}tests/btrfs/159 new file +141
-0@@ -0,0 +1,141 @@ +#! /bin/bash +# FS QA Test 159 +# +# Test case for btrfs v1 space cache corruption +# +# Btrfs has some unexpected corruption after power loss, during the +# investigation, the problem leads to v1 space cache corruption, which +# could be loaded by kernel without detection. +# +# Kernel has 3 detection for corrupted space cache, checksum, generation +# and free space, however the last one is a weak one. If in the one transaction +# no net space change it can be loaded by kernel and break up metadata CoW, +# leading serious corruption. +# +#----------------------------------------------------------------------- +# Copyright (c) SUSE. All Rights Reserved. +# +# This program is free software; you can redistribute it and/or +# modify it under the terms of the GNU General Public License as +# published by the Free Software Foundation. +# +# This program is distributed in the hope that it would be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write the Free Software Foundation, +# Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +#----------------------------------------------------------------------- +# + +seq=`basename $0` +seqres=$RESULT_DIR/$seq +echo "QA output created by $seq" + +here=`pwd` +tmp=/tmp/$$ +status=1 # failure is the default! +trap "_cleanup; exit \$status" 0 1 2 3 15 + +_cleanup() +{ + cd / + rm -f $tmp.* + _log_writes_cleanup +} + +# get standard environment, filters and checks +. ./common/rc +. ./common/dmlogwrites +. ./common/filter + +# remove previous $seqres.full before test +rm -f $seqres.full + +# Small workload is enough to trigger the problem +workload=$(( 512 * $LOAD_FACTOR )) +nr_threads=$(($($here/src/feature -o) * $LOAD_FACTOR)) + +# Modify as appropriate. +_supported_fs btrfs +_supported_os Linux +_require_log_writes +_require_scratch + +_log_writes_init +_log_writes_mkfs >> $seqres.full 2>&1 + +# Here we don't want to create space cache yet +_log_writes_mount -o nospace_cache + +# The SINGLE profile data chunk created by mkfs is too small (8M) so btrfs +# won't create space cache for it. +# We need a data chunk large enough so btrfs create space cache for it and +# store the cache in itself. +_run_btrfs_util_prog balance start --full-balance "$SCRATCH_MNT" + +_log_writes_unmount +_log_writes_mark mkfs + +# Disable tree log, so btrfs will always do full transaction commit +# It's OK to use tree log, but it will cause extra super block update which +# doesn't increase generation. +_log_writes_mount -o space_cache=v1,notreelog +run_check $FSSTRESS_PROG -w -n $workload -p $nr_threads -d $SCRATCH_MNT \ + $FSSTRESS_AVOID > /dev/null 2>&1 +_log_writes_unmount + +_log_writes_remove +# Here we manually iterate through the log entries, as we need extra check +# on the output of btrfs check. And we could have detailed replay log in +# $seqres.full +prev=$(_log_writes_mark_to_entry_number mkfs) +if [ -z "$prev" ]; then + _fail "failed to locate log writes mark 'mkfs'" +fi + +# Here we only checks the result *AFTER* FUA writes, and no tree log, so +# everything should be valid. +cur=$(_log_writes_find_next_fua $prev) +[ -z "$cur" ] && _fail "failed to locate next fua write" + +# log-replay will not replay the last item, so manually increase it by one +cur=$(($cur + 1)) + +_log_writes_replay_log_entry_range $prev >> $seqres.full 2>&1 +while [ ! -z "$cur" ]; do + _log_writes_replay_log_entry_range $cur $prev + # Catch the btrfs check output into temp file, as we need to + # grep the output to find the cache corruption + $BTRFS_UTIL_PROG check --check-data-csum $SCRATCH_DEV &> $tmp.fsck + + # Cache passed generation,csum and free space check but corrupted + # will be reported as error + if [ $? -ne 0 ]; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found corruption" + fi + + # Mount option has ruled out any possible factors affect space cache + # And we are at the FUA writes, no generation related problem should + # happen anyway + if grep -q -e 'failed to load free space cache' $tmp.fsck; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found invalid space cache" + fi + + prev=$cur + cur=$(_log_writes_find_next_fua $prev) + [ -z $cur ] && break + + # Same as above + cur=$(($cur + 1)) +done + +echo "Silence is golden" + +# success, all done +status=0 +exittests/btrfs/159.out new file +2
-0@@ -0,0 +1,2 @@ +QA output created by 159 +Silence is goldentests/btrfs/group +1
-1@@ -161,3 +161,4 @@ 156 auto quick trim 157 auto quick raid 158 auto quick raid scrub +159 auto --2.15.1
--
To unsubscribe from this list: send the line "unsubscribe fstests" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 3/3] fstests: btrfs: Add test case to check v1 space cache corruption
Quoted 2 lines · Qu Wenruo
[snip]
Quoted 4 lines
It breaks the rule that we shouldn't have the hole in file extents.
IIRC Nikolay is trying to use
inode_lock_shared()to solve this race.
Unfortunately the inode_lock_shared approach is a no go since Filipe objected to it quite adamantly. After discussion that happened in that thread I can say I'm almost convinced that the pair of READDIO_LOCK and setsize *do* provide necessary consistency for the DIO case. However at the moment there is a memory barrier missing.
But I think the DIO case is unrelated to the issue you are discussing here, no ?
[snip]
Re: [PATCH 3/3] fstests: btrfs: Add test case to check v1 space cache corruption
In reply to Qu WenruoQuoted 11 lines · Qu Wenruo
Quoted 6 lines · Filipe Manana
Quoted 1 line · Qu Wenruo
There are some btrfs corruption report in mail list for a while,
There have been for years (well, since ever) many reports of different types of corruptions.
Which kind of corruption are you referring to?Transid error.
You mean parent transid mismatches in tree blocks?
Please always be explicit about problems are you mentioning. There can be many "transid" problems.
Quoted 57 lines
Quoted 17 lines
Quoted 17 lines
although such corruption is pretty rare and almost impossible to reproduce, with dm-log-writes we found it's highly related to v1 space cache.
Unlike journal based filesystems, btrfs completely rely on metadata CoW to protect itself from power loss.
Which needs extent allocator to avoid allocate extents on existing extent range.
Btrfs also uses free space cache to speed up such allocation.However there is a problem, v1 space cache is not protected by data CoW, and can be corrupted during power loss.
So btrfs do extra check on free space cache, verifying its own in-file csum, generation and free space recorded in cache and extent tree.Quoted 4 lines
Quoted 2 lines
The problem is, under heavy concurrency, v1 space cache can be corrupted even under normal operations without power loss.
How?
At FUA writes, we can get v1 space cache who can pass checksum and generation check, but has difference in free space.
Quoted 5 lines
Quoted 3 lines
And we believe corrupted space cache can break btrfs metadata CoW and leads to the rare corruption in next power loss.
Which kind of corruption?
Transid related error.
Quoted 19 lines
Quoted 7 lines
The most obvious symptom will be difference in free space:
This will be caught by kernel, but such check is quite weak, and if the net free space change is 0 in one transaction, the corrupted cache can be loaded by kernel.
How can that happen? The only case I'm aware of, explained below, always leads to a difference (space cache has less free space then what we actually have if we check the extent tree).
Quoted 6 lines
In this case, btrfs check would report things like :
------
block group 298844160 has wrong amount of free space failed to load free space cache for block group 298844160
------Quoted 4 lines
This is normal, but not very common, due to tiny races that exists between committing a transaction (writing the free space caches) and running dellaloc for example (since reserving an extent while running dealloc doesn't joing/start a transaction).
Quoted 4 lines
This race explains a lot.
But could that cause corrupted cache to be loaded after power loss, and break metadata CoW?
No, unless there's a bug in the procedure of detecting inconsistent caches.
Quoted 18 lines
At least for the time point when FUA happens, the free space cache can pass both csum and generation, we only have free space difference to prevent it to be loaded.
Quoted 13 lines
Quoted 12 lines
But considering the test case are using notreelog, btrfs won't do sub-transaction commit which doesn't increase generation, each transaction should be consistent, and nothing should be reported at all.
Further more, we can even found corrupted file extents like:
------
root 5 inode 261 errors 100, file extent discount Found file extent holes:start: 962560, len: 32768ERROR: errors found in fs roots
Quoted 4 lines
Quoted 2 lines
Why do you think that's a corruption? Does it cause data loss or any user visible issue?
It breaks the rule that we shouldn't have the hole in file extents.
Right. My question/remark was that, besides the warning emitted by fsck, this does not cause any harm to users/applications nor the filesytem. That is, no data loss, metadata corruption or anything that prevents the user from reading all previously written data nor anything preventing future IO to any range of the file.
So this is just a minor annoyance and far from a serious bug.
Quoted 2 lines
IIRC Nikolay is trying to use
inode_lock_shared()to solve this race.
I don't see what's the relation, even because this is not caused by race conditions.
Quoted 18 lines
Quoted 14 lines
Having file extent holes not inserted happens when mixing buffered and direct IO writes to a file (and fsstress does that), for example:
create file
buffered write at offset 0, length 64K
direct IO write at offset at offset 64K, length 4K transaction commit
power loss
after this we got a missing 64K hole extent at offset 0 (atbtrfs_file_write_iterwe only add hole extents if the start offset is greater then the currenti_size)Quoted 3 lines
But this does not cause any problem for the user or the fs itself, and it's supposed to be like that in the
NO_HOLESmode which one day (probably) will be the default mode.
Quoted 5 lines
At least before that happens, we should follow the current schema of file extents.
If we just ignore problems that won't cause data loss and keeps them, there will never be a good on-disk format schema.
Sure, but it's a minor thing as previously said. I was pointing out that what you called a corruption is not really a corruption.
Quoted 272 lines
Thanks,
QuQuoted 267 lines
Quoted 264 lines
------
Signed-off-by Qu Wenruo <[email protected]>--- common/dmlogwrites | 72 +++++++++++++++++++++++++++ tests/btrfs/159 | 141 ++++++++++++++++++++++++++++++++++++++++++++++++++++ tests/btrfs/159.out | 2 + tests/btrfs/group | 1 + 4 files changed, 216 insertions(+) create mode 100755 tests/btrfs/159 create mode 100644 tests/btrfs/159.outcommon/dmlogwrites +72
-0@@ -126,3 +126,75 @@ _log_writes_cleanup() $UDEV_SETTLE_PROG >/dev/null 2>&1 _log_writes_remove } + +# Convert log writes mark to entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_mark_to_entry_number() +{ + local _mark=$1 + local ret + + [ -z "$_mark" ] && _fail \ + "mark must be given for _log_writes_mark_to_entry_number" + + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --end-mark $_mark 2> /dev/null) + [ -z "$ret" ] && return + ret=$(echo "$ret" | cut -f1 -d\@) + echo "mark $_mark has entry number $ret" >> $seqres.full + echo "$ret" +} + +# Find next fua write entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_find_next_fua() +{ + local _start_entry=$1 + local ret + + if [ -z "$_start_entry" ]; then + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua 2> /dev/null) + else + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua --start-entry $_start_entry 2> /dev/null) + fi + [ -z "$ret" ] && return + + ret=$(echo "$ret" | cut -f1 -d\@) + echo "next fua is entry number $ret" >> $seqres.full + echo "$ret" +} + +# Replay log range to specified entry +# $1: End entry. The last entry will *NOT* be replayed +# $2: Start entry. If not specified, start from the first entry. +_log_writes_replay_log_entry_range() +{ + local _end=$1 + local _start=$2 + + [ -z "$_end" ] && _fail \ + "end entry must be specified for _log_writes_replay_log_entry_range" + + if [[ "$_start" && "$_start" -gt "$_end" ]]; then + _fail \ + "wrong parameter order for _log_writes_replay_log_entry_range:start=$_start end=$_end" + fi + + # Original replay-log won't replay the last entry. So increase entry + # number here to ensure the end entry to be replayed + if [ -z "$_start" ]; then + echo "=== replay to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --limit $_end -v \ + >> $seqres.full 2>&1 + else + echo "=== replay from $_start to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --start-entry $_start \ + --limit $(($_end - $_start)) -v \ + >> $seqres.full 2>&1 + fi + [ $? -ne 0 ] && _fail "replay failed" +}tests/btrfs/159 new file +141
-0@@ -0,0 +1,141 @@ +#! /bin/bash +# FS QA Test 159 +# +# Test case for btrfs v1 space cache corruption +# +# Btrfs has some unexpected corruption after power loss, during the +# investigation, the problem leads to v1 space cache corruption, which +# could be loaded by kernel without detection. +# +# Kernel has 3 detection for corrupted space cache, checksum, generation +# and free space, however the last one is a weak one. If in the one transaction +# no net space change it can be loaded by kernel and break up metadata CoW, +# leading serious corruption. +# +#----------------------------------------------------------------------- +# Copyright (c) SUSE. All Rights Reserved. +# +# This program is free software; you can redistribute it and/or +# modify it under the terms of the GNU General Public License as +# published by the Free Software Foundation. +# +# This program is distributed in the hope that it would be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write the Free Software Foundation, +# Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +#----------------------------------------------------------------------- +# + +seq=`basename $0` +seqres=$RESULT_DIR/$seq +echo "QA output created by $seq" + +here=`pwd` +tmp=/tmp/$$ +status=1 # failure is the default! +trap "_cleanup; exit \$status" 0 1 2 3 15 + +_cleanup() +{ + cd / + rm -f $tmp.* + _log_writes_cleanup +} + +# get standard environment, filters and checks +. ./common/rc +. ./common/dmlogwrites +. ./common/filter + +# remove previous $seqres.full before test +rm -f $seqres.full + +# Small workload is enough to trigger the problem +workload=$(( 512 * $LOAD_FACTOR )) +nr_threads=$(($($here/src/feature -o) * $LOAD_FACTOR)) + +# Modify as appropriate. +_supported_fs btrfs +_supported_os Linux +_require_log_writes +_require_scratch + +_log_writes_init +_log_writes_mkfs >> $seqres.full 2>&1 + +# Here we don't want to create space cache yet +_log_writes_mount -o nospace_cache + +# The SINGLE profile data chunk created by mkfs is too small (8M) so btrfs +# won't create space cache for it. +# We need a data chunk large enough so btrfs create space cache for it and +# store the cache in itself. +_run_btrfs_util_prog balance start --full-balance "$SCRATCH_MNT" + +_log_writes_unmount +_log_writes_mark mkfs + +# Disable tree log, so btrfs will always do full transaction commit +# It's OK to use tree log, but it will cause extra super block update which +# doesn't increase generation. +_log_writes_mount -o space_cache=v1,notreelog +run_check $FSSTRESS_PROG -w -n $workload -p $nr_threads -d $SCRATCH_MNT \ + $FSSTRESS_AVOID > /dev/null 2>&1 +_log_writes_unmount + +_log_writes_remove +# Here we manually iterate through the log entries, as we need extra check +# on the output of btrfs check. And we could have detailed replay log in +# $seqres.full +prev=$(_log_writes_mark_to_entry_number mkfs) +if [ -z "$prev" ]; then + _fail "failed to locate log writes mark 'mkfs'" +fi + +# Here we only checks the result *AFTER* FUA writes, and no tree log, so +# everything should be valid. +cur=$(_log_writes_find_next_fua $prev) +[ -z "$cur" ] && _fail "failed to locate next fua write" + +# log-replay will not replay the last item, so manually increase it by one +cur=$(($cur + 1)) + +_log_writes_replay_log_entry_range $prev >> $seqres.full 2>&1 +while [ ! -z "$cur" ]; do + _log_writes_replay_log_entry_range $cur $prev + # Catch the btrfs check output into temp file, as we need to + # grep the output to find the cache corruption + $BTRFS_UTIL_PROG check --check-data-csum $SCRATCH_DEV &> $tmp.fsck + + # Cache passed generation,csum and free space check but corrupted + # will be reported as error + if [ $? -ne 0 ]; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found corruption" + fi + + # Mount option has ruled out any possible factors affect space cache + # And we are at the FUA writes, no generation related problem should + # happen anyway + if grep -q -e 'failed to load free space cache' $tmp.fsck; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found invalid space cache" + fi + + prev=$cur + cur=$(_log_writes_find_next_fua $prev) + [ -z $cur ] && break + + # Same as above + cur=$(($cur + 1)) +done + +echo "Silence is golden" + +# success, all done +status=0 +exittests/btrfs/159.out new file +2
-0@@ -0,0 +1,2 @@ +QA output created by 159 +Silence is goldentests/btrfs/group +1
-1@@ -161,3 +161,4 @@ 156 auto quick trim 157 auto quick raid 158 auto quick raid scrub +159 auto --2.15.1
--
To unsubscribe from this list: send the line "unsubscribe fstests" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Signature · 3 lines
Filipe David Manana, “Whether you think you can, or you think you can't — you're right.”
Re: [PATCH 3/3] fstests: btrfs: Add test case to check v1 space cache corruption
In reply to Filipe MananaQuoted 50 lines · Filipe Manana
Quoted 1 line · Qu Wenruo
There are some btrfs corruption report in mail list for a while,
There have been for years (well, since ever) many reports of different types of corruptions.
Which kind of corruption are you referring to?Quoted 10 lines
although such corruption is pretty rare and almost impossible to reproduce, with dm-log-writes we found it's highly related to v1 space cache.
Unlike journal based filesystems, btrfs completely rely on metadata CoW to protect itself from power loss.
Which needs extent allocator to avoid allocate extents on existing extent range.
Btrfs also uses free space cache to speed up such allocation.Quoted 7 lines
However there is a problem, v1 space cache is not protected by data CoW, and can be corrupted during power loss.
So btrfs do extra check on free space cache, verifying its own in-file csum, generation and free space recorded in cache and extent tree.The problem is, under heavy concurrency, v1 space cache can be corrupted even under normal operations without power loss.
How?
Quoted 2 lines
And we believe corrupted space cache can break btrfs metadata CoW and leads to the rare corruption in next power loss.
Which kind of corruption?
Quoted 6 lines
The most obvious symptom will be difference in free space:
This will be caught by kernel, but such check is quite weak, and if the net free space change is 0 in one transaction, the corrupted cache can be loaded by kernel.
How can that happen? The only case I'm aware of, explained below, always leads to a difference (space cache has less free space then what we actually have if we check the extent tree).
Quoted 6 lines
In this case, btrfs check would report things like :
------
block group 298844160 has wrong amount of free space failed to load free space cache for block group 298844160
------
Quoted 4 lines
This is normal, but not very common, due to tiny races that exists between committing a transaction (writing the free space caches) and running dellaloc for example (since reserving an extent while running dealloc doesn't joing/start a transaction).
Well, at least I didn't find any place to release space unprotected by trans handler, so free space of cache can only be less or equal to real free space.
So in that case, corrupted cache will never pass the free space check so it will never be loaded.
Another dead end unfortunately.
Thanks,
Qu
Quoted 298 lines
Quoted 6 lines
But considering the test case are using notreelog, btrfs won't do sub-transaction commit which doesn't increase generation, each transaction should be consistent, and nothing should be reported at all.
Quoted 6 lines
Further more, we can even found corrupted file extents like:
------
root 5 inode 261 errors 100, file extent discount Found file extent holes:start: 962560, len: 32768ERROR: errors found in fs roots
Why do you think that's a corruption? Does it cause data loss or any user visible issue?
Having file extent holes not inserted happens when mixing buffered and direct IO writes to a file (and fsstress does that), for example:
create file
buffered write at offset 0, length 64K
direct IO write at offset at offset 64K, length 4K transaction commit
power loss
after this we got a missing 64K hole extent at offset 0 (atbtrfs_file_write_iterwe only add hole extents if the start offset is greater then the currenti_size)But this does not cause any problem for the user or the fs itself, and it's supposed to be like that in the
NO_HOLESmode which one day (probably) will be the default mode.Quoted 263 lines
------
Signed-off-by Qu Wenruo <[email protected]>--- common/dmlogwrites | 72 +++++++++++++++++++++++++++ tests/btrfs/159 | 141 ++++++++++++++++++++++++++++++++++++++++++++++++++++ tests/btrfs/159.out | 2 + tests/btrfs/group | 1 + 4 files changed, 216 insertions(+) create mode 100755 tests/btrfs/159 create mode 100644 tests/btrfs/159.outcommon/dmlogwrites +72
-0@@ -126,3 +126,75 @@ _log_writes_cleanup() $UDEV_SETTLE_PROG >/dev/null 2>&1 _log_writes_remove } + +# Convert log writes mark to entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_mark_to_entry_number() +{ + local _mark=$1 + local ret + + [ -z "$_mark" ] && _fail \ + "mark must be given for _log_writes_mark_to_entry_number" + + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --end-mark $_mark 2> /dev/null) + [ -z "$ret" ] && return + ret=$(echo "$ret" | cut -f1 -d\@) + echo "mark $_mark has entry number $ret" >> $seqres.full + echo "$ret" +} + +# Find next fua write entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_find_next_fua() +{ + local _start_entry=$1 + local ret + + if [ -z "$_start_entry" ]; then + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua 2> /dev/null) + else + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua --start-entry $_start_entry 2> /dev/null) + fi + [ -z "$ret" ] && return + + ret=$(echo "$ret" | cut -f1 -d\@) + echo "next fua is entry number $ret" >> $seqres.full + echo "$ret" +} + +# Replay log range to specified entry +# $1: End entry. The last entry will *NOT* be replayed +# $2: Start entry. If not specified, start from the first entry. +_log_writes_replay_log_entry_range() +{ + local _end=$1 + local _start=$2 + + [ -z "$_end" ] && _fail \ + "end entry must be specified for _log_writes_replay_log_entry_range" + + if [[ "$_start" && "$_start" -gt "$_end" ]]; then + _fail \ + "wrong parameter order for _log_writes_replay_log_entry_range:start=$_start end=$_end" + fi + + # Original replay-log won't replay the last entry. So increase entry + # number here to ensure the end entry to be replayed + if [ -z "$_start" ]; then + echo "=== replay to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --limit $_end -v \ + >> $seqres.full 2>&1 + else + echo "=== replay from $_start to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --start-entry $_start \ + --limit $(($_end - $_start)) -v \ + >> $seqres.full 2>&1 + fi + [ $? -ne 0 ] && _fail "replay failed" +}tests/btrfs/159 new file +141
-0@@ -0,0 +1,141 @@ +#! /bin/bash +# FS QA Test 159 +# +# Test case for btrfs v1 space cache corruption +# +# Btrfs has some unexpected corruption after power loss, during the +# investigation, the problem leads to v1 space cache corruption, which +# could be loaded by kernel without detection. +# +# Kernel has 3 detection for corrupted space cache, checksum, generation +# and free space, however the last one is a weak one. If in the one transaction +# no net space change it can be loaded by kernel and break up metadata CoW, +# leading serious corruption. +# +#----------------------------------------------------------------------- +# Copyright (c) SUSE. All Rights Reserved. +# +# This program is free software; you can redistribute it and/or +# modify it under the terms of the GNU General Public License as +# published by the Free Software Foundation. +# +# This program is distributed in the hope that it would be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write the Free Software Foundation, +# Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +#----------------------------------------------------------------------- +# + +seq=`basename $0` +seqres=$RESULT_DIR/$seq +echo "QA output created by $seq" + +here=`pwd` +tmp=/tmp/$$ +status=1 # failure is the default! +trap "_cleanup; exit \$status" 0 1 2 3 15 + +_cleanup() +{ + cd / + rm -f $tmp.* + _log_writes_cleanup +} + +# get standard environment, filters and checks +. ./common/rc +. ./common/dmlogwrites +. ./common/filter + +# remove previous $seqres.full before test +rm -f $seqres.full + +# Small workload is enough to trigger the problem +workload=$(( 512 * $LOAD_FACTOR )) +nr_threads=$(($($here/src/feature -o) * $LOAD_FACTOR)) + +# Modify as appropriate. +_supported_fs btrfs +_supported_os Linux +_require_log_writes +_require_scratch + +_log_writes_init +_log_writes_mkfs >> $seqres.full 2>&1 + +# Here we don't want to create space cache yet +_log_writes_mount -o nospace_cache + +# The SINGLE profile data chunk created by mkfs is too small (8M) so btrfs +# won't create space cache for it. +# We need a data chunk large enough so btrfs create space cache for it and +# store the cache in itself. +_run_btrfs_util_prog balance start --full-balance "$SCRATCH_MNT" + +_log_writes_unmount +_log_writes_mark mkfs + +# Disable tree log, so btrfs will always do full transaction commit +# It's OK to use tree log, but it will cause extra super block update which +# doesn't increase generation. +_log_writes_mount -o space_cache=v1,notreelog +run_check $FSSTRESS_PROG -w -n $workload -p $nr_threads -d $SCRATCH_MNT \ + $FSSTRESS_AVOID > /dev/null 2>&1 +_log_writes_unmount + +_log_writes_remove +# Here we manually iterate through the log entries, as we need extra check +# on the output of btrfs check. And we could have detailed replay log in +# $seqres.full +prev=$(_log_writes_mark_to_entry_number mkfs) +if [ -z "$prev" ]; then + _fail "failed to locate log writes mark 'mkfs'" +fi + +# Here we only checks the result *AFTER* FUA writes, and no tree log, so +# everything should be valid. +cur=$(_log_writes_find_next_fua $prev) +[ -z "$cur" ] && _fail "failed to locate next fua write" + +# log-replay will not replay the last item, so manually increase it by one +cur=$(($cur + 1)) + +_log_writes_replay_log_entry_range $prev >> $seqres.full 2>&1 +while [ ! -z "$cur" ]; do + _log_writes_replay_log_entry_range $cur $prev + # Catch the btrfs check output into temp file, as we need to + # grep the output to find the cache corruption + $BTRFS_UTIL_PROG check --check-data-csum $SCRATCH_DEV &> $tmp.fsck + + # Cache passed generation,csum and free space check but corrupted + # will be reported as error + if [ $? -ne 0 ]; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found corruption" + fi + + # Mount option has ruled out any possible factors affect space cache + # And we are at the FUA writes, no generation related problem should + # happen anyway + if grep -q -e 'failed to load free space cache' $tmp.fsck; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found invalid space cache" + fi + + prev=$cur + cur=$(_log_writes_find_next_fua $prev) + [ -z $cur ] && break + + # Same as above + cur=$(($cur + 1)) +done + +echo "Silence is golden" + +# success, all done +status=0 +exittests/btrfs/159.out new file +2
-0@@ -0,0 +1,2 @@ +QA output created by 159 +Silence is goldentests/btrfs/group +1
-1@@ -161,3 +161,4 @@ 156 auto quick trim 157 auto quick raid 158 auto quick raid scrub +159 auto --2.15.1
--
To unsubscribe from this list: send the line "unsubscribe fstests" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 3/3] fstests: btrfs: Add test case to check v1 space cache corruption
Quoted 53 lines · Qu Wenruo
Quoted 50 lines · Filipe Manana
Quoted 1 line · Qu Wenruo
There are some btrfs corruption report in mail list for a while,
There have been for years (well, since ever) many reports of different types of corruptions.
Which kind of corruption are you referring to?Quoted 10 lines
although such corruption is pretty rare and almost impossible to reproduce, with dm-log-writes we found it's highly related to v1 space cache.
Unlike journal based filesystems, btrfs completely rely on metadata CoW to protect itself from power loss.
Which needs extent allocator to avoid allocate extents on existing extent range.
Btrfs also uses free space cache to speed up such allocation.Quoted 7 lines
However there is a problem, v1 space cache is not protected by data CoW, and can be corrupted during power loss.
So btrfs do extra check on free space cache, verifying its own in-file csum, generation and free space recorded in cache and extent tree.The problem is, under heavy concurrency, v1 space cache can be corrupted even under normal operations without power loss.
How?
Quoted 2 lines
And we believe corrupted space cache can break btrfs metadata CoW and leads to the rare corruption in next power loss.
Which kind of corruption?
Quoted 6 lines
The most obvious symptom will be difference in free space:
This will be caught by kernel, but such check is quite weak, and if the net free space change is 0 in one transaction, the corrupted cache can be loaded by kernel.
How can that happen? The only case I'm aware of, explained below, always leads to a difference (space cache has less free space then what we actually have if we check the extent tree).
Quoted 6 lines
In this case, btrfs check would report things like :
------
block group 298844160 has wrong amount of free space failed to load free space cache for block group 298844160
------
Quoted 8 lines
Quoted 4 lines
This is normal, but not very common, due to tiny races that exists between committing a transaction (writing the free space caches) and running dellaloc for example (since reserving an extent while running dealloc doesn't joing/start a transaction).
Well, at least I didn't find any place to release space unprotected by trans handler, so free space of cache can only be less or equal to real free space.
Well, that what I said before. For that particular race I mentioned, which is the only one I can remember of always existing, the only inconsistency that can happen is that the cache has less free extents than what you can find by scanning the extent tree. If the inconsistency was not detected at cache loading time, we would only leak extents, but never double allocate them.
Quoted 307 lines
So in that case, corrupted cache will never pass the free space check so it will never be loaded.
Another dead end unfortunately.
Thanks,
QuQuoted 298 lines
Quoted 6 lines
But considering the test case are using notreelog, btrfs won't do sub-transaction commit which doesn't increase generation, each transaction should be consistent, and nothing should be reported at all.
Quoted 6 lines
Further more, we can even found corrupted file extents like:
------
root 5 inode 261 errors 100, file extent discount Found file extent holes:start: 962560, len: 32768ERROR: errors found in fs roots
Why do you think that's a corruption? Does it cause data loss or any user visible issue?
Having file extent holes not inserted happens when mixing buffered and direct IO writes to a file (and fsstress does that), for example:
create file
buffered write at offset 0, length 64K
direct IO write at offset at offset 64K, length 4K transaction commit
power loss
after this we got a missing 64K hole extent at offset 0 (atbtrfs_file_write_iterwe only add hole extents if the start offset is greater then the currenti_size)But this does not cause any problem for the user or the fs itself, and it's supposed to be like that in the
NO_HOLESmode which one day (probably) will be the default mode.Quoted 263 lines
------
Signed-off-by Qu Wenruo <[email protected]>--- common/dmlogwrites | 72 +++++++++++++++++++++++++++ tests/btrfs/159 | 141 ++++++++++++++++++++++++++++++++++++++++++++++++++++ tests/btrfs/159.out | 2 + tests/btrfs/group | 1 + 4 files changed, 216 insertions(+) create mode 100755 tests/btrfs/159 create mode 100644 tests/btrfs/159.outcommon/dmlogwrites +72
-0@@ -126,3 +126,75 @@ _log_writes_cleanup() $UDEV_SETTLE_PROG >/dev/null 2>&1 _log_writes_remove } + +# Convert log writes mark to entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_mark_to_entry_number() +{ + local _mark=$1 + local ret + + [ -z "$_mark" ] && _fail \ + "mark must be given for _log_writes_mark_to_entry_number" + + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --end-mark $_mark 2> /dev/null) + [ -z "$ret" ] && return + ret=$(echo "$ret" | cut -f1 -d\@) + echo "mark $_mark has entry number $ret" >> $seqres.full + echo "$ret" +} + +# Find next fua write entry number +# Result entry number is output to stdout, could be empty if not found +_log_writes_find_next_fua() +{ + local _start_entry=$1 + local ret + + if [ -z "$_start_entry" ]; then + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua 2> /dev/null) + else + ret=$($here/src/log-writes/replay-log --find --log $LOGWRITES_DEV \ + --next-fua --start-entry $_start_entry 2> /dev/null) + fi + [ -z "$ret" ] && return + + ret=$(echo "$ret" | cut -f1 -d\@) + echo "next fua is entry number $ret" >> $seqres.full + echo "$ret" +} + +# Replay log range to specified entry +# $1: End entry. The last entry will *NOT* be replayed +# $2: Start entry. If not specified, start from the first entry. +_log_writes_replay_log_entry_range() +{ + local _end=$1 + local _start=$2 + + [ -z "$_end" ] && _fail \ + "end entry must be specified for _log_writes_replay_log_entry_range" + + if [[ "$_start" && "$_start" -gt "$_end" ]]; then + _fail \ + "wrong parameter order for _log_writes_replay_log_entry_range:start=$_start end=$_end" + fi + + # Original replay-log won't replay the last entry. So increase entry + # number here to ensure the end entry to be replayed + if [ -z "$_start" ]; then + echo "=== replay to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --limit $_end -v \ + >> $seqres.full 2>&1 + else + echo "=== replay from $_start to $_end ===" >> $seqres.full + $here/src/log-writes/replay-log --log $LOGWRITES_DEV \ + --replay $SCRATCH_DEV --start-entry $_start \ + --limit $(($_end - $_start)) -v \ + >> $seqres.full 2>&1 + fi + [ $? -ne 0 ] && _fail "replay failed" +}tests/btrfs/159 new file +141
-0@@ -0,0 +1,141 @@ +#! /bin/bash +# FS QA Test 159 +# +# Test case for btrfs v1 space cache corruption +# +# Btrfs has some unexpected corruption after power loss, during the +# investigation, the problem leads to v1 space cache corruption, which +# could be loaded by kernel without detection. +# +# Kernel has 3 detection for corrupted space cache, checksum, generation +# and free space, however the last one is a weak one. If in the one transaction +# no net space change it can be loaded by kernel and break up metadata CoW, +# leading serious corruption. +# +#----------------------------------------------------------------------- +# Copyright (c) SUSE. All Rights Reserved. +# +# This program is free software; you can redistribute it and/or +# modify it under the terms of the GNU General Public License as +# published by the Free Software Foundation. +# +# This program is distributed in the hope that it would be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write the Free Software Foundation, +# Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +#----------------------------------------------------------------------- +# + +seq=`basename $0` +seqres=$RESULT_DIR/$seq +echo "QA output created by $seq" + +here=`pwd` +tmp=/tmp/$$ +status=1 # failure is the default! +trap "_cleanup; exit \$status" 0 1 2 3 15 + +_cleanup() +{ + cd / + rm -f $tmp.* + _log_writes_cleanup +} + +# get standard environment, filters and checks +. ./common/rc +. ./common/dmlogwrites +. ./common/filter + +# remove previous $seqres.full before test +rm -f $seqres.full + +# Small workload is enough to trigger the problem +workload=$(( 512 * $LOAD_FACTOR )) +nr_threads=$(($($here/src/feature -o) * $LOAD_FACTOR)) + +# Modify as appropriate. +_supported_fs btrfs +_supported_os Linux +_require_log_writes +_require_scratch + +_log_writes_init +_log_writes_mkfs >> $seqres.full 2>&1 + +# Here we don't want to create space cache yet +_log_writes_mount -o nospace_cache + +# The SINGLE profile data chunk created by mkfs is too small (8M) so btrfs +# won't create space cache for it. +# We need a data chunk large enough so btrfs create space cache for it and +# store the cache in itself. +_run_btrfs_util_prog balance start --full-balance "$SCRATCH_MNT" + +_log_writes_unmount +_log_writes_mark mkfs + +# Disable tree log, so btrfs will always do full transaction commit +# It's OK to use tree log, but it will cause extra super block update which +# doesn't increase generation. +_log_writes_mount -o space_cache=v1,notreelog +run_check $FSSTRESS_PROG -w -n $workload -p $nr_threads -d $SCRATCH_MNT \ + $FSSTRESS_AVOID > /dev/null 2>&1 +_log_writes_unmount + +_log_writes_remove +# Here we manually iterate through the log entries, as we need extra check +# on the output of btrfs check. And we could have detailed replay log in +# $seqres.full +prev=$(_log_writes_mark_to_entry_number mkfs) +if [ -z "$prev" ]; then + _fail "failed to locate log writes mark 'mkfs'" +fi + +# Here we only checks the result *AFTER* FUA writes, and no tree log, so +# everything should be valid. +cur=$(_log_writes_find_next_fua $prev) +[ -z "$cur" ] && _fail "failed to locate next fua write" + +# log-replay will not replay the last item, so manually increase it by one +cur=$(($cur + 1)) + +_log_writes_replay_log_entry_range $prev >> $seqres.full 2>&1 +while [ ! -z "$cur" ]; do + _log_writes_replay_log_entry_range $cur $prev + # Catch the btrfs check output into temp file, as we need to + # grep the output to find the cache corruption + $BTRFS_UTIL_PROG check --check-data-csum $SCRATCH_DEV &> $tmp.fsck + + # Cache passed generation,csum and free space check but corrupted + # will be reported as error + if [ $? -ne 0 ]; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found corruption" + fi + + # Mount option has ruled out any possible factors affect space cache + # And we are at the FUA writes, no generation related problem should + # happen anyway + if grep -q -e 'failed to load free space cache' $tmp.fsck; then + cat $tmp.fsck >> $seqres.full + _fail "btrfs check found invalid space cache" + fi + + prev=$cur + cur=$(_log_writes_find_next_fua $prev) + [ -z $cur ] && break + + # Same as above + cur=$(($cur + 1)) +done + +echo "Silence is golden" + +# success, all done +status=0 +exittests/btrfs/159.out new file +2
-0@@ -0,0 +1,2 @@ +QA output created by 159 +Silence is goldentests/btrfs/group +1
-1@@ -161,3 +161,4 @@ 156 auto quick trim 157 auto quick raid 158 auto quick raid scrub +159 auto --2.15.1
--
To unsubscribe from this list: send the line "unsubscribe fstests" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Signature · 3 lines
Filipe David Manana, “Whether you think you can, or you think you can't — you're right.”
Quoted 52 lines · Qu Wenruo
Also change the flag numeric output to hex.
Signed-off-by Qu Wenruo <[email protected]>--- src/log-writes/log-writes.c | 70 ++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 63 insertions(+), 7 deletions(-)src/log-writes/log-writes.c +37
-0@@ -120,6 +120,58 @@ int log_discard(struct log *log, struct log_write_entry *entry)return 0 ; } +#define DEFINE_LOG_FLAGS_STR_ENTRY (x) \ + {LOG_##x##_FLAG, #x} + +struct flags_to_str_entry { +u64 flags; +const char *str; +} log_flags_table[] = { +DEFINE_LOG_FLAGS_STR_ENTRY (FLUSH ), +DEFINE_LOG_FLAGS_STR_ENTRY (FUA ), +DEFINE_LOG_FLAGS_STR_ENTRY (DISCARD ), +DEFINE_LOG_FLAGS_STR_ENTRY (MARK ) +}; + +#define ARRAY_SIZE (x) (sizeof(x) / sizeof((x)[0])) +#define LOG_FLAGS_BUF_SIZE 128 +/* +* Convert numeric flags to human readable flags. +* @flags: numeric flags +* @buf: output buffer for human readable string. +* must have enough space (LOG_FLAGS_BUF_SIZE) to contain all +* the string +*/ +static void entry_flags_to_str (u64 flags,char *buf) +{ +int empty =1 ; +int left_len; +int i; + + buf[0 ] ='\0' ; +for (i =0 ; i <ARRAY_SIZE (log_flags_table); i++) { +if (flags & log_flags_table[i].flags) { +if (!empty) +strncat (buf,"|" ,LOG_FLAGS_BUF_SIZE ); + empty =0 ; +strncat (buf, log_flags_table[i].str,LOG_FLAGS_BUF_SIZE ); + flags &= ~log_flags_table[i].flags; + }
src/log-writes/log-writes.c int log_discard(struct log *log, struct log_write_entry *entry) · line 169
Quoted 10 lines
src/log-writes/log-writes.c +10
-0+ } +if (flags) { +if (!empty) +strncat (buf,"|" ,LOG_FLAGS_BUF_SIZE ); + empty =0 ; + left_len =LOG_FLAGS_BUF_SIZE -strnlen (buf, +LOG_FLAGS_BUF_SIZE ); +if (left_len >0 ) +snprintf (buf +strnlen (buf,LOG_FLAGS_BUF_SIZE ), + left_len,"UNKNOWN.%llu" , flags);
Missed a spot - %llx
Quoted 79 lines
src/log-writes/log-writes.c +16
-8+ } +if (empty) +strncpy (buf,"NONE" ,LOG_FLAGS_BUF_SIZE ); +} +/* * @log: the log we are replaying. * @entry: entry to be replayed. @@ -179,6 +231,7 @@ int log_replay_next_entry(struct log *log, struct log_write_entry *entry,size_t read_size = read_data ? log->sectorsize :sizeof (struct log_write_entry );char *buf; +char flags_buf[LOG_FLAGS_BUF_SIZE ];ssize_t ret;off_t offset;int skip =0 ;@@ -210,19 +263,20 @@ int log_replay_next_entry(struct log *log, struct log_write_entry *entry, log->cur_pos += read_size; } + flags =le64_to_cpu (entry->flags); +entry_flags_to_str (flags, flags_buf); skip =log_should_skip (log, entry);if (log_writes_verbose >1 || (log_writes_verbose && !skip)) { -printf ("%s %d@%llu: sector %llu, size %llu, flags %llu\n" , +printf ("%s %d@%llu: sector %llu, size %llu, flags 0x%llx(%s)\n" , skip ?"skipping" :"replaying" , (int )log->cur_entry -1 , log->cur_pos / log->sectorsize, (unsigned long long )le64_to_cpu (entry->sector), (unsigned long long )size, - (unsigned long long )le64_to_cpu (entry->flags)); + (unsigned long long )flags, flags_buf); }if (!size)return 0 ; - flags =le64_to_cpu (entry->flags);if (flags &LOG_DISCARD_FLAG )return log_discard (log, entry);@@ -301,7 +355,7 @@ int log_seek_entry(struct log *log, u64 entry_num)return -1 ; }if (log_writes_verbose >1 ) - printf("seek entry %d@%llu: %llu, size %llu, flags %llu\n", + printf("seek entry %d@%llu: %llu, size %llu, flags 0x%llx\n", (int)i, log->cur_pos / log->sectorsize, (unsigned long long)le64_to_cpu(entry.sector), (unsigned long long)le64_to_cpu(entry.nr_sectors),@@ -339,6 +393,7 @@ int log_seek_next_entry(struct log *log, struct log_write_entry *entry,size_t read_size = read_data ? log->sectorsize :sizeof (struct log_write_entry );u64 flags; +char flags_buf[LOG_FLAGS_BUF_SIZE ];ssize_t ret;if (log->cur_entry >= log->nr_entries)@@ -366,14 +421,15 @@ int log_seek_next_entry(struct log *log, struct log_write_entry *entry, }else { log->cur_pos += read_size; } + flags =le64_to_cpu (entry->flags); +entry_flags_to_str (flags, flags_buf);if (log_writes_verbose >1 ) -printf ("seek entry %d@%llu: %llu, size %llu, flags %llu\n" , +printf ("seek entry %d@%llu: %llu, size %llu, flags 0x%llx(%s)\n" , (int )log->cur_entry -1 , log->cur_pos / log->sectorsize, (unsigned long long )le64_to_cpu (entry->sector), (unsigned long long )le64_to_cpu (entry->nr_sectors), - (unsigned long long )le64_to_cpu (entry->flags)); + (unsigned long long )flags, flags_buf); - flags =le64_to_cpu (entry->flags); read_size =le64_to_cpu (entry->nr_sectors) * log->sectorsize;if (!read_size || (flags &LOG_DISCARD_FLAG ))return 0 ; --2.15.1
PATCH v2 1/3 fstests: log-writes: Add support to output human readable flags
In reply to Qu WenruoAlso change the flag numeric output to hex.
---
v2:
Also output unknown flags in hex
--- src/log-writes/log-writes.c | 70 ++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 63 insertions(+), 7 deletions(-)
src/log-writes/log-writes.c +63 -7
@@ -120,6 +120,58 @@ int log_discard(struct log *log, struct log_write_entry *entry)return 0 ; } +#define DEFINE_LOG_FLAGS_STR_ENTRY (x) \ + {LOG_##x##_FLAG, #x} + +struct flags_to_str_entry { +u64 flags; +const char *str; +} log_flags_table[] = { +DEFINE_LOG_FLAGS_STR_ENTRY (FLUSH ), +DEFINE_LOG_FLAGS_STR_ENTRY (FUA ), +DEFINE_LOG_FLAGS_STR_ENTRY (DISCARD ), +DEFINE_LOG_FLAGS_STR_ENTRY (MARK ) +}; + +#define ARRAY_SIZE (x) (sizeof(x) / sizeof((x)[0])) +#define LOG_FLAGS_BUF_SIZE 128 +/* +* Convert numeric flags to human readable flags. +* @flags: numeric flags +* @buf: output buffer for human readable string. +* must have enough space (LOG_FLAGS_BUF_SIZE) to contain all +* the string +*/ +static void entry_flags_to_str (u64 flags,char *buf) +{ +int empty =1 ; +int left_len; +int i; + + buf[0 ] ='\0' ; +for (i =0 ; i <ARRAY_SIZE (log_flags_table); i++) { +if (flags & log_flags_table[i].flags) { +if (!empty) +strncat (buf,"|" ,LOG_FLAGS_BUF_SIZE ); + empty =0 ; +strncat (buf, log_flags_table[i].str,LOG_FLAGS_BUF_SIZE ); + flags &= ~log_flags_table[i].flags; + } + } +if (flags) { +if (!empty) +strncat (buf,"|" ,LOG_FLAGS_BUF_SIZE ); + empty =0 ; + left_len =LOG_FLAGS_BUF_SIZE -strnlen (buf, +LOG_FLAGS_BUF_SIZE ); +if (left_len >0 ) +snprintf (buf +strnlen (buf,LOG_FLAGS_BUF_SIZE ), + left_len,"UNKNOWN.0x%llx" , flags); + } +if (empty) +strncpy (buf,"NONE" ,LOG_FLAGS_BUF_SIZE ); +} +/* * @log: the log we are replaying. * @entry: entry to be replayed.
@@ -179,6 +231,7 @@ int log_replay_next_entry(struct log *log, struct log_write_entry *entry,size_t read_size = read_data ? log->sectorsize :sizeof (struct log_write_entry );char *buf; +char flags_buf[LOG_FLAGS_BUF_SIZE ];ssize_t ret;off_t offset;int skip =0 ;
@@ -210,19 +263,20 @@ int log_replay_next_entry(struct log *log, struct log_write_entry *entry, log->cur_pos += read_size; } + flags =le64_to_cpu (entry->flags); +entry_flags_to_str (flags, flags_buf); skip =log_should_skip (log, entry);if (log_writes_verbose >1 || (log_writes_verbose && !skip)) { -printf ("%s %d@%llu: sector %llu, size %llu, flags %llu\n" , +printf ("%s %d@%llu: sector %llu, size %llu, flags 0x%llx(%s)\n" , skip ?"skipping" :"replaying" , (int )log->cur_entry -1 , log->cur_pos / log->sectorsize, (unsigned long long )le64_to_cpu (entry->sector), (unsigned long long )size, - (unsigned long long )le64_to_cpu (entry->flags)); + (unsigned long long )flags, flags_buf); }if (!size)return 0 ; - flags =le64_to_cpu (entry->flags);if (flags &LOG_DISCARD_FLAG )return log_discard (log, entry);
@@ -301,7 +355,7 @@ int log_seek_entry(struct log *log, u64 entry_num)return -1 ; }if (log_writes_verbose >1 ) - printf("seek entry %d@%llu: %llu, size %llu, flags %llu\n", + printf("seek entry %d@%llu: %llu, size %llu, flags 0x%llx\n", (int)i, log->cur_pos / log->sectorsize, (unsigned long long)le64_to_cpu(entry.sector), (unsigned long long)le64_to_cpu(entry.nr_sectors),
@@ -339,6 +393,7 @@ int log_seek_next_entry(struct log *log, struct log_write_entry *entry,size_t read_size = read_data ? log->sectorsize :sizeof (struct log_write_entry );u64 flags; +char flags_buf[LOG_FLAGS_BUF_SIZE ];ssize_t ret;if (log->cur_entry >= log->nr_entries)
@@ -366,14 +421,15 @@ int log_seek_next_entry(struct log *log, struct log_write_entry *entry, }else { log->cur_pos += read_size; } + flags =le64_to_cpu (entry->flags); +entry_flags_to_str (flags, flags_buf);if (log_writes_verbose >1 ) -printf ("seek entry %d@%llu: %llu, size %llu, flags %llu\n" , +printf ("seek entry %d@%llu: %llu, size %llu, flags 0x%llx(%s)\n" , (int )log->cur_entry -1 , log->cur_pos / log->sectorsize, (unsigned long long )le64_to_cpu (entry->sector), (unsigned long long )le64_to_cpu (entry->nr_sectors), - (unsigned long long )le64_to_cpu (entry->flags)); + (unsigned long long )flags, flags_buf); - flags =le64_to_cpu (entry->flags); read_size =le64_to_cpu (entry->nr_sectors) * log->sectorsize;if (!read_size || (flags &LOG_DISCARD_FLAG ))return 0 ;
Signature · 1 line
2.15.1