Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Oops inside check_extent_to_backpointers during 1.13 → 1.18 upgrade #793

Open
g2p opened this issue Dec 2, 2024 · 7 comments
Open

Oops inside check_extent_to_backpointers during 1.13 → 1.18 upgrade #793

g2p opened this issue Dec 2, 2024 · 7 comments

Comments

@g2p
Copy link
Contributor

g2p commented Dec 2, 2024

This is a filesystem that had a corrupted LRU, so I mounted it with fsck+fix_errors. Because I'm mounting from bcachefs-testing (a6c9019; merged with 6.12.1), it is also doing a version upgrade:

bcachefs (fff77bd8-a548-4101-b7b7-a35fa30133a8): Doing compatible version upgrade from 1.13: inode_has_child_snapshots to 1.18: persistent_inode_cursors
running recovery passes: check_allocations,check_backpointers_to_extents,check_extents_to_backpointers

Here is the error in the LRU btree (at this point it was just the upgrade, no explicit fsck):

2024-12-02T19:16:36.019722: bcachefs (fff…): backpointers_to_extents: 22%, done 17591/76807 nodes, at backpointers:0:2502333079552:0
2024-12-02T19:16:42.367490: bcachefs (99…): backpointers_to_extents: 18%, done 30607/167624 nodes, at backpointers:0:4521027043368:0
2024-12-02T19:16:43.739494: bcachefs (fff…): corrupt btree node before write at btree lru level 0/1
2024-12-02T19:16:43.739617:   u64s 11 type btree_ptr_v2 18446462598799949824:22555927:0 len 0 ver 0: seq 1e815fffaf32294f written 408 min_key 281560644624456:281474977030657:1 durability: 1 ptr: 1:363693:0 gen 164
2024-12-02T19:16:43.739640:   node offset 408/408 bset u64s 4363 bset byte offset 520: invalid bkey format 57
2024-12-02T19:16:43.746178: bcachefs (fff…): inconsistency detected - emergency read only at journal seq 14338964
2024-12-02T19:16:43.749827: CPU: 0 UID: 0 PID: 10335 Comm: bch-reclaim/fff Kdump: loaded Tainted: G        W   E      6.12.1-g2p #102
2024-12-02T19:16:43.752229: Tainted: [W]=WARN, [E]=UNSIGNED_MODULE
2024-12-02T19:16:43.764591: Hardware name: To Be Filled By O.E.M. X570 Phantom Gaming 4/X570 Phantom Gaming 4, BIOS P5.61 02/22/2024
2024-12-02T19:16:43.766392: Call Trace:
2024-12-02T19:16:43.774752:  <TASK>
2024-12-02T19:16:43.774776: dump_stack_lvl (lib/dump_stack.c:122) 
2024-12-02T19:16:43.775366: dump_stack (lib/dump_stack.c:130) 
2024-12-02T19:16:43.775388: validate_bset_for_write (fs/bcachefs/btree_io.c:1991) 
2024-12-02T19:16:43.780732: __bch2_btree_node_write (fs/bcachefs/btree_io.c:2179 (discriminator 1)) 
2024-12-02T19:16:43.780757: bch2_btree_node_write (./arch/x86/include/asm/bitops.h:206 (discriminator 1) ./arch/x86/include/asm/bitops.h:238 (discriminator 1) ./include/asm-generic/bitops/instrumented-non-atomic.h:142 (discriminator 1) fs/bcachefs/btree_types.h:625 (discriminator 1) fs/bcachefs/btree_io.c:2332 (discriminator 1)) 
2024-12-02T19:16:43.781178: __btree_node_flush.isra.0 (fs/bcachefs/six.h:365 (discriminator 1) fs/bcachefs/btree_trans_commit.c:253 (discriminator 1)) 
2024-12-02T19:16:43.790711: ? bch2_btree_node_flush1 (fs/bcachefs/btree_trans_commit.c:260) 
2024-12-02T19:16:43.791698: bch2_btree_node_flush0 (fs/bcachefs/btree_trans_commit.c:262) 
2024-12-02T19:16:43.793541: journal_flush_pins.constprop.0 (./include/linux/spinlock.h:351 fs/bcachefs/journal_reclaim.c:570) 
2024-12-02T19:16:43.799308: ? lock_timer_base (kernel/time/timer.c:1051 (discriminator 1)) 
2024-12-02T19:16:43.799334: ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
2024-12-02T19:16:43.800497: ? bch2_get_next_online_dev.constprop.0 (fs/bcachefs/sb-members.h:160) 
2024-12-02T19:16:43.800529: __bch2_journal_reclaim (fs/bcachefs/journal_reclaim.c:701) 
2024-12-02T19:16:43.802186: bch2_journal_reclaim_thread (fs/bcachefs/journal_reclaim.c:744) 
2024-12-02T19:16:43.802207: ? __bch2_journal_reclaim (fs/bcachefs/journal_reclaim.c:726) 
2024-12-02T19:16:43.823546: kthread (kernel/kthread.c:389) 
2024-12-02T19:16:43.824484: ? kthread_park (kernel/kthread.c:342) 
2024-12-02T19:16:43.851153: ret_from_fork (arch/x86/kernel/process.c:153) 
2024-12-02T19:16:43.851176: ? kthread_park (kernel/kthread.c:342) 
2024-12-02T19:16:43.851195: ret_from_fork_asm (arch/x86/entry/entry_64.S:257) 
2024-12-02T19:16:43.852300:  </TASK>
2024-12-02T19:16:43.852506: bcachefs (fff…): corrupt btree node before write at btree lru level 0/1
2024-12-02T19:16:43.852535:   u64s 11 type btree_ptr_v2 281560286021448:281474977087749:0 len 0 ver 0: seq 7cae675a8af593dd written 272 min_key POS_MIN durability: 1 ptr: 1:586654:0 gen 58
2024-12-02T19:16:43.852736:   node offset 272/272 bset u64s 1505 bset byte offset 40: invalid bkey format 96
2024-12-02T19:16:43.852761: CPU: 8 UID: 0 PID: 10335 Comm: bch-reclaim/fff Kdump: loaded Tainted: G        W   E      6.12.1-g2p #102
2024-12-02T19:16:43.855046: Tainted: [W]=WARN, [E]=UNSIGNED_MODULE
2024-12-02T19:16:43.855065: Hardware name: To Be Filled By O.E.M. X570 Phantom Gaming 4/X570 Phantom Gaming 4, BIOS P5.61 02/22/2024
2024-12-02T19:16:43.855080: Call Trace:
2024-12-02T19:16:43.855094:  <TASK>
2024-12-02T19:16:43.855115: dump_stack_lvl (lib/dump_stack.c:122) 
2024-12-02T19:16:43.855136: dump_stack (lib/dump_stack.c:130) 
2024-12-02T19:16:43.855308: validate_bset_for_write (fs/bcachefs/btree_io.c:1991) 
2024-12-02T19:16:43.855331: __bch2_btree_node_write (fs/bcachefs/btree_io.c:2179 (discriminator 1)) 
2024-12-02T19:16:43.855354: bch2_btree_node_write (./arch/x86/include/asm/bitops.h:206 (discriminator 1) ./arch/x86/include/asm/bitops.h:238 (discriminator 1) ./include/asm-generic/bitops/instrumented-non-atomic.h:142 (discriminator 1) fs/bcachefs/btree_types.h:625 (discriminator 1) fs/bcachefs/btree_io.c:2332 (discriminator 1)) 
2024-12-02T19:16:43.855367: __btree_node_flush.isra.0 (fs/bcachefs/six.h:365 (discriminator 1) fs/bcachefs/btree_trans_commit.c:253 (discriminator 1)) 
2024-12-02T19:16:43.855381: ? bch2_btree_node_flush1 (fs/bcachefs/btree_trans_commit.c:260) 
2024-12-02T19:16:43.855911: bch2_btree_node_flush0 (fs/bcachefs/btree_trans_commit.c:262) 
2024-12-02T19:16:43.856370: journal_flush_pins.constprop.0 (./include/linux/spinlock.h:351 fs/bcachefs/journal_reclaim.c:570) 
2024-12-02T19:16:43.856931: ? lock_timer_base (kernel/time/timer.c:1051 (discriminator 1)) 
2024-12-02T19:16:43.856952: ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
2024-12-02T19:16:43.856966: ? bch2_get_next_online_dev.constprop.0 (fs/bcachefs/sb-members.h:160) 
2024-12-02T19:16:43.856986: __bch2_journal_reclaim (fs/bcachefs/journal_reclaim.c:701) 
2024-12-02T19:16:43.857006: bch2_journal_reclaim_thread (fs/bcachefs/journal_reclaim.c:744) 
2024-12-02T19:16:43.857333: ? __bch2_journal_reclaim (fs/bcachefs/journal_reclaim.c:726) 
2024-12-02T19:16:43.857351: kthread (kernel/kthread.c:389) 
2024-12-02T19:16:43.882155: ? kthread_park (kernel/kthread.c:342) 
2024-12-02T19:16:43.884389: ret_from_fork (arch/x86/kernel/process.c:153) 
2024-12-02T19:16:43.909403: ? kthread_park (kernel/kthread.c:342) 
2024-12-02T19:16:43.909426: ret_from_fork_asm (arch/x86/entry/entry_64.S:257) 
2024-12-02T19:16:43.923322:  </TASK>
2024-12-02T19:16:43.923346: bcachefs (fff…): bch2_check_backpointers_to_extents(): error erofs_journal_err
2024-12-02T19:16:43.924369: bcachefs (fff…): bch2_fs_recovery(): error erofs_journal_err
2024-12-02T19:16:43.924398: bcachefs (fff…): bch2_fs_start(): error starting filesystem erofs_journal_err
2024-12-02T19:16:43.924999: bcachefs (fff…): shutting down
2024-12-02T19:16:43.939928: bcachefs (fff…): going read-only
2024-12-02T19:16:43.939945: bcachefs (fff…): flushing journal and stopping allocators, journal seq 14338964
2024-12-02T19:16:43.949554: bcachefs (fff…): flushing journal and stopping allocators complete, journal seq 14338964
2024-12-02T19:16:43.971653: bcachefs (fff…): unclean shutdown complete, journal seq 14338964
2024-12-02T19:16:43.974165: bcachefs (fff…): finished waiting for writes to stop
2024-12-02T19:16:43.974429: bcachefs (fff…): done going read-only, filesystem not clean
2024-12-02T19:16:43.974949: bcachefs (fff…): shutdown complete
2024-12-02T19:16:43.976196: bcachefs: bch2_fs_get_tree() error: erofs_journal_err

