btrfs: ctree: Dump the leaf before BUG_ON in btrfs_set_item_key_safe

We have a long standing problem with reversed keys that's detected by
btrfs_set_item_key_safe. This is hard to reproduce so we'd like to
capture more information for later analysis.

Let's dump the leaf content before triggering BUG_ON() so that we can
have some clue on what's going wrong.  The output of tree locks should
help us to debug such problem.

Sample stacktrace:

 generic/522             [00:07:05]
 [26946.113381] run fstests generic/522 at 2019-04-16 00:07:05
 [27161.474720] kernel BUG at fs/btrfs/ctree.c:3192!
 [27161.475923] invalid opcode: 0000 [#1] PREEMPT SMP
 [27161.477167] CPU: 0 PID: 15676 Comm: fsx Tainted: G        W         5.1.0-rc5-default+ #562
 [27161.478932] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.12.0-0-ga698c89-prebuilt.qemu.org 04/01/2014
 [27161.481099] RIP: 0010:btrfs_set_item_key_safe+0x146/0x1c0 [btrfs]
 [27161.485369] RSP: 0018:ffffb087499e39b0 EFLAGS: 00010286
 [27161.486464] RAX: 00000000ffffffff RBX: ffff941534d80e70 RCX: 0000000000024000
 [27161.487929] RDX: 0000000000013039 RSI: ffffb087499e3aa5 RDI: ffffb087499e39c7
 [27161.489289] RBP: 000000000000000e R08: ffff9414e0f49008 R09: 0000000000001000
 [27161.490807] R10: 0000000000000000 R11: 0000000000000003 R12: ffff9414e0f48e70
 [27161.492305] R13: ffffb087499e3aa5 R14: 0000000000000000 R15: 0000000000071000
 [27161.493845] FS:  00007f8ea58d0b80(0000) GS:ffff94153d400000(0000) knlGS:0000000000000000
 [27161.495608] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
 [27161.496717] CR2: 00007f8ea57a9000 CR3: 0000000016a33000 CR4: 00000000000006f0
 [27161.498100] Call Trace:
 [27161.498771]  __btrfs_drop_extents+0x6ec/0xdf0 [btrfs]
 [27161.499872]  btrfs_log_changed_extents.isra.26+0x3a2/0x9e0 [btrfs]
 [27161.501114]  btrfs_log_inode+0x7ff/0xdc0 [btrfs]
 [27161.502114]  ? __mutex_unlock_slowpath+0x4b/0x2b0
 [27161.503172]  btrfs_log_inode_parent+0x237/0x9c0 [btrfs]
 [27161.504348]  btrfs_log_dentry_safe+0x4a/0x70 [btrfs]
 [27161.505374]  btrfs_sync_file+0x1b7/0x480 [btrfs]
 [27161.506371]  __x64_sys_msync+0x180/0x210
 [27161.507208]  do_syscall_64+0x54/0x180
 [27161.507932]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
 [27161.508839] RIP: 0033:0x7f8ea5aa9c61
 [27161.512616] RSP: 002b:00007ffea2a06498 EFLAGS: 00000246 ORIG_RAX: 000000000000001a
 [27161.514161] RAX: ffffffffffffffda RBX: 000000000002a938 RCX: 00007f8ea5aa9c61
 [27161.515376] RDX: 0000000000000004 RSI: 000000000001c9b2 RDI: 00007f8ea578d000
 [27161.516572] RBP: 000000000001c07a R08: fffffffffffffff8 R09: 000000000002a000
 [27161.517883] R10: 00007f8ea57a99b2 R11: 0000000000000246 R12: 0000000000000938
 [27161.519080] R13: 00007f8ea578d000 R14: 000000000001c9b2 R15: 0000000000000000
 [27161.520281] Modules linked in: btrfs libcrc32c xor zstd_decompress zstd_compress xxhash raid6_pq loop [last unloaded: scsi_debug]
 [27161.522272] ---[ end trace d5afec7ccac6a252 ]---
 [27161.523111] RIP: 0010:btrfs_set_item_key_safe+0x146/0x1c0 [btrfs]
 [27161.527253] RSP: 0018:ffffb087499e39b0 EFLAGS: 00010286
 [27161.528192] RAX: 00000000ffffffff RBX: ffff941534d80e70 RCX: 0000000000024000
 [27161.529392] RDX: 0000000000013039 RSI: ffffb087499e3aa5 RDI: ffffb087499e39c7
 [27161.530607] RBP: 000000000000000e R08: ffff9414e0f49008 R09: 0000000000001000
 [27161.531802] R10: 0000000000000000 R11: 0000000000000003 R12: ffff9414e0f48e70
 [27161.533018] R13: ffffb087499e3aa5 R14: 0000000000000000 R15: 0000000000071000
 [27161.534405] FS:  00007f8ea58d0b80(0000) GS:ffff94153d400000(0000) knlGS:0000000000000000
 [27161.536048] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
 [27161.537210] CR2: 00007f8ea57a9000 CR3: 0000000016a33000 CR4: 00000000000006f0

Reviewed-by: Filipe Manana <fdmanana@suse.com>
Signed-off-by: Qu Wenruo <wqu@suse.com>
Signed-off-by: David Sterba <dsterba@suse.com>

1 files changed, 22 insertions, 2 deletions

diff --git a/fs/btrfs/ctree.c b/fs/btrfs/ctree.c
index 5116c2a1f0f9..5df76c17775a 100644
--- a/fs/btrfs/ctree.c
+++ b/fs/btrfs/ctree.c
@@ -3185,11 +3185,31 @@ void btrfs_set_item_key_safe(struct btrfs_fs_info *fs_info,
 	slot = path->slots[0];
 	if (slot > 0) {
 		btrfs_item_key(eb, &disk_key, slot - 1);
-		BUG_ON(comp_keys(&disk_key, new_key) >= 0);
+		if (unlikely(comp_keys(&disk_key, new_key) >= 0)) {
+			btrfs_crit(fs_info,
+		"slot %u key (%llu %u %llu) new key (%llu %u %llu)",
+				   slot, btrfs_disk_key_objectid(&disk_key),
+				   btrfs_disk_key_type(&disk_key),
+				   btrfs_disk_key_offset(&disk_key),
+				   new_key->objectid, new_key->type,
+				   new_key->offset);
+			btrfs_print_leaf(eb);
+			BUG();
+		}
 	}
 	if (slot < btrfs_header_nritems(eb) - 1) {
 		btrfs_item_key(eb, &disk_key, slot + 1);
-		BUG_ON(comp_keys(&disk_key, new_key) <= 0);
+		if (unlikely(comp_keys(&disk_key, new_key) <= 0)) {
+			btrfs_crit(fs_info,
+		"slot %u key (%llu %u %llu) new key (%llu %u %llu)",
+				   slot, btrfs_disk_key_objectid(&disk_key),
+				   btrfs_disk_key_type(&disk_key),
+				   btrfs_disk_key_offset(&disk_key),
+				   new_key->objectid, new_key->type,
+				   new_key->offset);
+			btrfs_print_leaf(eb);
+			BUG();
+		}
 	}
 
 	btrfs_cpu_key_to_disk(&disk_key, new_key);