Forwarded: [PATCH] f2fs: DEBUG: trace node folio lifecycle to diagnose write_end_io BUG

[syzbot <syzbot+4af46ee83100e99bce09@syzkaller.appspotmail.com>]

For archival purposes, forwarding an incoming command email to
linux-kernel@vger.kernel.org, syzkaller-bugs@googlegroups.com.

***

Subject: [PATCH] f2fs: DEBUG: trace node folio lifecycle to diagnose write_end_io BUG
Author: kartikey406@gmail.com

#syz test: git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master


Not for upstream. Instrumentation to identify which path leaves
a node folio with folio->index != nid_of_node(folio) at writeback
time, triggering the BUG in f2fs_write_end_io() reported by syzbot.

Adds pr_info trace points at:
  - f2fs_new_node_folio()  - in-memory node folio construction
  - __get_node_folio()     - node folio lookup (cache or read)
  - __get_node_folio()     - synchronous footer sanity failure
  - f2fs_finish_read_bio() - async read completion footer check
  - f2fs_write_end_io()    - write completion footer check

BUG_ON in f2fs_write_end_io() is intentionally retained so the
kernel halts at the failing folio and the preceding pr_info
output appears in the syzbot console log.

Link: https://syzkaller.appspot.com/bug?extid=4af46ee83100e99bce09
Not-Signed-off-by: Deepanshu Kartikey <kartikey406@gmail.com>
---
 fs/f2fs/data.c | 19 ++++++++++++++-----
 fs/f2fs/node.c |  5 +++++
 2 files changed, 19 insertions(+), 5 deletions(-)

diff --git a/fs/f2fs/data.c b/fs/f2fs/data.c
index 8d4f1e75dee3..dc01a4fe089a 100644
--- a/fs/f2fs/data.c
+++ b/fs/f2fs/data.c
@@ -174,10 +174,17 @@ static void f2fs_finish_read_bio(struct bio *bio, bool in_task)
 			dec_page_count(F2FS_F_SB(folio), __read_io_type(folio));
 
 		if (bio->bi_status == BLK_STS_OK &&
-			F2FS_F_SB(folio)->node_inode && is_node_folio(folio) &&
-			f2fs_sanity_check_node_footer(F2FS_F_SB(folio),
-				folio, folio->index, NODE_TYPE_REGULAR, true))
-			bio->bi_status = BLK_STS_IOERR;
+			F2FS_F_SB(folio)->node_inode && is_node_folio(folio)) {
+			int rc = f2fs_sanity_check_node_footer(F2FS_F_SB(folio),
+			                                       folio, folio->index, NODE_TYPE_REGULAR, true);
+			pr_info("f2fs-dbg: READ end_io: index=%lu footer_nid=%u ino=%u rc=%d\n",
+				folio->index,
+				nid_of_node(folio),
+				ino_of_node(folio),
+				rc);
+			if (rc)
+				bio->bi_status = BLK_STS_IOERR;
+		}
 
 		if (finished)
 			folio_end_read(folio, bio->bi_status == BLK_STS_OK);
@@ -383,8 +390,10 @@ static void f2fs_write_end_io(struct bio *bio)
 		}
 
 		if (is_node_folio(folio)) {
-			f2fs_sanity_check_node_footer(sbi, folio,
+			int rc = f2fs_sanity_check_node_footer(sbi, folio,
 				folio->index, NODE_TYPE_REGULAR, true);
+			pr_info("f2fs-dbg: WRITE end_io: index=%lu footer_nid=%u ino=%u rc=%d\n",
+			         folio->index,nid_of_node(folio),ino_of_node(folio),rc);
 			f2fs_bug_on(sbi, folio->index != nid_of_node(folio));
 		}
 		if (f2fs_in_warm_node_list(folio))
diff --git a/fs/f2fs/node.c b/fs/f2fs/node.c
index 4e5bd9e4cfc3..12a9774ac1df 100644
--- a/fs/f2fs/node.c
+++ b/fs/f2fs/node.c
@@ -1423,6 +1423,8 @@ struct folio *f2fs_new_node_folio(struct dnode_of_data *dn, unsigned int ofs)
 	f2fs_folio_wait_writeback(folio, NODE, true, true);
 	fill_node_footer(folio, dn->nid, dn->inode->i_ino, ofs, true);
 	set_cold_node(folio, S_ISDIR(dn->inode->i_mode));
+	pr_info("f2fs-dbg: NEW node_folio: nid=%u ino=%lu ofs=%u\n",
+		dn->nid, dn->inode->i_ino, ofs);
 	if (!folio_test_uptodate(folio))
 		folio_mark_uptodate(folio);
 	if (folio_mark_dirty(folio))
@@ -1565,6 +1567,7 @@ static struct folio *__get_node_folio(struct f2fs_sb_info *sbi, pgoff_t nid,
 	struct folio *folio;
 	int err;
 
+	pr_info("f2fs-dbg: GET node_folio: nid=%lu ntype=%d\n", nid, ntype);
 	if (!nid)
 		return ERR_PTR(-ENOENT);
 	if (f2fs_check_nid_range(sbi, nid))
@@ -1603,6 +1606,8 @@ static struct folio *__get_node_folio(struct f2fs_sb_info *sbi, pgoff_t nid,
 	err = f2fs_sanity_check_node_footer(sbi, folio, nid, ntype, false);
 	if (!err)
 		return folio;
+	pr_info("f2fs-dbg: SYNC sanity fail: nid=%lu footer_nid=%u ino=%u err=%d\n",
+		nid,nid_of_node(folio),ino_of_node(folio),err);
 out_err:
 	folio_clear_uptodate(folio);
 out_put_err:
-- 
2.43.0