Next is trying again with fsck,fix_errors, a shift out of bounds, and an oops:

Oops#1 Part8
<6>[17279.911552] bcachefs (99…): backpointers_to_extents: 140%, done 235013/167624 nodes, at backpointers:0:19422230142976:0
<6>[17282.887523] bcachefs (fff…): extents_to_backpointers: 35%, done 41232/116676 nodes, at extents:537053792:1362424:U32_MAX
<4>[17288.993471] ------------[ cut here ]------------
<3>[17288.993476] UBSAN: shift-out-of-bounds in fs/bcachefs/bcachefs.h:1191:41
<3>[17288.993481] shift exponent 53 is too large for 32-bit type 'unsigned int'
<4>[17288.993485] CPU: 0 UID: 0 PID: 11725 Comm: mount Kdump: loaded Tainted: G        W   E      6.12.1-g2p #102
<4>[17288.993490] Tainted: [W]=WARN, [E]=UNSIGNED_MODULE
<4>[17288.993491] Hardware name: To Be Filled By O.E.M. X570 Phantom Gaming 4/X570 Phantom Gaming 4, BIOS P5.61 02/22/2024
<4>[17288.993493] Call Trace:
<4>[17288.993496]  <TASK>
<4>[17288.993501] dump_stack_lvl (lib/dump_stack.c:122) 
<4>[17288.993508] dump_stack (lib/dump_stack.c:130) 
<4>[17288.993511] ubsan_epilogue (lib/ubsan.c:232) 
<4>[17288.993515] __ubsan_handle_shift_out_of_bounds.cold (lib/ubsan.c:468) 
<4>[17288.993522] bch2_trans_iter_init_outlined.cold (fs/bcachefs/bcachefs.h:1191 (discriminator 1) fs/bcachefs/btree_iter.h:475 (discriminator 1) fs/bcachefs/btree_iter.c:3030 (discriminator 1)) 
<4>[17288.993526] ? bch2_btree_write_buffer_flush_locked (fs/bcachefs/btree_write_buffer.c:363) 
<4>[17288.993531] bch2_btree_write_buffer_flush_locked (fs/bcachefs/btree_write_buffer.c:363) 
<4>[17288.993538] ? __bch2_next_write_buffer_flush_journal_buf (./include/linux/err.h:81 (discriminator 1) fs/bcachefs/journal.c:965 (discriminator 1)) 
<4>[17288.993548] btree_write_buffer_flush_seq (fs/bcachefs/btree_write_buffer.c:550) 
<4>[17288.993553] bch2_btree_write_buffer_flush_sync (fs/bcachefs/btree_write_buffer.c:576) 
<4>[17288.993558] bch2_btree_write_buffer_maybe_flush (fs/bcachefs/btree_write_buffer.c:643) 
<4>[17288.993565] check_bp_exists (fs/bcachefs/backpointers.c:472) 
Oops#1 Part7
<4>[17288.993568] ? local_clock_noinstr (kernel/sched/clock.c:301 (discriminator 1)) 
<4>[17288.993571] ? local_clock (./arch/x86/include/asm/preempt.h:94 (discriminator 1) kernel/sched/clock.c:316 (discriminator 1)) 
<4>[17288.993583] check_extent_to_backpointers (fs/bcachefs/backpointers.c:594) 
<4>[17288.993585] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993588] ? check_extent_to_backpointers (fs/bcachefs/backpointers.c:594) 
<4>[17288.993596] bch2_check_extents_to_backpointers_pass (fs/bcachefs/backpointers.c:790 (discriminator 1)) 
<4>[17288.993606] bch2_check_extents_to_backpointers (fs/bcachefs/backpointers.c:1077) 
<4>[17288.993608] ? __wake_up_klogd.part.0 (./arch/x86/include/asm/preempt.h:94 (discriminator 1) kernel/printk/printk.c:4495 (discriminator 1)) 
<4>[17288.993618] bch2_run_recovery_pass (fs/bcachefs/recovery_passes.c:223) 
<4>[17288.993622] bch2_run_recovery_passes (fs/bcachefs/recovery_passes.c:285) 
<4>[17288.993625] bch2_fs_recovery (fs/bcachefs/recovery.c:937) 
<4>[17288.993633] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993635] ? bch2_recalc_capacity (fs/bcachefs/alloc_background.c:2473) 
<4>[17288.993640] bch2_fs_start (fs/bcachefs/super.c:1034) 
<4>[17288.993645] bch2_fs_get_tree (fs/bcachefs/fs.c:2201) 
<4>[17288.993656] vfs_get_tree (fs/super.c:1815) 
<4>[17288.993660] path_mount (fs/namespace.c:3508 fs/namespace.c:3834) 
<4>[17288.993664] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993668] __x64_sys_mount (fs/namespace.c:3848 fs/namespace.c:4057 fs/namespace.c:4034 fs/namespace.c:4034) 
<4>[17288.993673] x64_sys_call (arch/x86/entry/syscall_64.c:36) 
<4>[17288.993677] do_syscall_64 (arch/x86/entry/common.c:52 (discriminator 1) arch/x86/entry/common.c:83 (discriminator 1)) 
<4>[17288.993680] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993683] ? syscall_exit_to_user_mode (./arch/x86/include/asm/entry-common.h:57 (discriminator 1) ./arch/x86/include/asm/entry-common.h:65 (discriminator 1) ./include/linux/entry-common.h:330 (discriminator 1) kernel/entry/common.c:207 (discriminator 1) kernel/entry/common.c:218 (discriminator 1)) 
<4>[17288.993686] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993689] ? do_syscall_64 (arch/x86/entry/common.c:102) 
<4>[17288.993696] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993699] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993701] ? syscall_exit_to_user_mode (./arch/x86/include/asm/entry-common.h:57 (discriminator 1) ./arch/x86/include/asm/entry-common.h:65 (discriminator 1) ./include/linux/entry-common.h:330 (discriminator 1) kernel/entry/common.c:207 (discriminator 1) kernel/entry/common.c:218 (discriminator 1)) 
<4>[17288.993705] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993707] ? do_syscall_64 (arch/x86/entry/common.c:102) 
<4>[17288.993710] ? syscall_exit_to_user_mode (./arch/x86/include/asm/entry-common.h:57 (discriminator 1) ./arch/x86/include/asm/entry-common.h:65 (discriminator 1) ./include/linux/entry-common.h:330 (discriminator 1) kernel/entry/common.c:207 (discriminator 1) kernel/entry/common.c:218 (discriminator 1)) 
<4>[17288.993714] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993717] ? do_syscall_64 (arch/x86/entry/common.c:102) 
Oops#1 Part6
<4>[17288.993720] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993722] ? do_syscall_64 (arch/x86/entry/common.c:102) 
<4>[17288.993726] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993728] ? irqentry_exit_to_user_mode (./arch/x86/include/asm/entry-common.h:57 (discriminator 1) ./arch/x86/include/asm/entry-common.h:65 (discriminator 1) ./include/linux/entry-common.h:330 (discriminator 1) kernel/entry/common.c:231 (discriminator 1)) 
<4>[17288.993731] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993733] ? irqentry_exit (kernel/entry/common.c:367) 
<4>[17288.993736] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993738] ? exc_page_fault (arch/x86/mm/fault.c:1543) 
<4>[17288.993741] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:130) 
<4>[17288.993746] RIP: 0033:0x7f6138534cfe
<4>[17288.993750] Code: 48 8b 0d 25 c1 0d 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d f2 c0 0d 00 f7 d8 64 89 01 48
All code
========
   0:	48 8b 0d 25 c1 0d 00 	mov    0xdc125(%rip),%rcx        # 0xdc12c
   7:	f7 d8                	neg    %eax
   9:	64 89 01             	mov    %eax,%fs:(%rcx)
   c:	48 83 c8 ff          	or     $0xffffffffffffffff,%rax
  10:	c3                   	ret
  11:	66 2e 0f 1f 84 00 00 	cs nopw 0x0(%rax,%rax,1)
  18:	00 00 00 
  1b:	90                   	nop
  1c:	f3 0f 1e fa          	endbr64
  20:	49 89 ca             	mov    %rcx,%r10
  23:	b8 a5 00 00 00       	mov    $0xa5,%eax
  28:	0f 05                	syscall
  2a:*	48 3d 01 f0 ff ff    	cmp    $0xfffffffffffff001,%rax		<-- trapping instruction
  30:	73 01                	jae    0x33
  32:	c3                   	ret
  33:	48 8b 0d f2 c0 0d 00 	mov    0xdc0f2(%rip),%rcx        # 0xdc12c
  3a:	f7 d8                	neg    %eax
  3c:	64 89 01             	mov    %eax,%fs:(%rcx)
  3f:	48                   	rex.W

