[dm-devel] Sleeping function called from invalid context

[Matthew Wilcox]

Got this in linux-next 20230926, and I don't think it's due to my
patches on top (it may be, will verify):

04178 generic/347       run fstests generic/347 at 2023-09-26 17:24:55
04178 XFS (sdb): Mounting V5 Filesystem c0c11e6a-170c-48e4-84c5-42b46d6d5197
04178 XFS (sdb): Ending clean mount
04179 BUG: sleeping function called from invalid context at kernel/locking/rwsem.c:1525
04179 in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 1096408, name: kworker/u16:32
04179 preempt_count: 1, expected: 0
04179 RCU nest depth: 0, expected: 0
04179 4 locks held by kworker/u16:32/1096408:
04179  #0: ffff88800ac6ff38 ((wq_completion)dm-thin){+.+.}-{0:0}, at: process_one_work+0x17b/0x4a0
04179  #1: ffff88800800be48 ((work_completion)(&pool->worker)){+.+.}-{0:0}, at: process_one_work+0x17b/0x4a0
04179  #2: ffff88804d8715d0 (&pmd->root_lock){++++}-{3:3}, at: dm_thin_alloc_data_block+0x26/0xb0
04179  #3: ffff88800db2fe98 (&ea->lock){+.+.}-{2:2}, at: dm_ea_context_alloc+0x2a/0x380
04179 Preemption disabled at:
04179 [<ffffffff81878cba>] dm_ea_context_alloc+0x2a/0x380
04179 CPU: 6 PID: 1096408 Comm: kworker/u16:32 Kdump: loaded Not tainted 6.6.0-rc3-next-20230926-00005-geb8b46fa6084-dirty #289
04179 Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
04179 Workqueue: dm-thin do_worker
04179 Call Trace:
04179  <TASK>
04179  dump_stack_lvl+0x69/0x80
04179  dump_stack+0x10/0x20
04179  __might_resched+0x1a8/0x2c0
04179  __might_sleep+0x3d/0x70
04179  down_read+0x19/0x180
04179  cache_get+0x46/0xc0
04179  new_read+0x44/0x180
04179  dm_bufio_read+0x24/0x30
04179  dm_bm_read_lock+0x21/0x70
04179  dm_tm_read_lock+0x24/0xa0
04179  sm_ll_find_free_block+0xa1/0x190
04179  sm_ll_find_common_free_block+0x2e/0x80
04179  sm_disk_new_block_in_range+0x2f/0x70
04179  sm_alloc_extent+0xe/0x10
04179  dm_ea_context_alloc+0x4e/0x380
04179  dm_thin_alloc_data_block+0x4f/0xb0
04179  alloc_data_block+0x51/0x190
04179  process_cell+0x34b/0x620
04179  ? _raw_spin_unlock_irq+0x22/0x50
04179  do_worker+0x275/0xa00
04179  process_one_work+0x1d8/0x4a0
04179  ? process_one_work+0x17b/0x4a0
04179  worker_thread+0x1d9/0x3d0
04179  ? rescuer_thread+0x370/0x370
04179  kthread+0x109/0x140
04179  ? kthread_complete_and_exit+0x20/0x20
04179  ret_from_fork+0x31/0x50
04179  ? kthread_complete_and_exit+0x20/0x20
04179  ret_from_fork_asm+0x11/0x20
04179  </TASK>
04179 
04179 =============================
04179 [ BUG: Invalid wait context ]
04179 6.6.0-rc3-next-20230926-00005-geb8b46fa6084-dirty #289 Tainted: G        W         
04179 -----------------------------
04179 kworker/u16:32/1096408 is trying to lock:
04179 ffff88803d8c02f0 (&bc->trees[i].lock){++++}-{3:3}, at: cache_get+0x46/0xc0
04179 other info that might help us debug this:
04179 context-{4:4}
04179 4 locks held by kworker/u16:32/1096408:
04179  #0: ffff88800ac6ff38 ((wq_completion)dm-thin){+.+.}-{0:0}, at: process_one_work+0x17b/0x4a0
04179  #1: ffff88800800be48 ((work_completion)(&pool->worker)){+.+.}-{0:0}, at: process_one_work+0x17b/0x4a0
04179  #2: ffff88804d8715d0 (&pmd->root_lock){++++}-{3:3}, at: dm_thin_alloc_data_block+0x26/0xb0
04179  #3: ffff88800db2fe98 (&ea->lock){+.+.}-{2:2}, at: dm_ea_context_alloc+0x2a/0x380
04179 stack backtrace:
04179 CPU: 6 PID: 1096408 Comm: kworker/u16:32 Kdump: loaded Tainted: G        W          6.6.0-rc3-next-20230926-00005-geb8b46fa6084-dirty #289
04179 Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
04179 Workqueue: dm-thin do_worker
04179 Call Trace:
04179  <TASK>
04179  dump_stack_lvl+0x4a/0x80
04179  dump_stack+0x10/0x20
04179  __lock_acquire+0x9c9/0x26d0
04179  ? dump_stack_lvl+0x73/0x80
04179  lock_acquire+0xb8/0x280
04179  ? cache_get+0x46/0xc0
04179  ? __might_resched+0x1b4/0x2c0
04179  down_read+0x3c/0x180
04179  ? cache_get+0x46/0xc0
04179  cache_get+0x46/0xc0
04179  new_read+0x44/0x180
04179  dm_bufio_read+0x24/0x30
04179  dm_bm_read_lock+0x21/0x70
04179  dm_tm_read_lock+0x24/0xa0
04179  sm_ll_find_free_block+0xa1/0x190
04179  sm_ll_find_common_free_block+0x2e/0x80
04179  sm_disk_new_block_in_range+0x2f/0x70
04179  sm_alloc_extent+0xe/0x10
04179  dm_ea_context_alloc+0x4e/0x380
04179  ? save_sm_roots+0x70/0x70
04179  dm_thin_alloc_data_block+0x4f/0xb0
04179  alloc_data_block+0x51/0x190
04179  process_cell+0x34b/0x620
04179  ? _raw_spin_unlock_irq+0x22/0x50
04179  do_worker+0x275/0xa00
04179  process_one_work+0x1d8/0x4a0
04179  ? process_one_work+0x17b/0x4a0
04179  worker_thread+0x1d9/0x3d0
04179  ? rescuer_thread+0x370/0x370
04179  kthread+0x109/0x140
04179  ? kthread_complete_and_exit+0x20/0x20
04179  ret_from_fork+0x31/0x50
04179  ? kthread_complete_and_exit+0x20/0x20
04179  ret_from_fork_asm+0x11/0x20
04179  </TASK>

I have a few more of these, but I don't see any new information in them.