Skip to contentSkip to conversation

xfs: add a writepage delay error injection tag

RFC PATCH In review Brian Foster 2 participants 4 messages Oct 24, 2017 – Oct 25, 2017 XFS filesystem

lore
Share & tools
lore
#0 lore raw

RFC PATCH 1/1 xfs: add a writepage delay error injection tag

The XFS ->writepage() cached mapping is racy in that the mapping can change as a result of external factors after it has been looked up and cached. If the current write_cache_pages() instance has to handle subsequent pages over the affected mapping, writeback can submit I/O to the wrong place, causing data loss and possibly corruption in the process.

To support the ability to manufacture this problem and effectively regression test it from userspace, introduce an error injection tag that triggers a fixed delay during ->writepage(). The delay occurs immediately after a mapping is cached. Once userspace triggers writeback, the delay provides userspace with a five second window to perform other operations on the file to attempt to invalidate the mapping.

Note that this tag is intended to be used by xfstests rather than for generic error handling testing. The lifetime of this tag should be tethered to the existence of targeted regression tests for the writepage mapping validity problem.

---

Hi all,

I'm posting this as an RFC for now because I'd like to try and see if there's a reproducer for this that doesn't rely on error injection. I need to think about that a bit more. In the meantime, I wanted to post this as a POC for the associated problem. This does indeed confirm that it's still possible to send I/O off to the wrong place outside the eofblocks variant of the problem that was previously fixed (and more easily reproduced).

I'll post the assocated xfstests test that demonstrates this problem in reply to this patch. The test reproduces about 50% of the time on my test vm.

Thoughts, reviews, flames appreciated.

Brian

 fs/xfs/xfs_aops.c  | 9 +++++++++
 fs/xfs/xfs_error.c | 3 +++
 fs/xfs/xfs_error.h | 4 +++-
 3 files changed, 15 insertions(+), 1 deletion(-)