Code starting with the faulting instruction
===========================================
   0:	48 3d 01 f0 ff ff    	cmp    $0xfffffffffffff001,%rax
   6:	73 01                	jae    0x9
   8:	c3                   	ret
   9:	48 8b 0d f2 c0 0d 00 	mov    0xdc0f2(%rip),%rcx        # 0xdc102
  10:	f7 d8                	neg    %eax
  12:	64 89 01             	mov    %eax,%fs:(%rcx)
  15:	48                   	rex.W
<4>[17288.993752] RSP: 002b:00007ffe1b57ac18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
<4>[17288.993757] RAX: ffffffffffffffda RBX: 000055d41b8ba940 RCX: 00007f6138534cfe
<4>[17288.993759] RDX: 000055d41b8baed0 RSI: 000055d41b8baf40 RDI: 000055d41b8baef0
<4>[17288.993761] RBP: 00007ffe1b57ac80 R08: 000055d41b8bbd40 R09: 0000000000000001
<4>[17288.993763] R10: 0000000000000400 R11: 0000000000000246 R12: 000055d41b8baef0
<4>[17288.993765] R13: 000055d41b8baf40 R14: 000055d41b8baed0 R15: 000055d41b8baaa0
<4>[17288.993771]  </TASK>
<4>[17288.993772] ---[ end trace ]---
<1>[17288.993776] BUG: kernel NULL pointer dereference, address: 0000000000000000
<1>[17288.993778] #PF: supervisor read access in kernel mode
<1>[17288.993781] #PF: error_code(0x0000) - not-present page
<6>[17288.993784] PGD 0 P4D 0
<4>[17288.993788] Oops: Oops: 0000 [#1] PREEMPT SMP NOPTI
<4>[17288.993792] CPU: 0 UID: 0 PID: 11725 Comm: mount Kdump: loaded Tainted: G        W   E      6.12.1-g2p #102
Oops#1 Part5
<4>[17288.993796] Tainted: [W]=WARN, [E]=UNSIGNED_MODULE
<4>[17288.993798] Hardware name: To Be Filled By O.E.M. X570 Phantom Gaming 4/X570 Phantom Gaming 4, BIOS P5.61 02/22/2024
<4>[17288.993801] RIP: 0010:bch2_btree_path_traverse_one (fs/bcachefs/btree_iter.c:733 (discriminator 2) fs/bcachefs/btree_iter.c:1190 (discriminator 2)) 
<4>[17288.993805] Code: 89 f3 83 e6 1f 83 e3 1f 83 fe 14 0f 87 9c 06 00 00 48 83 fe 16 0f 83 93 0f 00 00 0f b6 db 48 c1 e3 07 49 8d b4 1e 18 09 00 00 <4c> 8b 3e 4d 85 ff 0f 84 9c 06 00 00 4d 89 ee 4d 89 e5 4d 89 fc 49
All code
========
   0:	89 f3                	mov    %esi,%ebx
   2:	83 e6 1f             	and    $0x1f,%esi
   5:	83 e3 1f             	and    $0x1f,%ebx
   8:	83 fe 14             	cmp    $0x14,%esi
   b:	0f 87 9c 06 00 00    	ja     0x6ad
  11:	48 83 fe 16          	cmp    $0x16,%rsi
  15:	0f 83 93 0f 00 00    	jae    0xfae
  1b:	0f b6 db             	movzbl %bl,%ebx
  1e:	48 c1 e3 07          	shl    $0x7,%rbx
  22:	49 8d b4 1e 18 09 00 	lea    0x918(%r14,%rbx,1),%rsi
  29:	00 
  2a:*	4c 8b 3e             	mov    (%rsi),%r15		<-- trapping instruction
  2d:	4d 85 ff             	test   %r15,%r15
  30:	0f 84 9c 06 00 00    	je     0x6d2
  36:	4d 89 ee             	mov    %r13,%r14
  39:	4d 89 e5             	mov    %r12,%r13
  3c:	4d 89 fc             	mov    %r15,%r12
  3f:	49                   	rex.WB

Code starting with the faulting instruction
===========================================
   0:	4c 8b 3e             	mov    (%rsi),%r15
   3:	4d 85 ff             	test   %r15,%r15
   6:	0f 84 9c 06 00 00    	je     0x6a8
   c:	4d 89 ee             	mov    %r13,%r14
   f:	4d 89 e5             	mov    %r12,%r13
  12:	4d 89 fc             	mov    %r15,%r12
  15:	49                   	rex.WB
<4>[17288.993808] RSP: 0018:ffffab7301bef050 EFLAGS: 00010246
<4>[17288.993811] RAX: 0000000000000000 RBX: 0000000000000015 RCX: 0000000000000000
<4>[17288.993814] RDX: 0000000000000010 RSI: 0000000000000000 RDI: 0000000000000000
<4>[17288.993816] RBP: ffffab7301bef178 R08: 0000000000000002 R09: ffff9a41dc67c000
<4>[17288.993819] R10: 0000000000000004 R11: 0000000000000004 R12: ffff9a41dc67c370
<4>[17288.993821] R13: ffff9a41dc67c000 R14: ffff9a41caac0000 R15: ffffab73196b7030
<4>[17288.993824] FS:  00007f61386b2800(0000) GS:ffff9a44eec00000(0000) knlGS:0000000000000000
<4>[17288.993827] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[17288.993829] CR2: 0000000000000000 CR3: 00000003ab438000 CR4: 0000000000350ef0
<4>[17288.993832] Call Trace:
<4>[17288.993834]  <TASK>
<4>[17288.993836] ? __die_body.cold (arch/x86/kernel/dumpstack.c:478 (discriminator 1) arch/x86/kernel/dumpstack.c:465 (discriminator 1) arch/x86/kernel/dumpstack.c:420 (discriminator 1)) 
<4>[17288.993842] ? __die (arch/x86/kernel/dumpstack.c:435) 
<4>[17288.993846] ? page_fault_oops (arch/x86/mm/fault.c:711 (discriminator 1)) 
<4>[17288.993851] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993857] ? do_user_addr_fault (arch/x86/mm/fault.c:1236) 
<4>[17288.993863] ? exc_page_fault (./arch/x86/include/asm/irqflags.h:37 ./arch/x86/include/asm/irqflags.h:92 arch/x86/mm/fault.c:1489 arch/x86/mm/fault.c:1539) 
<4>[17288.993867] ? asm_exc_page_fault (./arch/x86/include/asm/idtentry.h:623) 
Oops#1 Part4
<4>[17288.993873] ? bch2_btree_path_traverse_one (fs/bcachefs/btree_iter.c:733 (discriminator 2) fs/bcachefs/btree_iter.c:1190 (discriminator 2)) 
<4>[17288.993878] ? bch2_btree_path_traverse_one (fs/bcachefs/six.h:207 (discriminator 1) fs/bcachefs/btree_locking.h:287 (discriminator 1) fs/bcachefs/btree_iter.c:755 (discriminator 1) fs/bcachefs/btree_iter.c:1190 (discriminator 1)) 
<4>[17288.993882] ? bch2_btree_write_buffer_flush_locked (fs/bcachefs/btree_write_buffer.c:170 fs/bcachefs/btree_write_buffer.c:377) 
<4>[17288.993887] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993890] ? bch2_btree_path_upgrade_noupgrade_sibs (fs/bcachefs/btree_locking.c:627) 
<4>[17288.993893] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993896] ? bch2_path_get (fs/bcachefs/btree_iter.c:1808) 
<4>[17288.993900] ? bch2_btree_write_buffer_flush_locked (fs/bcachefs/btree_write_buffer.c:363) 
<4>[17288.993907] bch2_btree_iter_traverse (fs/bcachefs/btree_iter.c:1901) 
<4>[17288.993912] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993915] bch2_btree_write_buffer_flush_locked (fs/bcachefs/btree_write_buffer.c:170 fs/bcachefs/btree_write_buffer.c:377) 
<4>[17288.993922] ? __bch2_next_write_buffer_flush_journal_buf (./include/linux/err.h:81 (discriminator 1) fs/bcachefs/journal.c:965 (discriminator 1)) 
<4>[17288.993930] btree_write_buffer_flush_seq (fs/bcachefs/btree_write_buffer.c:550) 
<4>[17288.993936] bch2_btree_write_buffer_flush_sync (fs/bcachefs/btree_write_buffer.c:576) 
<4>[17288.993941] bch2_btree_write_buffer_maybe_flush (fs/bcachefs/btree_write_buffer.c:643) 
<4>[17288.993948] check_bp_exists (fs/bcachefs/backpointers.c:472) 
<4>[17288.993951] ? local_clock_noinstr (kernel/sched/clock.c:301 (discriminator 1)) 
<4>[17288.993955] ? local_clock (./arch/x86/include/asm/preempt.h:94 (discriminator 1) kernel/sched/clock.c:316 (discriminator 1)) 
<4>[17288.993966] check_extent_to_backpointers (fs/bcachefs/backpointers.c:594) 
<4>[17288.993969] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.993972] ? check_extent_to_backpointers (fs/bcachefs/backpointers.c:594) 
<4>[17288.993981] bch2_check_extents_to_backpointers_pass (fs/bcachefs/backpointers.c:790 (discriminator 1)) 
<4>[17288.993991] bch2_check_extents_to_backpointers (fs/bcachefs/backpointers.c:1077) 
<4>[17288.993994] ? __wake_up_klogd.part.0 (./arch/x86/include/asm/preempt.h:94 (discriminator 1) kernel/printk/printk.c:4495 (discriminator 1)) 
<4>[17288.994003] bch2_run_recovery_pass (fs/bcachefs/recovery_passes.c:223) 
<4>[17288.994007] bch2_run_recovery_passes (fs/bcachefs/recovery_passes.c:285) 
<4>[17288.994011] bch2_fs_recovery (fs/bcachefs/recovery.c:937) 
<4>[17288.994019] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994022] ? bch2_recalc_capacity (fs/bcachefs/alloc_background.c:2473) 
Oops#1 Part3
<4>[17288.994027] bch2_fs_start (fs/bcachefs/super.c:1034) 
<4>[17288.994032] bch2_fs_get_tree (fs/bcachefs/fs.c:2201) 
<4>[17288.994043] vfs_get_tree (fs/super.c:1815) 
<4>[17288.994047] path_mount (fs/namespace.c:3508 fs/namespace.c:3834) 
<4>[17288.994051] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994055] __x64_sys_mount (fs/namespace.c:3848 fs/namespace.c:4057 fs/namespace.c:4034 fs/namespace.c:4034) 
<4>[17288.994060] x64_sys_call (arch/x86/entry/syscall_64.c:36) 
<4>[17288.994064] do_syscall_64 (arch/x86/entry/common.c:52 (discriminator 1) arch/x86/entry/common.c:83 (discriminator 1)) 
<4>[17288.994068] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994071] ? syscall_exit_to_user_mode (./arch/x86/include/asm/entry-common.h:57 (discriminator 1) ./arch/x86/include/asm/entry-common.h:65 (discriminator 1) ./include/linux/entry-common.h:330 (discriminator 1) kernel/entry/common.c:207 (discriminator 1) kernel/entry/common.c:218 (discriminator 1)) 
<4>[17288.994074] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994077] ? do_syscall_64 (arch/x86/entry/common.c:102) 
<4>[17288.994084] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994086] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994089] ? syscall_exit_to_user_mode (./arch/x86/include/asm/entry-common.h:57 (discriminator 1) ./arch/x86/include/asm/entry-common.h:65 (discriminator 1) ./include/linux/entry-common.h:330 (discriminator 1) kernel/entry/common.c:207 (discriminator 1) kernel/entry/common.c:218 (discriminator 1)) 
<4>[17288.994093] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994095] ? do_syscall_64 (arch/x86/entry/common.c:102) 
<4>[17288.994099] ? syscall_exit_to_user_mode (./arch/x86/include/asm/entry-common.h:57 (discriminator 1) ./arch/x86/include/asm/entry-common.h:65 (discriminator 1) ./include/linux/entry-common.h:330 (discriminator 1) kernel/entry/common.c:207 (discriminator 1) kernel/entry/common.c:218 (discriminator 1)) 
<4>[17288.994102] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994105] ? do_syscall_64 (arch/x86/entry/common.c:102) 
<4>[17288.994108] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994111] ? do_syscall_64 (arch/x86/entry/common.c:102) 
<4>[17288.994115] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994117] ? irqentry_exit_to_user_mode (./arch/x86/include/asm/entry-common.h:57 (discriminator 1) ./arch/x86/include/asm/entry-common.h:65 (discriminator 1) ./include/linux/entry-common.h:330 (discriminator 1) kernel/entry/common.c:231 (discriminator 1)) 
<4>[17288.994121] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994124] ? irqentry_exit (kernel/entry/common.c:367) 
<4>[17288.994127] ? srso_return_thunk (arch/x86/lib/retpoline.S:224) 
<4>[17288.994129] ? exc_page_fault (arch/x86/mm/fault.c:1543) 
<4>[17288.994133] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:130) 
<4>[17288.994137] RIP: 0033:0x7f6138534cfe
<4>[17288.994139] Code: 48 8b 0d 25 c1 0d 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d f2 c0 0d 00 f7 d8 64 89 01 48
All code
========
   0:	48 8b 0d 25 c1 0d 00 	mov    0xdc125(%rip),%rcx        # 0xdc12c
   7:	f7 d8                	neg    %eax
   9:	64 89 01             	mov    %eax,%fs:(%rcx)
   c:	48 83 c8 ff          	or     $0xffffffffffffffff,%rax
  10:	c3                   	ret
  11:	66 2e 0f 1f 84 00 00 	cs nopw 0x0(%rax,%rax,1)
  18:	00 00 00 
  1b:	90                   	nop
  1c:	f3 0f 1e fa          	endbr64
  20:	49 89 ca             	mov    %rcx,%r10
  23:	b8 a5 00 00 00       	mov    $0xa5,%eax
  28:	0f 05                	syscall
  2a:*	48 3d 01 f0 ff ff    	cmp    $0xfffffffffffff001,%rax		<-- trapping instruction
  30:	73 01                	jae    0x33
  32:	c3                   	ret
  33:	48 8b 0d f2 c0 0d 00 	mov    0xdc0f2(%rip),%rcx        # 0xdc12c
  3a:	f7 d8                	neg    %eax
  3c:	64 89 01             	mov    %eax,%fs:(%rcx)
  3f:	48                   	rex.W

