]> git-server-git.apps.pok.os.sepia.ceph.com Git - xfstests-dev.git/commitdiff
xfs: regression test for writeback corruption bug
authorDarrick J. Wong <djwong@kernel.org>
Wed, 21 Dec 2022 00:21:50 +0000 (16:21 -0800)
committerZorro Lang <zlang@kernel.org>
Sun, 25 Dec 2022 13:24:08 +0000 (21:24 +0800)
This is a regression test for a data corruption bug that existed in XFS'
copy on write code between 4.9 and 4.19.  The root cause is a
concurrency bug wherein we would drop ILOCK_SHARED after querying the
CoW fork in xfs_map_cow and retake it before querying the data fork in
xfs_map_blocks.  See the test description for a lot more details.

Cc: Wengang Wang <wen.gang.wang@oracle.com>
Signed-off-by: Darrick J. Wong <djwong@kernel.org>
Reviewed-by: Zorro Lang <zlang@redhat.com>
Signed-off-by: Zorro Lang <zlang@kernel.org>
common/rc
common/tracing [new file with mode: 0644]
tests/xfs/558 [new file with mode: 0755]
tests/xfs/558.out [new file with mode: 0644]

index 30a2a0985ba073c0a3b0a186bb047ba666fcefae..23530413ec10fdcfaa12d24ce4395dc11076aa36 100644 (file)
--- a/common/rc
+++ b/common/rc
@@ -3609,6 +3609,21 @@ _check_xflag()
        fi
 }
 
+# Make sure the given file access mode is set to use the pagecache.  If
+# userspace or kernel don't support statx or STATX_ATTR_DAX, we assume that
+# means pagecache.  The sole parameter must be a directory.
+_require_pagecache_access() {
+       local testfile="$1/testfile"
+
+       touch "$testfile"
+       if ! _check_s_dax "$testfile" 0 &>> $seqres.full; then
+               rm -f "$testfile"
+               _notrun 'test requires pagecache access'
+       fi
+
+       rm -f "$testfile"
+}
+
 # Check if dax mount options are supported
 #
 # $1 can be either 'dax=always' or 'dax'