fs/xfs/xfs_aops.c +9 -0
index a3eeaba..802e030 100644
@@ -967,6 +967,15 @@ xfs_writepage_map(
 				goto out;
 			wpc->imap_valid = xfs_imap_valid(inode, &wpc->imap,
 							 offset);
+			/*
+			 * The writepage delay injection tag is for userspace
+			 * imap validiation testing purposes. The delay allows
+			 * userspace some time to try and invalidate wpc->imap
+			 * immediately after it is cached.
+			 */
+			if (XFS_TEST_ERROR(false, XFS_I(inode)->i_mount,
+					   XFS_ERRTAG_WRITEPAGE_DELAY))
+				ssleep(5);
 		}
 		if (wpc->imap_valid) {
 			lock_buffer(bh);
fs/xfs/xfs_error.c +3 -0
index eaf86f5..36072e6 100644
@@ -58,6 +58,7 @@ static unsigned int xfs_errortag_random_default[] = {
 	XFS_RANDOM_DROP_WRITES,
 	XFS_RANDOM_LOG_BAD_CRC,
 	XFS_RANDOM_LOG_ITEM_PIN,
+	XFS_RANDOM_WRITEPAGE_DELAY,
 };
 
 struct xfs_errortag_attr {
@@ -163,6 +164,7 @@ XFS_ERRORTAG_ATTR_RW(ag_resv_critical,	XFS_ERRTAG_AG_RESV_CRITICAL);
 XFS_ERRORTAG_ATTR_RW(drop_writes,	XFS_ERRTAG_DROP_WRITES);
 XFS_ERRORTAG_ATTR_RW(log_bad_crc,	XFS_ERRTAG_LOG_BAD_CRC);
 XFS_ERRORTAG_ATTR_RW(log_item_pin,	XFS_ERRTAG_LOG_ITEM_PIN);
+XFS_ERRORTAG_ATTR_RW(writepage_delay,	XFS_ERRTAG_WRITEPAGE_DELAY);
 
 static struct attribute *xfs_errortag_attrs[] = {
 	XFS_ERRORTAG_ATTR_LIST(noerror),
@@ -196,6 +198,7 @@ static struct attribute *xfs_errortag_attrs[] = {
 	XFS_ERRORTAG_ATTR_LIST(drop_writes),
 	XFS_ERRORTAG_ATTR_LIST(log_bad_crc),
 	XFS_ERRORTAG_ATTR_LIST(log_item_pin),
+	XFS_ERRORTAG_ATTR_LIST(writepage_delay),
 	NULL,
 };
 
fs/xfs/xfs_error.h +3 -1
index 7c4bef3..17556b3 100644
@@ -107,7 +107,8 @@ extern void xfs_verifier_error(struct xfs_buf *bp);
 #define XFS_ERRTAG_DROP_WRITES				28
 #define XFS_ERRTAG_LOG_BAD_CRC				29
 #define XFS_ERRTAG_LOG_ITEM_PIN				30
-#define XFS_ERRTAG_MAX					31
+#define XFS_ERRTAG_WRITEPAGE_DELAY			31
+#define XFS_ERRTAG_MAX					32
 
 /*
  * Random factors for above tags, 1 means always, 2 means 1/2 time, etc.
@@ -143,6 +144,7 @@ extern void xfs_verifier_error(struct xfs_buf *bp);
 #define XFS_RANDOM_DROP_WRITES				1
 #define XFS_RANDOM_LOG_BAD_CRC				1
 #define XFS_RANDOM_LOG_ITEM_PIN				1
+#define XFS_RANDOM_WRITEPAGE_DELAY			1
 
 #ifdef DEBUG
 extern int xfs_errortag_init(struct xfs_mount *mp);
Signature · 1 line
2.9.5
#1 lore raw

RFC PATCH 1/1 tests/xfs: test writepage cached mapping validity

XFS has a bug where page writeback can end up sending data to the wrong location due to a stale, cached file mapping. Add a test to trigger this problem using the DEBUG mode error injection tag that is available to widen the race window.

---
 tests/xfs/999     | 102 ++++++++++++++++++++++++++++++++++++++++++++++++++++++
 tests/xfs/999.out |   2 ++
 tests/xfs/group   |   1 +
 3 files changed, 105 insertions(+)
 create mode 100755 tests/xfs/999
 create mode 100644 tests/xfs/999.out
tests/xfs/999 new file +102 -0
new file mode 100755
index 0000000..ef0c0d2
@@ -0,0 +1,102 @@
+#! /bin/bash
+# FS QA Test 999
+#
+# Test XFS page writeback code for races with the cached file mapping. XFS
+# caches the file -> block mapping for a full extent once it is initially looked
+# up. The cached mapping is used for all subsequent pages in the same writeback
+# cycle that cover the associated extent. Under certain conditions, it is
+# possible for concurrent operations on the file to invalidate the cached
+# mapping without the knowledge of writeback. Writeback ends up sending I/O to a
+# partly stale mapping and potentially leaving delalloc blocks in the current
+# mapping unconverted.
+#
+# Note that this test depends on XFS DEBUG mode error injection to widen the
+# race window long enough to reproduce.
+#
+#-----------------------------------------------------------------------
+# Copyright (c) 2017 Red Hat, Inc.  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.*
+}
+
+# get standard environment, filters and checks
+. ./common/rc
+. ./common/inject
+
+# remove previous $seqres.full before test
+rm -f $seqres.full
+
+# real QA test starts here
+
+# Modify as appropriate.
+_supported_fs generic
+_supported_os Linux
+_require_scratch
+_require_xfs_io_error_injection writepage_delay
+
+_scratch_mkfs >> $seqres.full 2>&1 || _fail "mkfs failed"
+_scratch_mount || _fail "mount failed"
+
+file=$SCRATCH_MNT/file
+
+# First truncate the file and fsync to get the file size on-disk. This is
+# necessary so the subsequent truncate down won't wait on writeback. We want the
+# next truncate to race with writeback and truncate on XFS will actually flush
+# and wait if the current in-core size doesn't match the on-disk inode size.
+$XFS_IO_PROG -fc "truncate 64k" -c fsync $file >> $seqres.full 2>&1
+
+# Create an initial delalloc mapping. We use 64k because reproducing the problem
+# requires the affected page to be part of a subsequent pagevec scan than the
+# one where we will block. The pagevec size is 14 pages (or 56k with a typical
+# 4k page sized system), so 64k ensures that writeback will require two pagevec
+# lookups.
+$XFS_IO_PROG -c "pwrite -b 64k 0 64k" $file >> $seqres.full 2>&1
+
+_scratch_inject_error writepage_delay 1
+
+# Now that the writepage delay is enabled, issue writeback and a racing truncate
+# and rewrite of the final page. Note that 'sync' is required to reproduce this
+# reliably.
+sync &
+$XFS_IO_PROG -c "truncate 60k" \
+	     -c "pwrite -S 0xef 60k 4k" $file >> $seqres.full 2>&1
+
+wait
+
+_scratch_inject_error writepage_delay 0
+
+# If the test fails, the most likely outcome is an sb_fdblocks mismatch and an
+# associated lingering delalloc assert failure.
+
+echo Silence is golden
+
+# success, all done
+status=0
+exit
tests/xfs/999.out new file +2 -0
new file mode 100644
index 0000000..3b276ca
@@ -0,0 +1,2 @@
+QA output created by 999
+Silence is golden
tests/xfs/group +1 -0
index b439842..a109bbb 100644
@@ -431,3 +431,4 @@
 431 auto quick dangerous
 432 auto quick dir metadata
 433 auto quick attr
+999 auto quick
Signature · 1 line
2.9.5
#2 lore raw
In reply to Brian Foster
Quoted 15 lines · Brian Foster

The XFS ->writepage() cached mapping is racy in that the mapping can change as a result of external factors after it has been looked up and cached. If the current write_cache_pages() instance has to handle subsequent pages over the affected mapping, writeback can submit I/O to the wrong place, causing data loss and possibly corruption in the process.

To support the ability to manufacture this problem and effectively regression test it from userspace, introduce an error injection tag that triggers a fixed delay during ->writepage(). The delay occurs immediately after a mapping is cached. Once userspace triggers writeback, the delay provides userspace with a five second window to perform other operations on the file to attempt to invalidate the mapping.

Quoted 4 lines

Note that this tag is intended to be used by xfstests rather than for generic error handling testing. The lifetime of this tag should be tethered to the existence of targeted regression tests for the writepage mapping validity problem.

Won't that effectively be 'forever' since we'll want to make sure the problem doesn't come back, even if Dave's RFC rework eventually makes it upstream?

I was also wondering if maybe some day we might want an error log whose numeric setting is something other than "frequency of occurrence"... like this one, which could become a writepage_delay_ms to inject arbitrary amounts of delay into writeback(?) But I might just be babbling here. :)

--D

Quoted 103 lines

---

Hi all,

I'm posting this as an RFC for now because I'd like to try and see if there's a reproducer for this that doesn't rely on error injection. I need to think about that a bit more. In the meantime, I wanted to post this as a POC for the associated problem. This does indeed confirm that it's still possible to send I/O off to the wrong place outside the eofblocks variant of the problem that was previously fixed (and more easily reproduced).

I'll post the assocated xfstests test that demonstrates this problem in reply to this patch. The test reproduces about 50% of the time on my test vm.

Thoughts, reviews, flames appreciated.

Brian

 fs/xfs/xfs_aops.c  | 9 +++++++++
 fs/xfs/xfs_error.c | 3 +++
 fs/xfs/xfs_error.h | 4 +++-
 3 files changed, 15 insertions(+), 1 deletion(-)
fs/xfs/xfs_aops.c +9 -0
index a3eeaba..802e030 100644
@@ -967,6 +967,15 @@ xfs_writepage_map(
 				goto out;
 			wpc->imap_valid = xfs_imap_valid(inode, &wpc->imap,
 							 offset);
+			/*
+			 * The writepage delay injection tag is for userspace
+			 * imap validiation testing purposes. The delay allows
+			 * userspace some time to try and invalidate wpc->imap
+			 * immediately after it is cached.
+			 */
+			if (XFS_TEST_ERROR(false, XFS_I(inode)->i_mount,
+					   XFS_ERRTAG_WRITEPAGE_DELAY))
+				ssleep(5);
 		}
 		if (wpc->imap_valid) {
 			lock_buffer(bh);
fs/xfs/xfs_error.c +3 -0
index eaf86f5..36072e6 100644
@@ -58,6 +58,7 @@ static unsigned int xfs_errortag_random_default[] = {
 	XFS_RANDOM_DROP_WRITES,
 	XFS_RANDOM_LOG_BAD_CRC,
 	XFS_RANDOM_LOG_ITEM_PIN,
+	XFS_RANDOM_WRITEPAGE_DELAY,
 };
 
 struct xfs_errortag_attr {
@@ -163,6 +164,7 @@ XFS_ERRORTAG_ATTR_RW(ag_resv_critical,	XFS_ERRTAG_AG_RESV_CRITICAL);
 XFS_ERRORTAG_ATTR_RW(drop_writes,	XFS_ERRTAG_DROP_WRITES);
 XFS_ERRORTAG_ATTR_RW(log_bad_crc,	XFS_ERRTAG_LOG_BAD_CRC);
 XFS_ERRORTAG_ATTR_RW(log_item_pin,	XFS_ERRTAG_LOG_ITEM_PIN);
+XFS_ERRORTAG_ATTR_RW(writepage_delay,	XFS_ERRTAG_WRITEPAGE_DELAY);
 
 static struct attribute *xfs_errortag_attrs[] = {
 	XFS_ERRORTAG_ATTR_LIST(noerror),
@@ -196,6 +198,7 @@ static struct attribute *xfs_errortag_attrs[] = {
 	XFS_ERRORTAG_ATTR_LIST(drop_writes),
 	XFS_ERRORTAG_ATTR_LIST(log_bad_crc),
 	XFS_ERRORTAG_ATTR_LIST(log_item_pin),
+	XFS_ERRORTAG_ATTR_LIST(writepage_delay),
 	NULL,
 };
 
fs/xfs/xfs_error.h +3 -1
index 7c4bef3..17556b3 100644
@@ -107,7 +107,8 @@ extern void xfs_verifier_error(struct xfs_buf *bp);
 #define XFS_ERRTAG_DROP_WRITES				28
 #define XFS_ERRTAG_LOG_BAD_CRC				29
 #define XFS_ERRTAG_LOG_ITEM_PIN				30
-#define XFS_ERRTAG_MAX					31
+#define XFS_ERRTAG_WRITEPAGE_DELAY			31
+#define XFS_ERRTAG_MAX					32
 
 /*
  * Random factors for above tags, 1 means always, 2 means 1/2 time, etc.
@@ -143,6 +144,7 @@ extern void xfs_verifier_error(struct xfs_buf *bp);
 #define XFS_RANDOM_DROP_WRITES				1
 #define XFS_RANDOM_LOG_BAD_CRC				1
 #define XFS_RANDOM_LOG_ITEM_PIN				1
+#define XFS_RANDOM_WRITEPAGE_DELAY			1
 
 #ifdef DEBUG
 extern int xfs_errortag_init(struct xfs_mount *mp);
Signature · 6 lines
2.9.5

--
To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
#3 lore raw
Quoted 16 lines · Darrick J. Wong
Quoted 15 lines · Brian Foster

The XFS ->writepage() cached mapping is racy in that the mapping can change as a result of external factors after it has been looked up and cached. If the current write_cache_pages() instance has to handle subsequent pages over the affected mapping, writeback can submit I/O to the wrong place, causing data loss and possibly corruption in the process.

To support the ability to manufacture this problem and effectively regression test it from userspace, introduce an error injection tag that triggers a fixed delay during ->writepage(). The delay occurs immediately after a mapping is cached. Once userspace triggers writeback, the delay provides userspace with a five second window to perform other operations on the file to attempt to invalidate the mapping.

Quoted 9 lines
Quoted 4 lines

Note that this tag is intended to be used by xfstests rather than for generic error handling testing. The lifetime of this tag should be tethered to the existence of targeted regression tests for the writepage mapping validity problem.

Won't that effectively be 'forever' since we'll want to make sure the problem doesn't come back, even if Dave's RFC rework eventually makes it upstream?

Heh, indeed. That's just me being wishy washy since I was hoping to avoid the need for error injection here. IOW, I was hoping to replace this test with a better one, but then decided to send it as an RFC. I'd like to try using a really large allocsize or some such to see if that creates a long enough extent/writeback runway to race without needing the delay. If I can't get anywhere with that, I'll drop the text above on the next post.

Quoted 6 lines

I was also wondering if maybe some day we might want an error log whose numeric setting is something other than "frequency of occurrence"... like this one, which could become a writepage_delay_ms to inject arbitrary amounts of delay into writeback(?) But I might just be babbling here. :)

I had the same thought when writing this.. that it would be nice if userspace could just specify the delay rather than the frequency because the latter is not really useful in this particular case. At the very least, I'm not sure 5s is really necessary now that we have a test script, so I'll revisit that. I had set that when I was running commands manually to find something that worked.

Brian

Quoted 109 lines

--D

Quoted 103 lines

---

Hi all,

I'm posting this as an RFC for now because I'd like to try and see if there's a reproducer for this that doesn't rely on error injection. I need to think about that a bit more. In the meantime, I wanted to post this as a POC for the associated problem. This does indeed confirm that it's still possible to send I/O off to the wrong place outside the eofblocks variant of the problem that was previously fixed (and more easily reproduced).

I'll post the assocated xfstests test that demonstrates this problem in reply to this patch. The test reproduces about 50% of the time on my test vm.

Thoughts, reviews, flames appreciated.

Brian

 fs/xfs/xfs_aops.c  | 9 +++++++++
 fs/xfs/xfs_error.c | 3 +++
 fs/xfs/xfs_error.h | 4 +++-
 3 files changed, 15 insertions(+), 1 deletion(-)
fs/xfs/xfs_aops.c +9 -0
index a3eeaba..802e030 100644
@@ -967,6 +967,15 @@ xfs_writepage_map(
 				goto out;
 			wpc->imap_valid = xfs_imap_valid(inode, &wpc->imap,
 							 offset);
+			/*
+			 * The writepage delay injection tag is for userspace
+			 * imap validiation testing purposes. The delay allows
+			 * userspace some time to try and invalidate wpc->imap
+			 * immediately after it is cached.
+			 */
+			if (XFS_TEST_ERROR(false, XFS_I(inode)->i_mount,
+					   XFS_ERRTAG_WRITEPAGE_DELAY))
+				ssleep(5);
 		}
 		if (wpc->imap_valid) {
 			lock_buffer(bh);
fs/xfs/xfs_error.c +3 -0
index eaf86f5..36072e6 100644
@@ -58,6 +58,7 @@ static unsigned int xfs_errortag_random_default[] = {
 	XFS_RANDOM_DROP_WRITES,
 	XFS_RANDOM_LOG_BAD_CRC,
 	XFS_RANDOM_LOG_ITEM_PIN,
+	XFS_RANDOM_WRITEPAGE_DELAY,
 };
 
 struct xfs_errortag_attr {
@@ -163,6 +164,7 @@ XFS_ERRORTAG_ATTR_RW(ag_resv_critical,	XFS_ERRTAG_AG_RESV_CRITICAL);
 XFS_ERRORTAG_ATTR_RW(drop_writes,	XFS_ERRTAG_DROP_WRITES);
 XFS_ERRORTAG_ATTR_RW(log_bad_crc,	XFS_ERRTAG_LOG_BAD_CRC);
 XFS_ERRORTAG_ATTR_RW(log_item_pin,	XFS_ERRTAG_LOG_ITEM_PIN);
+XFS_ERRORTAG_ATTR_RW(writepage_delay,	XFS_ERRTAG_WRITEPAGE_DELAY);
 
 static struct attribute *xfs_errortag_attrs[] = {
 	XFS_ERRORTAG_ATTR_LIST(noerror),
@@ -196,6 +198,7 @@ static struct attribute *xfs_errortag_attrs[] = {
 	XFS_ERRORTAG_ATTR_LIST(drop_writes),
 	XFS_ERRORTAG_ATTR_LIST(log_bad_crc),
 	XFS_ERRORTAG_ATTR_LIST(log_item_pin),
+	XFS_ERRORTAG_ATTR_LIST(writepage_delay),
 	NULL,
 };
 
fs/xfs/xfs_error.h +3 -1
index 7c4bef3..17556b3 100644
@@ -107,7 +107,8 @@ extern void xfs_verifier_error(struct xfs_buf *bp);
 #define XFS_ERRTAG_DROP_WRITES				28
 #define XFS_ERRTAG_LOG_BAD_CRC				29
 #define XFS_ERRTAG_LOG_ITEM_PIN				30
-#define XFS_ERRTAG_MAX					31
+#define XFS_ERRTAG_WRITEPAGE_DELAY			31
+#define XFS_ERRTAG_MAX					32
 
 /*
  * Random factors for above tags, 1 means always, 2 means 1/2 time, etc.
@@ -143,6 +144,7 @@ extern void xfs_verifier_error(struct xfs_buf *bp);
 #define XFS_RANDOM_DROP_WRITES				1
 #define XFS_RANDOM_LOG_BAD_CRC				1
 #define XFS_RANDOM_LOG_ITEM_PIN				1
+#define XFS_RANDOM_WRITEPAGE_DELAY			1
 
 #ifdef DEBUG
 extern int xfs_errortag_init(struct xfs_mount *mp);
Signature · 6 lines
2.9.5

--
To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe linux-xfs" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html