Code starting with the faulting instruction
===========================================
   0:	48 3d 01 f0 ff ff    	cmp    $0xfffffffffffff001,%rax
   6:	73 01                	jae    0x9
   8:	c3                   	ret
   9:	48 8b 0d f2 c0 0d 00 	mov    0xdc0f2(%rip),%rcx        # 0xdc102
  10:	f7 d8                	neg    %eax
  12:	64 89 01             	mov    %eax,%fs:(%rcx)
  15:	48                   	rex.W
Oops#1 Part2
<4>[17288.994142] RSP: 002b:00007ffe1b57ac18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
<4>[17288.994146] RAX: ffffffffffffffda RBX: 000055d41b8ba940 RCX: 00007f6138534cfe
<4>[17288.994148] RDX: 000055d41b8baed0 RSI: 000055d41b8baf40 RDI: 000055d41b8baef0
<4>[17288.994151] RBP: 00007ffe1b57ac80 R08: 000055d41b8bbd40 R09: 0000000000000001
<4>[17288.994153] R10: 0000000000000400 R11: 0000000000000246 R12: 000055d41b8baef0
<4>[17288.994156] R13: 000055d41b8baf40 R14: 000055d41b8baed0 R15: 000055d41b8baaa0
<4>[17288.994162]  </TASK>


