* bcache-register hang after reboot
@ 2021-11-10 5:44 Nikhil Kshirsagar
2021-11-10 20:13 ` Kent Overstreet
0 siblings, 1 reply; 10+ messages in thread
From: Nikhil Kshirsagar @ 2021-11-10 5:44 UTC (permalink / raw)
To: linux-bcache
Hello,
After a reboot of an Ubuntu server running 4.15.0-143-generic kernel,
the storage devices using bcache do not come back up and the following
stack traces are seen in kern.log. Please could someone help me
understand if this is due to a full bcache journal? Is there any
workaround, or fix?
Nov 5 05:48:20 kernel: [ 242.651880] INFO: task bcache-register:943
blocked for more than 120 seconds.
Nov 5 05:48:20 kernel: [ 242.655071] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:20 kernel: [ 242.656717] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:20 kernel: [ 242.658380] bcache-register D 0 943
1 0x00000006
Nov 5 05:48:20 kernel: [ 242.658385] Call Trace:
Nov 5 05:48:20 kernel: [ 242.658398] __schedule+0x24e/0x890
Nov 5 05:48:20 kernel: [ 242.658403] schedule+0x2c/0x80
Nov 5 05:48:20 kernel: [ 242.658424] closure_sync+0x18/0x90 [bcache]
Nov 5 05:48:20 kernel: [ 242.658439] bch_journal+0x123/0x380 [bcache]
Nov 5 05:48:20 kernel: [ 242.658453] bch_journal_meta+0x47/0x70 [bcache]
Nov 5 05:48:20 kernel: [ 242.658461] ? __switch_to+0x123/0x4e0
Nov 5 05:48:20 kernel: [ 242.658465] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:20 kernel: [ 242.658467] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:20 kernel: [ 242.658473] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.658477] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.658480] ? mutex_lock+0x2f/0x40
Nov 5 05:48:20 kernel: [ 242.658494] bch_btree_set_root+0x1c2/0x1f0 [bcache]
Nov 5 05:48:20 kernel: [ 242.658506] btree_split+0x69a/0x700 [bcache]
Nov 5 05:48:20 kernel: [ 242.658509] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:20 kernel: [ 242.658511] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:20 kernel: [ 242.658513] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:20 kernel: [ 242.658516] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:20 kernel: [ 242.658518] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:20 kernel: [ 242.658520] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:20 kernel: [ 242.658524] ? _cond_resched+0x19/0x40
Nov 5 05:48:20 kernel: [ 242.658528] ? __mutex_lock.isra.5+0x431/0x4e0
Nov 5 05:48:20 kernel: [ 242.658532] ? __switch_to+0x123/0x4e0
Nov 5 05:48:20 kernel: [ 242.658534] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:20 kernel: [ 242.658536] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:20 kernel: [ 242.658538] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:20 kernel: [ 242.658549]
bch_btree_insert_node+0x340/0x410 [bcache]
Nov 5 05:48:20 kernel: [ 242.658561] btree_split+0x551/0x700 [bcache]
Nov 5 05:48:20 kernel: [ 242.658568] ? __internal_add_timer+0x1f/0x60
Nov 5 05:48:20 kernel: [ 242.658572] ? add_timer+0x124/0x2b0
Nov 5 05:48:20 kernel: [ 242.658583]
bch_btree_insert_node+0x340/0x410 [bcache]
Nov 5 05:48:20 kernel: [ 242.658595] btree_insert_fn+0x24/0x40 [bcache]
Nov 5 05:48:20 kernel: [ 242.658607]
bch_btree_map_nodes_recurse+0x54/0x190 [bcache]
Nov 5 05:48:20 kernel: [ 242.658618] ?
bch_btree_insert_check_key+0x1f0/0x1f0 [bcache]
Nov 5 05:48:20 kernel: [ 242.658622] ? _cond_resched+0x19/0x40
Nov 5 05:48:20 kernel: [ 242.658626] ? down_write+0x12/0x40
Nov 5 05:48:20 kernel: [ 242.658637] ?
bch_btree_node_get+0x80/0x280 [bcache]
Nov 5 05:48:20 kernel: [ 242.658642] ? up_read+0x30/0x30
Nov 5 05:48:20 kernel: [ 242.658653]
bch_btree_map_nodes_recurse+0x112/0x190 [bcache]
Nov 5 05:48:20 kernel: [ 242.658663] ?
bch_btree_insert_check_key+0x1f0/0x1f0 [bcache]
Nov 5 05:48:20 kernel: [ 242.658675]
__bch_btree_map_nodes+0xf0/0x150 [bcache]
Nov 5 05:48:20 kernel: [ 242.658685] ?
bch_btree_insert_check_key+0x1f0/0x1f0 [bcache]
Nov 5 05:48:20 kernel: [ 242.658696] bch_btree_insert+0xf9/0x170 [bcache]
Nov 5 05:48:20 kernel: [ 242.658701] ? wait_woken+0x80/0x80
Nov 5 05:48:20 kernel: [ 242.658714] bch_journal_replay+0x220/0x2f0 [bcache]
Nov 5 05:48:20 kernel: [ 242.658720] ? sched_clock_cpu+0x11/0xb0
Nov 5 05:48:20 kernel: [ 242.658723] ? try_to_wake_up+0x59/0x4a0
Nov 5 05:48:20 kernel: [ 242.658739] run_cache_set+0x5d6/0x990 [bcache]
Nov 5 05:48:20 kernel: [ 242.658752] register_bcache+0xd04/0x1110 [bcache]
Nov 5 05:48:20 kernel: [ 242.658764] ? register_bcache+0xd04/0x1110 [bcache]
Nov 5 05:48:20 kernel: [ 242.658769] ? __handle_mm_fault+0xf43/0x1290
Nov 5 05:48:20 kernel: [ 242.658776] kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.658780] ? kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.658784] sysfs_kf_write+0x3c/0x50
Nov 5 05:48:20 kernel: [ 242.658787] kernfs_fop_write+0x125/0x1a0
Nov 5 05:48:20 kernel: [ 242.658791] __vfs_write+0x1b/0x40
Nov 5 05:48:20 kernel: [ 242.658794] vfs_write+0xb1/0x1a0
Nov 5 05:48:20 kernel: [ 242.658797] SyS_write+0x5c/0xe0
Nov 5 05:48:20 kernel: [ 242.658802] do_syscall_64+0x73/0x130
Nov 5 05:48:20 kernel: [ 242.658806]
entry_SYSCALL_64_after_hwframe+0x41/0xa6
Nov 5 05:48:20 kernel: [ 242.658809] RIP: 0033:0x7f9942e96224
Nov 5 05:48:20 kernel: [ 242.658811] RSP: 002b:00007ffc32a525e8
EFLAGS: 00000246 ORIG_RAX: 0000000000000001
Nov 5 05:48:20 kernel: [ 242.658815] RAX: ffffffffffffffda RBX:
000000000000000d RCX: 00007f9942e96224
Nov 5 05:48:20 kernel: [ 242.658816] RDX: 000000000000000d RSI:
000055e5e081c260 RDI: 0000000000000003
Nov 5 05:48:20 kernel: [ 242.658818] RBP: 000055e5e081c260 R08:
0000000000000000 R09: 000000000000000c
Nov 5 05:48:20 kernel: [ 242.658819] R10: 00000000fffffff4 R11:
0000000000000246 R12: 00007ffc32a52680
Nov 5 05:48:20 kernel: [ 242.658821] R13: 000000000000000d R14:
00007f994316e2a0 R15: 00007f994316d760
Nov 5 05:48:20 kernel: [ 242.658829] INFO: task bcache-register:969
blocked for more than 120 seconds.
Nov 5 05:48:20 kernel: [ 242.660133] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:20 kernel: [ 242.661251] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:20 kernel: [ 242.662390] bcache-register D 0 969
1 0x00000004
Nov 5 05:48:20 kernel: [ 242.662393] Call Trace:
Nov 5 05:48:20 kernel: [ 242.662399] __schedule+0x24e/0x890
Nov 5 05:48:20 kernel: [ 242.662405] ? find_get_entry+0x1e/0x110
Nov 5 05:48:20 kernel: [ 242.662409] schedule+0x2c/0x80
Nov 5 05:48:20 kernel: [ 242.662412] schedule_preempt_disabled+0xe/0x10
Nov 5 05:48:20 kernel: [ 242.662414] __mutex_lock.isra.5+0x276/0x4e0
Nov 5 05:48:20 kernel: [ 242.662421] ? alloc_pages_current+0x6a/0xe0
Nov 5 05:48:20 kernel: [ 242.662424] __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.662427] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.662429] mutex_lock+0x2f/0x40
Nov 5 05:48:20 kernel: [ 242.662441] register_bcache+0x412/0x1110 [bcache]
Nov 5 05:48:20 kernel: [ 242.662445] ? __handle_mm_fault+0xf43/0x1290
Nov 5 05:48:20 kernel: [ 242.662450] kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.662453] ? kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.662455] sysfs_kf_write+0x3c/0x50
Nov 5 05:48:20 kernel: [ 242.662458] kernfs_fop_write+0x125/0x1a0
Nov 5 05:48:20 kernel: [ 242.662461] __vfs_write+0x1b/0x40
Nov 5 05:48:20 kernel: [ 242.662462] vfs_write+0xb1/0x1a0
Nov 5 05:48:20 kernel: [ 242.662465] SyS_write+0x5c/0xe0
Nov 5 05:48:20 kernel: [ 242.662470] do_syscall_64+0x73/0x130
Nov 5 05:48:20 kernel: [ 242.662472]
entry_SYSCALL_64_after_hwframe+0x41/0xa6
Nov 5 05:48:20 kernel: [ 242.662474] RIP: 0033:0x7f8695ceb224
Nov 5 05:48:20 kernel: [ 242.662475] RSP: 002b:00007ffe9698dd58
EFLAGS: 00000246 ORIG_RAX: 0000000000000001
Nov 5 05:48:20 kernel: [ 242.662477] RAX: ffffffffffffffda RBX:
0000000000000009 RCX: 00007f8695ceb224
Nov 5 05:48:20 kernel: [ 242.662478] RDX: 0000000000000009 RSI:
0000559670e98260 RDI: 0000000000000003
Nov 5 05:48:20 kernel: [ 242.662479] RBP: 0000559670e98260 R08:
0000000000000000 R09: 0000000000000008
Nov 5 05:48:20 kernel: [ 242.662480] R10: 00000000fffffff8 R11:
0000000000000246 R12: 00007ffe9698ddf0
Nov 5 05:48:20 kernel: [ 242.662481] R13: 0000000000000009 R14:
00007f8695fc32a0 R15: 00007f8695fc2760
Nov 5 05:48:20 kernel: [ 242.662485] INFO: task bcache-register:972
blocked for more than 120 seconds.
Nov 5 05:48:20 kernel: [ 242.663630] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:20 kernel: [ 242.664791] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:20 kernel: [ 242.665968] bcache-register D 0 972
1 0x00000004
Nov 5 05:48:20 kernel: [ 242.665971] Call Trace:
Nov 5 05:48:20 kernel: [ 242.665976] __schedule+0x24e/0x890
Nov 5 05:48:20 kernel: [ 242.665980] ? find_get_entry+0x1e/0x110
Nov 5 05:48:20 kernel: [ 242.665983] schedule+0x2c/0x80
Nov 5 05:48:20 kernel: [ 242.665986] schedule_preempt_disabled+0xe/0x10
Nov 5 05:48:20 kernel: [ 242.665988] __mutex_lock.isra.5+0x276/0x4e0
Nov 5 05:48:20 kernel: [ 242.665992] ? alloc_pages_current+0x6a/0xe0
Nov 5 05:48:20 kernel: [ 242.665995] __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.665997] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.666000] mutex_lock+0x2f/0x40
Nov 5 05:48:20 kernel: [ 242.666009] register_bcache+0x412/0x1110 [bcache]
Nov 5 05:48:20 kernel: [ 242.666012] ? __handle_mm_fault+0xf43/0x1290
Nov 5 05:48:20 kernel: [ 242.666016] kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.666019] ? kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.666021] sysfs_kf_write+0x3c/0x50
Nov 5 05:48:20 kernel: [ 242.666023] kernfs_fop_write+0x125/0x1a0
Nov 5 05:48:20 kernel: [ 242.666025] __vfs_write+0x1b/0x40
Nov 5 05:48:20 kernel: [ 242.666027] vfs_write+0xb1/0x1a0
Nov 5 05:48:20 kernel: [ 242.666029] SyS_write+0x5c/0xe0
Nov 5 05:48:20 kernel: [ 242.666033] do_syscall_64+0x73/0x130
Nov 5 05:48:20 kernel: [ 242.666035]
entry_SYSCALL_64_after_hwframe+0x41/0xa6
Nov 5 05:48:20 kernel: [ 242.666037] RIP: 0033:0x7fb36e40a224
Nov 5 05:48:20 kernel: [ 242.666038] RSP: 002b:00007ffdc09c03c8
EFLAGS: 00000246 ORIG_RAX: 0000000000000001
Nov 5 05:48:20 kernel: [ 242.666040] RAX: ffffffffffffffda RBX:
0000000000000009 RCX: 00007fb36e40a224
Nov 5 05:48:20 kernel: [ 242.666041] RDX: 0000000000000009 RSI:
000055ac39f14260 RDI: 0000000000000003
Nov 5 05:48:20 kernel: [ 242.666042] RBP: 000055ac39f14260 R08:
0000000000000000 R09: 0000000000000008
Nov 5 05:48:20 kernel: [ 242.666043] R10: 00000000fffffff8 R11:
0000000000000246 R12: 00007ffdc09c0460
Nov 5 05:48:20 kernel: [ 242.666044] R13: 0000000000000009 R14:
00007fb36e6e22a0 R15: 00007fb36e6e1760
Nov 5 05:48:20 kernel: [ 242.666047] INFO: task bcache-register:974
blocked for more than 120 seconds.
Nov 5 05:48:20 kernel: [ 242.667231] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:20 kernel: [ 242.668431] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:20 kernel: [ 242.669479] bcache-register D 0 974
1 0x00000004
Nov 5 05:48:20 kernel: [ 242.669481] Call Trace:
Nov 5 05:48:20 kernel: [ 242.669483] __schedule+0x24e/0x890
Nov 5 05:48:20 kernel: [ 242.669485] ? find_get_entry+0x1e/0x110
Nov 5 05:48:20 kernel: [ 242.669487] schedule+0x2c/0x80
Nov 5 05:48:20 kernel: [ 242.669488] schedule_preempt_disabled+0xe/0x10
Nov 5 05:48:20 kernel: [ 242.669489] __mutex_lock.isra.5+0x276/0x4e0
Nov 5 05:48:20 kernel: [ 242.669491] ? alloc_pages_current+0x6a/0xe0
Nov 5 05:48:20 kernel: [ 242.669492] __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.669493] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.669494] mutex_lock+0x2f/0x40
Nov 5 05:48:20 kernel: [ 242.669498] register_bcache+0x412/0x1110 [bcache]
Nov 5 05:48:20 kernel: [ 242.669501] ? __handle_mm_fault+0xf43/0x1290
Nov 5 05:48:20 kernel: [ 242.669503] kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.669504] ? kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.669505] sysfs_kf_write+0x3c/0x50
Nov 5 05:48:20 kernel: [ 242.669507] kernfs_fop_write+0x125/0x1a0
Nov 5 05:48:20 kernel: [ 242.669509] __vfs_write+0x1b/0x40
Nov 5 05:48:20 kernel: [ 242.669510] vfs_write+0xb1/0x1a0
Nov 5 05:48:20 kernel: [ 242.669511] SyS_write+0x5c/0xe0
Nov 5 05:48:20 kernel: [ 242.669512] do_syscall_64+0x73/0x130
Nov 5 05:48:20 kernel: [ 242.669513]
entry_SYSCALL_64_after_hwframe+0x41/0xa6
Nov 5 05:48:20 kernel: [ 242.669515] RIP: 0033:0x7f6669c01224
Nov 5 05:48:20 kernel: [ 242.669515] RSP: 002b:00007ffc30ac1ce8
EFLAGS: 00000246 ORIG_RAX: 0000000000000001
Nov 5 05:48:20 kernel: [ 242.669516] RAX: ffffffffffffffda RBX:
0000000000000009 RCX: 00007f6669c01224
Nov 5 05:48:20 kernel: [ 242.669517] RDX: 0000000000000009 RSI:
0000561588dc9260 RDI: 0000000000000003
Nov 5 05:48:20 kernel: [ 242.669517] RBP: 0000561588dc9260 R08:
0000000000000000 R09: 0000000000000008
Nov 5 05:48:20 kernel: [ 242.669517] R10: 00000000fffffff8 R11:
0000000000000246 R12: 00007ffc30ac1d80
Nov 5 05:48:20 kernel: [ 242.669518] R13: 0000000000000009 R14:
00007f6669ed92a0 R15: 00007f6669ed8760
Nov 5 05:48:20 kernel: [ 242.669520] INFO: task bcache-register:977
blocked for more than 120 seconds.
Nov 5 05:48:20 kernel: [ 242.670046] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:20 kernel: [ 242.670565] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:20 kernel: [ 242.671076] bcache-register D 0 977
1 0x00000004
Nov 5 05:48:20 kernel: [ 242.671077] Call Trace:
Nov 5 05:48:20 kernel: [ 242.671080] __schedule+0x24e/0x890
Nov 5 05:48:20 kernel: [ 242.671081] schedule+0x2c/0x80
Nov 5 05:48:20 kernel: [ 242.671083] schedule_preempt_disabled+0xe/0x10
Nov 5 05:48:20 kernel: [ 242.671084] __mutex_lock.isra.5+0x276/0x4e0
Nov 5 05:48:20 kernel: [ 242.671086] ? alloc_pages_current+0x6a/0xe0
Nov 5 05:48:20 kernel: [ 242.671087] __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.671088] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.671090] mutex_lock+0x2f/0x40
Nov 5 05:48:20 kernel: [ 242.671094] register_bcache+0x412/0x1110 [bcache]
Nov 5 05:48:20 kernel: [ 242.671096] ? __handle_mm_fault+0xf43/0x1290
Nov 5 05:48:20 kernel: [ 242.671098] kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.671099] ? kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.671100] sysfs_kf_write+0x3c/0x50
Nov 5 05:48:20 kernel: [ 242.671101] kernfs_fop_write+0x125/0x1a0
Nov 5 05:48:20 kernel: [ 242.671102] __vfs_write+0x1b/0x40
Nov 5 05:48:20 kernel: [ 242.671103] vfs_write+0xb1/0x1a0
Nov 5 05:48:20 kernel: [ 242.671103] SyS_write+0x5c/0xe0
Nov 5 05:48:20 kernel: [ 242.671105] do_syscall_64+0x73/0x130
Nov 5 05:48:20 kernel: [ 242.671106]
entry_SYSCALL_64_after_hwframe+0x41/0xa6
Nov 5 05:48:20 kernel: [ 242.671107] RIP: 0033:0x7f0111112224
Nov 5 05:48:20 kernel: [ 242.671107] RSP: 002b:00007fff2f21c788
EFLAGS: 00000246 ORIG_RAX: 0000000000000001
Nov 5 05:48:20 kernel: [ 242.671108] RAX: ffffffffffffffda RBX:
0000000000000009 RCX: 00007f0111112224
Nov 5 05:48:20 kernel: [ 242.671108] RDX: 0000000000000009 RSI:
0000564671709260 RDI: 0000000000000003
Nov 5 05:48:20 kernel: [ 242.671109] RBP: 0000564671709260 R08:
0000000000000000 R09: 0000000000000008
Nov 5 05:48:20 kernel: [ 242.671109] R10: 00000000fffffff8 R11:
0000000000000246 R12: 00007fff2f21c820
Nov 5 05:48:20 kernel: [ 242.671109] R13: 0000000000000009 R14:
00007f01113ea2a0 R15: 00007f01113e9760
Nov 5 05:48:20 kernel: [ 242.671111] INFO: task bcache-register:982
blocked for more than 120 seconds.
Nov 5 05:48:20 kernel: [ 242.671614] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:20 kernel: [ 242.672154] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:20 kernel: [ 242.672671] bcache-register D 0 982
1 0x00000004
Nov 5 05:48:20 kernel: [ 242.672672] Call Trace:
Nov 5 05:48:20 kernel: [ 242.672674] __schedule+0x24e/0x890
Nov 5 05:48:20 kernel: [ 242.672676] ? find_get_entry+0x1e/0x110
Nov 5 05:48:20 kernel: [ 242.672678] schedule+0x2c/0x80
Nov 5 05:48:20 kernel: [ 242.672679] schedule_preempt_disabled+0xe/0x10
Nov 5 05:48:20 kernel: [ 242.672680] __mutex_lock.isra.5+0x276/0x4e0
Nov 5 05:48:20 kernel: [ 242.672682] ? alloc_pages_current+0x6a/0xe0
Nov 5 05:48:20 kernel: [ 242.672683] __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.672684] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.672685] mutex_lock+0x2f/0x40
Nov 5 05:48:20 kernel: [ 242.672689] register_bcache+0x412/0x1110 [bcache]
Nov 5 05:48:20 kernel: [ 242.672691] ? __handle_mm_fault+0xf43/0x1290
Nov 5 05:48:20 kernel: [ 242.672693] kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.672694] ? kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.672695] sysfs_kf_write+0x3c/0x50
Nov 5 05:48:20 kernel: [ 242.672696] kernfs_fop_write+0x125/0x1a0
Nov 5 05:48:20 kernel: [ 242.672698] __vfs_write+0x1b/0x40
Nov 5 05:48:20 kernel: [ 242.672698] vfs_write+0xb1/0x1a0
Nov 5 05:48:20 kernel: [ 242.672700] SyS_write+0x5c/0xe0
Nov 5 05:48:20 kernel: [ 242.672702] do_syscall_64+0x73/0x130
Nov 5 05:48:20 kernel: [ 242.672703]
entry_SYSCALL_64_after_hwframe+0x41/0xa6
Nov 5 05:48:20 kernel: [ 242.672704] RIP: 0033:0x7f95ed5c9224
Nov 5 05:48:20 kernel: [ 242.672704] RSP: 002b:00007ffd801bf818
EFLAGS: 00000246 ORIG_RAX: 0000000000000001
Nov 5 05:48:20 kernel: [ 242.672705] RAX: ffffffffffffffda RBX:
0000000000000009 RCX: 00007f95ed5c9224
Nov 5 05:48:20 kernel: [ 242.672706] RDX: 0000000000000009 RSI:
00005580aa3d8260 RDI: 0000000000000003
Nov 5 05:48:20 kernel: [ 242.672706] RBP: 00005580aa3d8260 R08:
0000000000000000 R09: 0000000000000008
Nov 5 05:48:20 kernel: [ 242.672707] R10: 00000000fffffff8 R11:
0000000000000246 R12: 00007ffd801bf8b0
Nov 5 05:48:20 kernel: [ 242.672707] R13: 0000000000000009 R14:
00007f95ed8a12a0 R15: 00007f95ed8a0760
Nov 5 05:48:20 kernel: [ 242.672709] INFO: task bcache-register:986
blocked for more than 120 seconds.
Nov 5 05:48:20 kernel: [ 242.673210] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:20 kernel: [ 242.673676] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:20 kernel: [ 242.674138] bcache-register D 0 986
1 0x00000004
Nov 5 05:48:20 kernel: [ 242.674139] Call Trace:
Nov 5 05:48:20 kernel: [ 242.674142] __schedule+0x24e/0x890
Nov 5 05:48:20 kernel: [ 242.674143] ? find_get_entry+0x1e/0x110
Nov 5 05:48:20 kernel: [ 242.674145] schedule+0x2c/0x80
Nov 5 05:48:20 kernel: [ 242.674146] schedule_preempt_disabled+0xe/0x10
Nov 5 05:48:20 kernel: [ 242.674147] __mutex_lock.isra.5+0x276/0x4e0
Nov 5 05:48:20 kernel: [ 242.674148] ? alloc_pages_current+0x6a/0xe0
Nov 5 05:48:20 kernel: [ 242.674149] __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.674150] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:20 kernel: [ 242.674151] mutex_lock+0x2f/0x40
Nov 5 05:48:20 kernel: [ 242.674155] register_bcache+0x412/0x1110 [bcache]
Nov 5 05:48:20 kernel: [ 242.674157] ? __handle_mm_fault+0xf43/0x1290
Nov 5 05:48:20 kernel: [ 242.674159] kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.674160] ? kobj_attr_store+0x12/0x20
Nov 5 05:48:20 kernel: [ 242.674161] sysfs_kf_write+0x3c/0x50
Nov 5 05:48:20 kernel: [ 242.674162] kernfs_fop_write+0x125/0x1a0
Nov 5 05:48:20 kernel: [ 242.674163] __vfs_write+0x1b/0x40
Nov 5 05:48:20 kernel: [ 242.674164] vfs_write+0xb1/0x1a0
Nov 5 05:48:20 kernel: [ 242.674165] SyS_write+0x5c/0xe0
Nov 5 05:48:20 kernel: [ 242.674167] do_syscall_64+0x73/0x130
Nov 5 05:48:20 kernel: [ 242.674167]
entry_SYSCALL_64_after_hwframe+0x41/0xa6
Nov 5 05:48:20 kernel: [ 242.674168] RIP: 0033:0x7fb5a170d224
Nov 5 05:48:20 kernel: [ 242.674169] RSP: 002b:00007ffcd0691f78
EFLAGS: 00000246 ORIG_RAX: 0000000000000001
Nov 5 05:48:20 kernel: [ 242.674170] RAX: ffffffffffffffda RBX:
0000000000000009 RCX: 00007fb5a170d224
Nov 5 05:48:20 kernel: [ 242.674170] RDX: 0000000000000009 RSI:
000055b23525a260 RDI: 0000000000000003
Nov 5 05:48:20 kernel: [ 242.674171] RBP: 000055b23525a260 R08:
0000000000000000 R09: 0000000000000008
Nov 5 05:48:20 kernel: [ 242.674171] R10: 00000000fffffff8 R11:
0000000000000246 R12: 00007ffcd0692010
Nov 5 05:48:20 kernel: [ 242.674171] R13: 0000000000000009 R14:
00007fb5a19e52a0 R15: 00007fb5a19e4760
Nov 5 05:48:20 kernel: [ 242.674175] INFO: task
bcache_allocato:1029 blocked for more than 120 seconds.
Nov 5 05:48:20 kernel: [ 242.674630] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:20 kernel: [ 242.675072] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:20 kernel: [ 242.675521] bcache_allocato D 0 1029
2 0x80000000
Nov 5 05:48:20 kernel: [ 242.675522] Call Trace:
Nov 5 05:48:20 kernel: [ 242.675525] __schedule+0x24e/0x890
Nov 5 05:48:20 kernel: [ 242.675525] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:20 kernel: [ 242.675526] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:20 kernel: [ 242.675527] schedule+0x2c/0x80
Nov 5 05:48:20 kernel: [ 242.675532] closure_sync+0x18/0x90 [bcache]
Nov 5 05:48:20 kernel: [ 242.675535] bch_journal+0x123/0x380 [bcache]
Nov 5 05:48:20 kernel: [ 242.675536] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:20 kernel: [ 242.675539] bch_journal_meta+0x47/0x70 [bcache]
Nov 5 05:48:20 kernel: [ 242.675541] ? schedule+0x2c/0x80
Nov 5 05:48:20 kernel: [ 242.675544] ? closure_sync+0x18/0x90 [bcache]
Nov 5 05:48:20 kernel: [ 242.675547] ?
prio_io.constprop.32+0x116/0x140 [bcache]
Nov 5 05:48:20 kernel: [ 242.675548] ? _cond_resched+0x19/0x40
Nov 5 05:48:20 kernel: [ 242.675549] ? mutex_lock+0x12/0x40
Nov 5 05:48:20 kernel: [ 242.675553] bch_prio_write+0x304/0x470 [bcache]
Nov 5 05:48:20 kernel: [ 242.675556]
bch_allocator_thread+0x235/0x4c0 [bcache]
Nov 5 05:48:20 kernel: [ 242.675560] kthread+0x121/0x140
Nov 5 05:48:20 kernel: [ 242.675563] ?
invalidate_buckets+0x890/0x890 [bcache]
Nov 5 05:48:20 kernel: [ 242.675564] ?
kthread_create_worker_on_cpu+0x70/0x70
Nov 5 05:48:20 kernel: [ 242.675565] ret_from_fork+0x35/0x40
Nov 5 05:48:20 kernel: [ 330.909260] br-bond1: port 2(veth-br-data)
entered blocking state
Nov 5 05:48:20 kernel: [ 330.909264] br-bond1: port 2(veth-br-data)
entered disabled state
Nov 5 05:48:20 kernel: [ 330.909472] device veth-br-data entered
promiscuous mode
Nov 5 05:48:20 kernel: [ 330.913355] IPv6: ADDRCONF(NETDEV_UP):
veth-br-data: link is not ready
Nov 5 05:48:20 kernel: [ 330.933518] IPv6: ADDRCONF(NETDEV_UP):
veth-br-bond1: link is not ready
Nov 5 05:48:20 kernel: [ 330.933535] IPv6: ADDRCONF(NETDEV_CHANGE):
veth-br-bond1: link becomes ready
Nov 5 05:48:20 kernel: [ 330.933645] IPv6: ADDRCONF(NETDEV_CHANGE):
veth-br-data: link becomes ready
Nov 5 05:48:20 kernel: [ 330.933706] br-bond1: port 2(veth-br-data)
entered blocking state
Nov 5 05:48:20 kernel: [ 330.933710] br-bond1: port 2(veth-br-data)
entered forwarding state
Nov 5 05:48:20 kernel: [ 333.394130] new mount options do not match
the existing superblock, will be ignored
Nov 5 05:48:20 kernel: [ 333.738771] Process accounting resumed
Nov 5 05:48:24 kernel: [ 339.280833] openvswitch: Open vSwitch
switching datapath
Nov 5 05:48:24 kernel: [ 339.640280] device ovs-system entered
promiscuous mode
Nov 5 05:48:24 kernel: [ 340.122082] device br-int entered promiscuous mode
Nov 5 05:48:25 kernel: [ 340.512290] i40e 0000:09:00.0 eno1: port
4789 already offloaded
Nov 5 05:48:25 kernel: [ 340.512294] i40e 0000:09:00.1 eno2: port
4789 already offloaded
Nov 5 05:48:25 kernel: [ 340.512297] i40e 0000:2f:00.0 enp47s0f0:
port 4789 already offloaded
Nov 5 05:48:25 kernel: [ 340.512300] i40e 0000:2f:00.1 enp47s0f1:
port 4789 already offloaded
Nov 5 05:48:25 kernel: [ 340.512303] i40e 0000:58:00.0 enp88s0f0:
port 4789 already offloaded
Nov 5 05:48:25 kernel: [ 340.512305] i40e 0000:58:00.1 enp88s0f1:
port 4789 already offloaded
Nov 5 05:48:25 kernel: [ 340.512918] device vxlan_sys_4789 entered
promiscuous mode
Nov 5 05:48:25 kernel: [ 340.564171] device br-tun entered promiscuous mode
Nov 5 05:48:25 kernel: [ 340.570996] device br-ex entered promiscuous mode
Nov 5 05:48:25 kernel: [ 340.571508] device veth-br-bond1 entered
promiscuous mode
Nov 5 05:48:25 kernel: [ 340.577139] device br-data entered promiscuous mode
Nov 5 05:48:42 kernel: [ 357.672105] ip6_tables: (C) 2000-2006
Netfilter Core Team
Nov 5 05:48:43 kernel: [ 358.439969] Ebtables v2.0 registered
Nov 5 05:48:48 kernel: [ 363.490744] INFO: task bcache-register:943
blocked for more than 120 seconds.
Nov 5 05:48:48 kernel: [ 363.490806] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:48 kernel: [ 363.490848] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:48 kernel: [ 363.490904] bcache-register D 0 943
1 0x00000006
Nov 5 05:48:48 kernel: [ 363.490908] Call Trace:
Nov 5 05:48:48 kernel: [ 363.490920] __schedule+0x24e/0x890
Nov 5 05:48:48 kernel: [ 363.490926] schedule+0x2c/0x80
Nov 5 05:48:48 kernel: [ 363.490945] closure_sync+0x18/0x90 [bcache]
Nov 5 05:48:48 kernel: [ 363.490960] bch_journal+0x123/0x380 [bcache]
Nov 5 05:48:48 kernel: [ 363.490973] bch_journal_meta+0x47/0x70 [bcache]
Nov 5 05:48:48 kernel: [ 363.490980] ? __switch_to+0x123/0x4e0
Nov 5 05:48:48 kernel: [ 363.490984] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:48 kernel: [ 363.490986] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:48 kernel: [ 363.490991] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:48 kernel: [ 363.490995] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:48 kernel: [ 363.490999] ? mutex_lock+0x2f/0x40
Nov 5 05:48:48 kernel: [ 363.491012] bch_btree_set_root+0x1c2/0x1f0 [bcache]
Nov 5 05:48:48 kernel: [ 363.491024] btree_split+0x69a/0x700 [bcache]
Nov 5 05:48:48 kernel: [ 363.491026] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:48 kernel: [ 363.491028] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:48 kernel: [ 363.491030] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:48 kernel: [ 363.491034] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:48 kernel: [ 363.491036] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:48 kernel: [ 363.491038] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:48 kernel: [ 363.491041] ? _cond_resched+0x19/0x40
Nov 5 05:48:48 kernel: [ 363.491045] ? __mutex_lock.isra.5+0x431/0x4e0
Nov 5 05:48:48 kernel: [ 363.491049] ? __switch_to+0x123/0x4e0
Nov 5 05:48:48 kernel: [ 363.491051] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:48 kernel: [ 363.491053] ? __switch_to_asm+0x41/0x70
Nov 5 05:48:48 kernel: [ 363.491055] ? __switch_to_asm+0x35/0x70
Nov 5 05:48:48 kernel: [ 363.491067]
bch_btree_insert_node+0x340/0x410 [bcache]
Nov 5 05:48:48 kernel: [ 363.491078] btree_split+0x551/0x700 [bcache]
Nov 5 05:48:48 kernel: [ 363.491086] ? __internal_add_timer+0x1f/0x60
Nov 5 05:48:48 kernel: [ 363.491090] ? add_timer+0x124/0x2b0
Nov 5 05:48:48 kernel: [ 363.491101]
bch_btree_insert_node+0x340/0x410 [bcache]
Nov 5 05:48:48 kernel: [ 363.491113] btree_insert_fn+0x24/0x40 [bcache]
Nov 5 05:48:48 kernel: [ 363.491125]
bch_btree_map_nodes_recurse+0x54/0x190 [bcache]
Nov 5 05:48:48 kernel: [ 363.491136] ?
bch_btree_insert_check_key+0x1f0/0x1f0 [bcache]
Nov 5 05:48:48 kernel: [ 363.491139] ? _cond_resched+0x19/0x40
Nov 5 05:48:48 kernel: [ 363.491143] ? down_write+0x12/0x40
Nov 5 05:48:48 kernel: [ 363.491154] ?
bch_btree_node_get+0x80/0x280 [bcache]
Nov 5 05:48:48 kernel: [ 363.491159] ? up_read+0x30/0x30
Nov 5 05:48:48 kernel: [ 363.491170]
bch_btree_map_nodes_recurse+0x112/0x190 [bcache]
Nov 5 05:48:48 kernel: [ 363.491180] ?
bch_btree_insert_check_key+0x1f0/0x1f0 [bcache]
Nov 5 05:48:48 kernel: [ 363.491192]
__bch_btree_map_nodes+0xf0/0x150 [bcache]
Nov 5 05:48:48 kernel: [ 363.491202] ?
bch_btree_insert_check_key+0x1f0/0x1f0 [bcache]
Nov 5 05:48:48 kernel: [ 363.491213] bch_btree_insert+0xf9/0x170 [bcache]
Nov 5 05:48:48 kernel: [ 363.491217] ? wait_woken+0x80/0x80
Nov 5 05:48:48 kernel: [ 363.491230] bch_journal_replay+0x220/0x2f0 [bcache]
Nov 5 05:48:48 kernel: [ 363.491235] ? sched_clock_cpu+0x11/0xb0
Nov 5 05:48:48 kernel: [ 363.491238] ? try_to_wake_up+0x59/0x4a0
Nov 5 05:48:48 kernel: [ 363.491253] run_cache_set+0x5d6/0x990 [bcache]
Nov 5 05:48:48 kernel: [ 363.491267] register_bcache+0xd04/0x1110 [bcache]
Nov 5 05:48:48 kernel: [ 363.491278] ? register_bcache+0xd04/0x1110 [bcache]
Nov 5 05:48:48 kernel: [ 363.491283] ? __handle_mm_fault+0xf43/0x1290
Nov 5 05:48:48 kernel: [ 363.491289] kobj_attr_store+0x12/0x20
Nov 5 05:48:48 kernel: [ 363.491293] ? kobj_attr_store+0x12/0x20
Nov 5 05:48:48 kernel: [ 363.491297] sysfs_kf_write+0x3c/0x50
Nov 5 05:48:48 kernel: [ 363.491299] kernfs_fop_write+0x125/0x1a0
Nov 5 05:48:48 kernel: [ 363.491303] __vfs_write+0x1b/0x40
Nov 5 05:48:48 kernel: [ 363.491306] vfs_write+0xb1/0x1a0
Nov 5 05:48:48 kernel: [ 363.491309] SyS_write+0x5c/0xe0
Nov 5 05:48:48 kernel: [ 363.491314] do_syscall_64+0x73/0x130
Nov 5 05:48:48 kernel: [ 363.491317]
entry_SYSCALL_64_after_hwframe+0x41/0xa6
Nov 5 05:48:48 kernel: [ 363.491321] RIP: 0033:0x7f9942e96224
Nov 5 05:48:48 kernel: [ 363.491323] RSP: 002b:00007ffc32a525e8
EFLAGS: 00000246 ORIG_RAX: 0000000000000001
Nov 5 05:48:48 kernel: [ 363.491326] RAX: ffffffffffffffda RBX:
000000000000000d RCX: 00007f9942e96224
Nov 5 05:48:48 kernel: [ 363.491328] RDX: 000000000000000d RSI:
000055e5e081c260 RDI: 0000000000000003
Nov 5 05:48:48 kernel: [ 363.491329] RBP: 000055e5e081c260 R08:
0000000000000000 R09: 000000000000000c
Nov 5 05:48:48 kernel: [ 363.491331] R10: 00000000fffffff4 R11:
0000000000000246 R12: 00007ffc32a52680
Nov 5 05:48:48 kernel: [ 363.491333] R13: 000000000000000d R14:
00007f994316e2a0 R15: 00007f994316d760
Nov 5 05:48:48 kernel: [ 363.491340] INFO: task bcache-register:969
blocked for more than 120 seconds.
Nov 5 05:48:48 kernel: [ 363.491394] Not tainted
4.15.0-143-generic #147-Ubuntu
Nov 5 05:48:48 kernel: [ 363.491435] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 5 05:48:48 kernel: [ 363.491489] bcache-register D 0 969
1 0x00000004
Nov 5 05:48:48 kernel: [ 363.491492] Call Trace:
Nov 5 05:48:48 kernel: [ 363.491498] __schedule+0x24e/0x890
Nov 5 05:48:48 kernel: [ 363.491505] ? find_get_entry+0x1e/0x110
Nov 5 05:48:48 kernel: [ 363.491509] schedule+0x2c/0x80
Nov 5 05:48:48 kernel: [ 363.491513] schedule_preempt_disabled+0xe/0x10
Nov 5 05:48:48 kernel: [ 363.491517] __mutex_lock.isra.5+0x276/0x4e0
Nov 5 05:48:48 kernel: [ 363.491523] ? alloc_pages_current+0x6a/0xe0
Nov 5 05:48:48 kernel: [ 363.491528] __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:48 kernel: [ 363.491531] ? __mutex_lock_slowpath+0x13/0x20
Nov 5 05:48:48 kernel: [ 363.491535] mutex_lock+0x2f/0x40
Nov 5 05:48:48 kernel: [ 363.491548] register_bcache+0x412/0x1110 [bcache]
Nov 5 05:48:48 kernel: [ 363.491552] ? __handle_mm_fault+0xf43/0x1290
Nov 5 05:48:48 kernel: [ 363.491559] kobj_attr_store+0x12/0x20
Nov 5 05:48:48 kernel: [ 363.491562] ? kobj_attr_store+0x12/0x20
Nov 5 05:48:48 kernel: [ 363.491565] sysfs_kf_write+0x3c/0x50
Nov 5 05:48:48 kernel: [ 363.491568] kernfs_fop_write+0x125/0x1a0
Nov 5 05:48:48 kernel: [ 363.491571] __vfs_write+0x1b/0x40
Nov 5 05:48:48 kernel: [ 363.491574] vfs_write+0xb1/0x1a0
Nov 5 05:48:48 kernel: [ 363.491577] SyS_write+0x5c/0xe0
Nov 5 05:48:48 kernel: [ 363.491582] do_syscall_64+0x73/0x130
Nov 5 05:48:48 kernel: [ 363.491585]
entry_SYSCALL_64_after_hwframe+0x41/0xa6
Nov 5 05:48:48 kernel: [ 363.491587] RIP: 0033:0x7f8695ceb224
Nov 5 05:48:48 kernel: [ 363.491588] RSP: 002b:00007ffe9698dd58
EFLAGS: 00000246 ORIG_RAX: 0000000000000001
Nov 5 05:48:48 kernel: [ 363.491591] RAX: ffffffffffffffda RBX:
0000000000000009 RCX: 00007f8695ceb224
Nov 5 05:48:48 kernel: [ 363.491592] RDX: 0000000000000009 RSI:
0000559670e98260 RDI: 0000000000000003
Nov 5 05:48:48 kernel: [ 363.491594] RBP: 0000559670e98260 R08:
0000000000000000 R09: 0000000000000008
Nov 5 05:48:48 kernel: [ 363.491596] R10: 00000000fffffff8 R11:
0000000000000246 R12: 00007ffe9698ddf0
Nov 5 05:48:48 kernel: [ 363.491597] R13: 0000000000000009 R14:
00007f8695fc32a0 R15: 00007f8695fc2760
Regards,
Nikhil.
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: bcache-register hang after reboot
2021-11-10 5:44 bcache-register hang after reboot Nikhil Kshirsagar
@ 2021-11-10 20:13 ` Kent Overstreet
2021-11-11 20:54 ` Mauricio Oliveira
2021-11-12 5:45 ` Coly Li
0 siblings, 2 replies; 10+ messages in thread
From: Kent Overstreet @ 2021-11-10 20:13 UTC (permalink / raw)
To: Nikhil Kshirsagar; +Cc: linux-bcache
On Wed, Nov 10, 2021 at 11:14:41AM +0530, Nikhil Kshirsagar wrote:
> Hello,
>
> After a reboot of an Ubuntu server running 4.15.0-143-generic kernel,
> the storage devices using bcache do not come back up and the following
> stack traces are seen in kern.log. Please could someone help me
> understand if this is due to a full bcache journal? Is there any
> workaround, or fix?
Your journal is completely full, so persisting the new btree root while doing
journal replay is hanging.
There isn't a _good_ solution for this journal deadlock in bcache (it's fixed in
bcachefs), but there is a hack:
edit drivers/md/bcache/btree.c line 2493
delete the call to bch_journal_meta(), and build a new kernel. Once you've
gotten it to register, do a clean shutdown and then go back to a stock kernel.
Running the kernel with that call deleted won't be safe if you crash, but it'll
get you going again.
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: bcache-register hang after reboot
2021-11-10 20:13 ` Kent Overstreet
@ 2021-11-11 20:54 ` Mauricio Oliveira
2021-11-13 18:05 ` Kent Overstreet
2021-11-12 5:45 ` Coly Li
1 sibling, 1 reply; 10+ messages in thread
From: Mauricio Oliveira @ 2021-11-11 20:54 UTC (permalink / raw)
To: Kent Overstreet; +Cc: Nikhil Kshirsagar, linux-bcache
Hi Kent,
On Wed, Nov 10, 2021 at 5:13 PM Kent Overstreet
<kent.overstreet@gmail.com> wrote:
> Your journal is completely full, so persisting the new btree root while doing
> journal replay is hanging.
>
> There isn't a _good_ solution for this journal deadlock in bcache (it's fixed in
> bcachefs), but there is a hack:
>
> edit drivers/md/bcache/btree.c line 2493
>
> delete the call to bch_journal_meta(), and build a new kernel. Once you've
> gotten it to register, do a clean shutdown and then go back to a stock kernel.
>
> Running the kernel with that call deleted won't be safe if you crash, but it'll
> get you going again.
Thanks for the clarification and suggestions.
Would it be OK to implement that workaround if requested by a sysadmin ?
(say, to ack the data safety / crash risk)
Right now the issue is known, reproduces with v5.15, has no good solution,
remains after reboot, prints hung task warnings continuously, and prevents
using the device at all; and this workaround requires kernel dev/build skills.
Since its effects seem bad enough, it would seem fair enough to provide a
way out even if it's not a _good_ one.
Say, we could try and detect the journal full during journal replay, and handle
it by failing the device registration. This would unblock the tasks, and provide
a more intuitive error message. (maybe leading to the next paragraph.)
We could also add a sysfs tunable to skip the call to bch_journal_meta(),
and allow the registration to proceed, but fail it unconditionally in the end
so the device isn't used with data safety / crash risk
(or force an automatic unregister + register again w/ bch_journal_meta(),
and disable the sysfs tunable).
This would help with the full journal, and allow a sysadmin to perform the
workaround without kernel rebuild and reboots.
Thanks!
--
Mauricio Faria de Oliveira
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: bcache-register hang after reboot
2021-11-10 20:13 ` Kent Overstreet
2021-11-11 20:54 ` Mauricio Oliveira
@ 2021-11-12 5:45 ` Coly Li
2021-11-13 18:12 ` Kent Overstreet
1 sibling, 1 reply; 10+ messages in thread
From: Coly Li @ 2021-11-12 5:45 UTC (permalink / raw)
To: Kent Overstreet; +Cc: linux-bcache, Nikhil Kshirsagar
On 11/11/21 4:13 AM, Kent Overstreet wrote:
> On Wed, Nov 10, 2021 at 11:14:41AM +0530, Nikhil Kshirsagar wrote:
>> Hello,
>>
>> After a reboot of an Ubuntu server running 4.15.0-143-generic kernel,
>> the storage devices using bcache do not come back up and the following
>> stack traces are seen in kern.log. Please could someone help me
>> understand if this is due to a full bcache journal? Is there any
>> workaround, or fix?
> Your journal is completely full, so persisting the new btree root while doing
> journal replay is hanging.
>
> There isn't a _good_ solution for this journal deadlock in bcache (it's fixed in
> bcachefs), but there is a hack:
>
> edit drivers/md/bcache/btree.c line 2493
>
> delete the call to bch_journal_meta(), and build a new kernel. Once you've
> gotten it to register, do a clean shutdown and then go back to a stock kernel.
>
> Running the kernel with that call deleted won't be safe if you crash, but it'll
> get you going again.
This happens eventually. I had a patch to reserve the last 2 blocks in
the last journal bucket, and only to use them during boot time. It seems
to be time to refine the patch.
(BTW, looking forward to see bcachefs in mainline kernel).
Coly Li
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: bcache-register hang after reboot
2021-11-11 20:54 ` Mauricio Oliveira
@ 2021-11-13 18:05 ` Kent Overstreet
2021-12-13 22:04 ` Mauricio Faria de Oliveira
0 siblings, 1 reply; 10+ messages in thread
From: Kent Overstreet @ 2021-11-13 18:05 UTC (permalink / raw)
To: Mauricio Oliveira; +Cc: Nikhil Kshirsagar, linux-bcache
On Thu, Nov 11, 2021 at 05:54:18PM -0300, Mauricio Oliveira wrote:
> Hi Kent,
>
> On Wed, Nov 10, 2021 at 5:13 PM Kent Overstreet
> <kent.overstreet@gmail.com> wrote:
> > Your journal is completely full, so persisting the new btree root while doing
> > journal replay is hanging.
> >
> > There isn't a _good_ solution for this journal deadlock in bcache (it's fixed in
> > bcachefs), but there is a hack:
> >
> > edit drivers/md/bcache/btree.c line 2493
> >
> > delete the call to bch_journal_meta(), and build a new kernel. Once you've
> > gotten it to register, do a clean shutdown and then go back to a stock kernel.
> >
> > Running the kernel with that call deleted won't be safe if you crash, but it'll
> > get you going again.
>
> Thanks for the clarification and suggestions.
>
> Would it be OK to implement that workaround if requested by a sysadmin ?
> (say, to ack the data safety / crash risk)
>
> Right now the issue is known, reproduces with v5.15, has no good solution,
> remains after reboot, prints hung task warnings continuously, and prevents
> using the device at all; and this workaround requires kernel dev/build skills.
>
> Since its effects seem bad enough, it would seem fair enough to provide a
> way out even if it's not a _good_ one.
>
> Say, we could try and detect the journal full during journal replay, and handle
> it by failing the device registration. This would unblock the tasks, and provide
> a more intuitive error message. (maybe leading to the next paragraph.)
>
> We could also add a sysfs tunable to skip the call to bch_journal_meta(),
> and allow the registration to proceed, but fail it unconditionally in the end
> so the device isn't used with data safety / crash risk
> (or force an automatic unregister + register again w/ bch_journal_meta(),
> and disable the sysfs tunable).
>
> This would help with the full journal, and allow a sysadmin to perform the
> workaround without kernel rebuild and reboots.
I think the best solution might be to change bch_btree_set_root() to check if
we're in journal replay, and if we are, make the call to bch_journal_meta()
nonblocking - pass it NULL instead of a closure.
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: bcache-register hang after reboot
2021-11-12 5:45 ` Coly Li
@ 2021-11-13 18:12 ` Kent Overstreet
0 siblings, 0 replies; 10+ messages in thread
From: Kent Overstreet @ 2021-11-13 18:12 UTC (permalink / raw)
To: Coly Li; +Cc: linux-bcache, Nikhil Kshirsagar
On Fri, Nov 12, 2021 at 01:45:06PM +0800, Coly Li wrote:
> On 11/11/21 4:13 AM, Kent Overstreet wrote:
> > On Wed, Nov 10, 2021 at 11:14:41AM +0530, Nikhil Kshirsagar wrote:
> > > Hello,
> > >
> > > After a reboot of an Ubuntu server running 4.15.0-143-generic kernel,
> > > the storage devices using bcache do not come back up and the following
> > > stack traces are seen in kern.log. Please could someone help me
> > > understand if this is due to a full bcache journal? Is there any
> > > workaround, or fix?
> > Your journal is completely full, so persisting the new btree root while doing
> > journal replay is hanging.
> >
> > There isn't a _good_ solution for this journal deadlock in bcache (it's fixed in
> > bcachefs), but there is a hack:
> >
> > edit drivers/md/bcache/btree.c line 2493
> >
> > delete the call to bch_journal_meta(), and build a new kernel. Once you've
> > gotten it to register, do a clean shutdown and then go back to a stock kernel.
> >
> > Running the kernel with that call deleted won't be safe if you crash, but it'll
> > get you going again.
>
> This happens eventually. I had a patch to reserve the last 2 blocks in the
> last journal bucket, and only to use them during boot time. It seems to be
> time to refine the patch.
bcachefs has that modification as well - the bcache journal code is so minimal
in comparison.
> (BTW, looking forward to see bcachefs in mainline kernel).
Thanks! Now that snapshots are done, I'm going to be focusing on closing bugs
for awhile, and then hopefully finally upstreaming it soon.
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: bcache-register hang after reboot
2021-11-13 18:05 ` Kent Overstreet
@ 2021-12-13 22:04 ` Mauricio Faria de Oliveira
2021-12-13 22:22 ` Mauricio Faria de Oliveira
2021-12-14 16:06 ` Coly Li
0 siblings, 2 replies; 10+ messages in thread
From: Mauricio Faria de Oliveira @ 2021-12-13 22:04 UTC (permalink / raw)
To: kent.overstreet; +Cc: linux-bcache, mfo, nkshirsagar
Hey Kent and Coly,
It turns out that, at least for the disk image that reproduces the issue,
the closure from bch_btree_set_root() to bch_journal_meta() doesn't make
a difference; the stall is in bch_journal() -> journal_wait_for_write().
So the previous suggestion to skip bch_journal_meta() altogether works,
to get things going.. of course, checking for journal replay/full case.
What do you think of this patch?
It simply checks the conditions in run_cache_set() for bch_journal_replay().
(it starts w/ unlikely(!CACHE_SET_RUNNING) to quickly get to the usual case,
and apparently has an extra strict check for !gc_thread, just in case.
And it is journal_full() only, as the !journal_full() case in journal_wait_
for_write() seems to be handled via another function per the comment.)
This works w/ the disk image here.
Thanks!
Mauricio
diff --git a/drivers/md/bcache/btree.c b/drivers/md/bcache/btree.c
index 72abe5cf4b12..bedeffc3ae28 100644
--- a/drivers/md/bcache/btree.c
+++ b/drivers/md/bcache/btree.c
@@ -2477,9 +2477,6 @@ int bch_btree_insert(struct cache_set *c, struct keylist *keys,
void bch_btree_set_root(struct btree *b)
{
unsigned int i;
- struct closure cl;
-
- closure_init_stack(&cl);
trace_bcache_btree_set_root(b);
@@ -2494,8 +2491,18 @@ void bch_btree_set_root(struct btree *b)
b->c->root = b;
- bch_journal_meta(b->c, &cl);
- closure_sync(&cl);
+ /* Don't journal during replay if journal is full (prevents deadlock) */
+ if (unlikely(!test_bit(CACHE_SET_RUNNING, &b->c->flags)) &&
+ CACHE_SYNC(&b->c->cache->sb) && b->c->gc_thread == NULL &&
+ journal_full(&b->c->journal)) {
+ pr_info("Not journaling new root (replay with full journal)\n");
+ } else {
+ struct closure cl;
+
+ closure_init_stack(&cl);
+ bch_journal_meta(b->c, &cl);
+ closure_sync(&cl);
+ }
}
/* Map across nodes or keys */
^ permalink raw reply related [flat|nested] 10+ messages in thread
* Re: bcache-register hang after reboot
2021-12-13 22:04 ` Mauricio Faria de Oliveira
@ 2021-12-13 22:22 ` Mauricio Faria de Oliveira
2021-12-14 16:06 ` Coly Li
1 sibling, 0 replies; 10+ messages in thread
From: Mauricio Faria de Oliveira @ 2021-12-13 22:22 UTC (permalink / raw)
To: kent.overstreet; +Cc: linux-bcache, nkshirsagar
On Mon, Dec 13, 2021 at 7:04 PM Mauricio Faria de Oliveira
<mfo@canonical.com> wrote:
> It turns out that, at least for the disk image that reproduces the issue,
> the closure from bch_btree_set_root() to bch_journal_meta() doesn't make
> a difference; the stall is in bch_journal() -> journal_wait_for_write().
Sorry, I forgot to add the replied-to message. This is the message/context: [1]
[1] https://lore.kernel.org/linux-bcache/YY%2F+YDSjdZPma3oT@moria.home.lan/
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: bcache-register hang after reboot
2021-12-13 22:04 ` Mauricio Faria de Oliveira
2021-12-13 22:22 ` Mauricio Faria de Oliveira
@ 2021-12-14 16:06 ` Coly Li
2021-12-14 16:43 ` Mauricio Faria de Oliveira
1 sibling, 1 reply; 10+ messages in thread
From: Coly Li @ 2021-12-14 16:06 UTC (permalink / raw)
To: Mauricio Faria de Oliveira; +Cc: linux-bcache, nkshirsagar, kent.overstreet
On 12/14/21 6:04 AM, Mauricio Faria de Oliveira wrote:
> Hey Kent and Coly,
>
> It turns out that, at least for the disk image that reproduces the issue,
> the closure from bch_btree_set_root() to bch_journal_meta() doesn't make
> a difference; the stall is in bch_journal() -> journal_wait_for_write().
>
> So the previous suggestion to skip bch_journal_meta() altogether works,
> to get things going.. of course, checking for journal replay/full case.
>
> What do you think of this patch?
>
> It simply checks the conditions in run_cache_set() for bch_journal_replay().
> (it starts w/ unlikely(!CACHE_SET_RUNNING) to quickly get to the usual case,
> and apparently has an extra strict check for !gc_thread, just in case.
> And it is journal_full() only, as the !journal_full() case in journal_wait_
> for_write() seems to be handled via another function per the comment.)
>
> This works w/ the disk image here.
Hi Mauricio,
The following patch might work but not a proper fix. I am in travel
recently, and hope soon I may have time to refine a patch for such
non-space issue for journal.
I have a patch but it need to be rebased with the latest bcache code.
Thanks.
Coly Li
>
> Thanks!
> Mauricio
>
> diff --git a/drivers/md/bcache/btree.c b/drivers/md/bcache/btree.c
> index 72abe5cf4b12..bedeffc3ae28 100644
> --- a/drivers/md/bcache/btree.c
> +++ b/drivers/md/bcache/btree.c
> @@ -2477,9 +2477,6 @@ int bch_btree_insert(struct cache_set *c, struct keylist *keys,
> void bch_btree_set_root(struct btree *b)
> {
> unsigned int i;
> - struct closure cl;
> -
> - closure_init_stack(&cl);
>
> trace_bcache_btree_set_root(b);
>
> @@ -2494,8 +2491,18 @@ void bch_btree_set_root(struct btree *b)
>
> b->c->root = b;
>
> - bch_journal_meta(b->c, &cl);
> - closure_sync(&cl);
> + /* Don't journal during replay if journal is full (prevents deadlock) */
> + if (unlikely(!test_bit(CACHE_SET_RUNNING, &b->c->flags)) &&
> + CACHE_SYNC(&b->c->cache->sb) && b->c->gc_thread == NULL &&
> + journal_full(&b->c->journal)) {
> + pr_info("Not journaling new root (replay with full journal)\n");
> + } else {
> + struct closure cl;
> +
> + closure_init_stack(&cl);
> + bch_journal_meta(b->c, &cl);
> + closure_sync(&cl);
> + }
> }
>
> /* Map across nodes or keys */
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: bcache-register hang after reboot
2021-12-14 16:06 ` Coly Li
@ 2021-12-14 16:43 ` Mauricio Faria de Oliveira
0 siblings, 0 replies; 10+ messages in thread
From: Mauricio Faria de Oliveira @ 2021-12-14 16:43 UTC (permalink / raw)
To: Coly Li; +Cc: linux-bcache, nkshirsagar, kent.overstreet
On Tue, Dec 14, 2021 at 1:06 PM Coly Li <colyli@suse.de> wrote:
>
> On 12/14/21 6:04 AM, Mauricio Faria de Oliveira wrote:
> > What do you think of this patch?
[snip]
> The following patch might work but not a proper fix. I am in travel
> recently, and hope soon I may have time to refine a patch for such
> non-space issue for journal.
> I have a patch but it need to be rebased with the latest bcache code.
Hey Coly.
Ok, thanks for the prompt reply and letting us know!
cheers,
^ permalink raw reply [flat|nested] 10+ messages in thread
end of thread, other threads:[~2021-12-14 16:44 UTC | newest]
Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-11-10 5:44 bcache-register hang after reboot Nikhil Kshirsagar
2021-11-10 20:13 ` Kent Overstreet
2021-11-11 20:54 ` Mauricio Oliveira
2021-11-13 18:05 ` Kent Overstreet
2021-12-13 22:04 ` Mauricio Faria de Oliveira
2021-12-13 22:22 ` Mauricio Faria de Oliveira
2021-12-14 16:06 ` Coly Li
2021-12-14 16:43 ` Mauricio Faria de Oliveira
2021-11-12 5:45 ` Coly Li
2021-11-13 18:12 ` Kent Overstreet
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.