diff --git a/common/tracing b/common/tracing
new file mode 100644 (file)
index 0000000..b3051c2
--- /dev/null
@@ -0,0 +1,66 @@
+##/bin/bash
+# SPDX-License-Identifier: GPL-2.0-or-later
+# Copyright (c) 2022 Oracle.  All Rights Reserved.
+#
+# Routines for dealing with ftrace (or any other tracing).
+
+FTRACE_INSTANCES_DIR="/sys/kernel/debug/tracing/instances/"
+
+_require_ftrace() {
+       test -d "$FTRACE_INSTANCES_DIR" || \
+               _notrun "kernel does not support ftrace"
+}
+
+_ftrace_cleanup() {
+       if [ -d "$FTRACE_DIR" ]; then
+               _ftrace_ignore_events
+               # Removing an ftrace buffer requires rmdir, even though the
+               # virtual directory contains children.
+               rmdir "$FTRACE_DIR"
+       fi
+}
+
+_ftrace_setup() {
+       test -n "$FTRACE_DIR" && _fail "_ftrace_setup already run?"
+
+       # Give this fstest its own ftrace buffer so that we don't mess up
+       # any other tracers that might be running.
+       FTRACE_DIR="$FTRACE_INSTANCES_DIR/fstests.$seq"
+
+       test -d "$FTRACE_DIR" && rmdir "$FTRACE_DIR"
+       mkdir "$FTRACE_DIR"
+}
+
+# Intercept the given events.  Arguments may be regular expressions.
+_ftrace_record_events() {
+       test -d "$FTRACE_DIR" || _fail "_ftrace_setup not run?"
+
+       for arg in "$@"; do
+               # Replace slashes with semicolons per ftrace convention
+               find "$FTRACE_DIR/events/" -type d -name "$arg" -printf '%P\n' | \
+                       tr '/' ':' >> "$FTRACE_DIR/set_event"
+       done
+}
+
+# Stop intercepting the given events.  If no arguments, stops all events.
+_ftrace_ignore_events() {
+       test -d "$FTRACE_DIR" || _fail "_ftrace_setup not run?"
+
+       if [ "$#" -eq 0 ]; then
+               echo > "$FTRACE_DIR/set_event"
+       else
+               for arg in "$@"; do
+                       # Replace slashes with semicolons per ftrace convention
+                       find "$FTRACE_DIR/events/" -type d -name "$arg" -printf '!%P\n' | \
+                               tr '/' ':' >> "$FTRACE_DIR/set_event"
+               done
+       fi
+}
+
+# Dump whatever was written to the ftrace buffer since the last time this
+# helper was called.
+_ftrace_dump() {
+       test -d "$FTRACE_DIR" || _fail "_ftrace_setup not run?"
+
+       cat "$FTRACE_DIR/trace"
+}
diff --git a/tests/xfs/558 b/tests/xfs/558
new file mode 100755 (executable)
index 0000000..819faf2
--- /dev/null
@@ -0,0 +1,210 @@
+#! /bin/bash
+# SPDX-License-Identifier: GPL-2.0
+# Copyright (c) 2022 Oracle.  All Rights Reserved.
+#
+# FS QA Test No. 558
+#
+# This is a regression test for a data corruption bug that existed in XFS' copy
+# on write code between 4.9 and 4.19.  The root cause is a concurrency bug
+# wherein we would drop ILOCK_SHARED after querying the CoW fork in xfs_map_cow
+# and retake it before querying the data fork in xfs_map_blocks.  If a second
+# thread changes the CoW fork mappings between the two calls, it's possible for
+# xfs_map_blocks to return a zero-block mapping, which results in writeback
+# being elided for that block.  Elided writeback of dirty data results in
+# silent loss of writes.
+#
+# Worse yet, kernels from that era still used buffer heads, which means that an
+# elided writeback leaves the page clean but the bufferheads dirty.  Due to a
+# naïve optimization in mark_buffer_dirty, the SetPageDirty call is elided if
+# the bufferhead is dirty, which means that a subsequent rewrite of the data
+# block will never result in the page being marked dirty, and all subsequent
+# writes are lost.
+#
+# It turns out that Christoph Hellwig unwittingly fixed the race in commit
+# 5c665e5b5af6 ("xfs: remove xfs_map_cow"), and no testcase was ever written.
+# Four years later, we hit it on a production 4.14 kernel.  This testcase
+# relies on a debugging knob that introduces artificial delays into writeback.
+#
+# Before the race, the file blocks 0-1 are not shared and blocks 2-5 are
+# shared.  There are no extents in CoW fork.
+#
+# Two threads race like this:
+#
+# Thread 1 (writeback block 0)     | Thread 2  (write to block 2)
+# ---------------------------------|--------------------------------
+#                                  |
+# 1. Check if block 0 in CoW fork  |
+#    from xfs_map_cow.             |
+#                                  |
+# 2. Block 0 not found in CoW      |
+#    fork; the block is considered |
+#    not shared.                   |
+#                                  |
+# 3. xfs_map_blocks looks up data  |
+#    fork to get a map covering    |
+#    block 0.                      |
+#                                  |
+# 4. It gets a data fork mapping   |
+#    for block 0 with length 2.    |
+#                                  |
+#                                  | 1. A buffered write to block 2 sees
+#                                  |    that it is a shared block and no
+#                                  |    extent covers block 2 in CoW fork.
+#                                  |
+#                                  |    It creates a new CoW fork mapping.
+#                                  |    Due to the cowextsize, the new
+#                                  |    extent starts at block 0 with
+#                                  |    length 128.
+#                                  |
+#                                  |
+# 5. It lookup CoW fork again to   |
+#    trim the map (0, 2) to a      |
+#    shared block boundary.        |
+#                                  |
+# 5a. It finds (0, 128) in CoW fork|
+# 5b. It trims the data fork map   |
+#     from (0, 1) to (0, 0) (!!!)  |
+#                                  |
+# 6. The xfs_imap_valid call after |
+#    the xfs_map_blocks call checks|
+#    if the mapping (0, 0) covers  |
+#    block 0.  The result is "NO". |
+#                                  |
+# 7. Since block 0 has no physical |
+#    block mapped, it's not added  |
+#    to the ioend.  This is the    |
+#    first problem.                |
+#                                  |
+# 8. xfs_add_to_ioend usually      |
+#    clears the bufferhead dirty   |
+#    flag  Because this is skipped,|
+#    we leave the page clean with  |
+#    the associated buffer head(s) |
+#    dirty (the second problem).   |
+#    Now the dirty state is        |
+#    inconsistent.
+#
+# On newer kernels, this is also a functionality test for the ifork sequence
+# counter because the writeback completions will change the data fork and force
+# revalidations of the wb mapping.
+#
+. ./common/preamble
+_begin_fstest auto quick clone
+
+# Import common functions.
+. ./common/reflink
+. ./common/inject
+. ./common/tracing
+
+# real QA test starts here
+_cleanup()
+{
+       test -n "$sentryfile" && rm -f $sentryfile
+       wait
+       _ftrace_cleanup
+       cd /
+       rm -r -f $tmp.* $sentryfile $tracefile
+}
+
+# Modify as appropriate.
+_supported_fs xfs
+_fixed_by_kernel_commit 5c665e5b5af6 "xfs: remove xfs_map_cow"
+_require_ftrace
+_require_xfs_io_error_injection "wb_delay_ms"
+_require_scratch_reflink
+_require_cp_reflink
+
+_scratch_mkfs >> $seqres.full
+_scratch_mount >> $seqres.full
+
+# This is a pagecache test, so try to disable fsdax mode.
+$XFS_IO_PROG -c 'chattr -x' $SCRATCH_MNT &> $seqres.full
+_require_pagecache_access $SCRATCH_MNT
+
+blksz=65536
+_require_congruent_file_oplen $SCRATCH_MNT $blksz
+
+# Make sure we have sufficient extent size to create speculative CoW
+# preallocations.
+$XFS_IO_PROG -c 'cowextsize 1m' $SCRATCH_MNT
+
+# Write out a file with the first two blocks unshared and the rest shared.
+_pwrite_byte 0x59 0 $((160 * blksz)) $SCRATCH_MNT/file >> $seqres.full
+_pwrite_byte 0x59 0 $((160 * blksz)) $SCRATCH_MNT/file.compare >> $seqres.full
+sync
+
+_cp_reflink $SCRATCH_MNT/file $SCRATCH_MNT/file.reflink
+
+_pwrite_byte 0x58 0 $((2 * blksz)) $SCRATCH_MNT/file >> $seqres.full
+_pwrite_byte 0x58 0 $((2 * blksz)) $SCRATCH_MNT/file.compare >> $seqres.full
+sync
+
+# Avoid creation of large folios on newer kernels by cycling the mount and
+# immediately writing to the page cache.
+_scratch_cycle_mount
+
+# Write the same data to file.compare as we're about to do to file.  Do this
+# before slowing down writeback to avoid unnecessary delay.
+_pwrite_byte 0x57 0 $((2 * blksz)) $SCRATCH_MNT/file.compare >> $seqres.full
+_pwrite_byte 0x56 $((2 * blksz)) $((2 * blksz)) $SCRATCH_MNT/file.compare >> $seqres.full
+sync
+
+# Introduce a half-second wait to each writeback block mapping call.  This
+# gives us a chance to race speculative cow prealloc with writeback.
+_scratch_inject_error "wb_delay_ms" 500
+
+_ftrace_setup
+_ftrace_record_events 'xfs_wb*iomap_invalid'
+
+# Start thread 1 + writeback above
+$XFS_IO_PROG -c "pwrite -S 0x57 0 $((2 * blksz))" \
+       -c 'fsync' $SCRATCH_MNT/file >> $seqres.full &
+sleep 1
+
+# Start a sentry to look for evidence of invalidation tracepoint tripping.  If
+# we see that, we know we've forced writeback to revalidate a mapping.  The
+# test has been successful, so turn off the delay.
+sentryfile=$TEST_DIR/$seq.sentry
+tracefile=$TEST_DIR/$seq.ftrace
+wait_for_errortag() {
+       while [ -e "$sentryfile" ]; do
+               _ftrace_dump | grep iomap_invalid >> "$tracefile"
+               if grep -q iomap_invalid "$tracefile"; then
+                       _scratch_inject_error "wb_delay_ms" 0
+                       _ftrace_ignore_events
+                       break;
+               fi
+               sleep 0.5
+       done
+}
+touch $sentryfile
+wait_for_errortag &
+
+# Start thread 2 to create the cowextsize reservation
+$XFS_IO_PROG -c "pwrite -S 0x56 $((2 * blksz)) $((2 * blksz))" \
+       -c 'fsync' $SCRATCH_MNT/file >> $seqres.full
+rm -f $sentryfile
+
+cat "$tracefile" >> $seqres.full
+grep -q iomap_invalid "$tracefile"
+saw_invalidation=$?
+
+# Flush everything to disk.  If the bug manifests, then after the cycle,
+# file should have stale 0x58 in block 0 because we silently dropped a write.
+_scratch_cycle_mount
+
+if ! cmp -s $SCRATCH_MNT/file $SCRATCH_MNT/file.compare; then
+       echo file and file.compare do not match
+       $XFS_IO_PROG -c 'bmap -celpv' -c 'bmap -elpv' $SCRATCH_MNT/file &>> $seqres.full
+       echo file.compare
+       od -tx1 -Ad -c $SCRATCH_MNT/file.compare
+       echo file
+       od -tx1 -Ad -c $SCRATCH_MNT/file
+elif [ $saw_invalidation -ne 0 ]; then
+       # The files matched, but nothing got logged about the revalidation?
+       echo "Expected to hear about writeback iomap invalidations?"
+fi
+
+echo Silence is golden
+status=0
+exit
diff --git a/tests/xfs/558.out b/tests/xfs/558.out
new file mode 100644 (file)
index 0000000..9a6c4e7
--- /dev/null
@@ -0,0 +1,2 @@
+QA output created by 558
+Silence is golden