@thememika
Copy link

@g2p Could I just ask, how do you make the kernel show the relevant source files in backtraces? And the All code thing? Is it some patch to kernel, or a config option I've never heard about? Thanks

@g2p
Copy link
Contributor Author

g2p commented Dec 3, 2024

@thememika I get logs from journalctl or pstore (look at /usr/lib/tmpfiles.d/systemd-pstore.conf to enable), then I pipe them through scripts/decode_stacktrace.sh vmlinux from the kernel source tree.

@g2p
Copy link
Contributor Author

g2p commented Dec 7, 2024

I couldn't reproduce the bug, on the same kernel build (of a6c9019 merged with 6.12.1) the upgrade went through the next time I tried (also with fsck,fix_errors).

Nothing particular in the logs for the successful mount, either.
Here are errors logged on the superblock, only the accounting_mismatch is newer:

errors (size 72):
accounting_mismatch                         30              Fri Dec  6 15:57:22 2024
accounting_key_junk_at_end                  72              Sun Aug 11 10:33:02 2024
accounting_key_replicas_nr_devs_0           16              Sun Aug 11 10:33:02 2024
accounting_key_version_0                    10              Sun Sep 29 09:58:41 2024

@g2p
Copy link
Contributor Author

g2p commented Dec 7, 2024

The first time with the crash, I was mounting two filesystems at the same time, and the upgrades (from 1.13 to 1.18) were eating up memory. Next time, I was cautious and did them sequentially, another filesystem did its upgrade okay, the one that had crashed before crashed again near the end. And on a third boot, that filesystem was able to upgrade.

So it might have been related to memory pressure.
CONFIG_COMPACTION is on. Also the filesystems use reflinks (fclones deduplication), and the one that crashed has 1.7 million files.

Btree usage:
reflink: 1.46 GiB
subvolumes: 256 KiB
snapshots: 256 KiB
lru: 19.0 MiB
freespace: 2.50 MiB
need_discard: 512 KiB
backpointers: 17.2 GiB
bucket_gens: 15.8 MiB
snapshot_trees: 256 KiB
deleted_inodes: 256 KiB
logged_ops: 512 KiB
rebalance_work: 768 KiB
accounting: 1.50 MiB
btree: 1/1 1 [dm-17] 24.2 GiB
user: 1/1 1 [dm-17] 7.88 TiB
btree: 1/1 1 [dm-16] 28.1 GiB
user: 1/1 1 [dm-16] 581 MiB
cached: 1/1 1 [dm-16] 95.6 GiB

@g2p
Copy link
Contributor Author

g2p commented Dec 7, 2024

Link to another report of the same crash, also during the 1.13 to 1.18 upgrade: https://gist.github.com/noradtux/cb4f4a0234d2cd91871cb56714add986/

@g2p g2p changed the title Oops inside check_extent_to_backpointers Oops inside check_extent_to_backpointers during 1.13 → 1.18 upgrade Dec 7, 2024
@g2p
Copy link
Contributor Author

g2p commented Dec 10, 2024

Tried to reproduce, downgrade went well, upgrade failed to mount with this error reported in dmesg:

12:30:56.916511: bcachefs (fff…): extents_to_backpointers: 12%, done 14783/116807 nodes, at extents:134351211:619088:U32_MAX  
12:31:06.696502: bcachefs (fff…): corrupt btree node before write at btree stripes level 0/0                                  
12:31:06.696748:   u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq c7d40b67d356047 written 8 min_key POS_MIN durability: 1 ptr: 1:298187:0 gen 51         
12:31:06.697669:   node offset 8/8 bset u64s 341 bset byte offset 40: invalid bkey format 35                                                                  
12:31:06.697941: bcachefs (fff…): inconsistency detected - emergency read only at journal seq 14866772                        

@koverstreet
Copy link
Owner

Just pinged you on IRC - can you get me a metadata dump? There's some funny corruption going on, and this isn't showing up in my upgrade test.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants