syzbot


possible deadlock in console_flush_all

Status: closed as invalid on 2023/09/22 10:29
Subsystems: mm
[Documentation on labels]
Reported-by: syzbot+1196a75f5d71352645a4@syzkaller.appspotmail.com
First crash: 235d, last: 235d
Discussions (1)
Title Replies (including bot) Last reply
[syzbot] [mm?] possible deadlock in console_flush_all 1 (2) 2023/09/22 10:28
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in console_flush_all (2) trace bpf C error 52463 18h34m 214d 0/26 upstream: reported C repro on 2023/10/08 06:28

Sample crash report:
------------[ cut here ]------------
======================================================
WARNING: possible circular locking dependency detected
6.6.0-rc1-next-20230915-syzkaller #0 Not tainted
------------------------------------------------------
kswapd0/80 is trying to acquire lock:
ffffffff8cab7f20 (console_owner){-.-.}-{0:0}, at: console_lock_spinning_enable kernel/printk/printk.c:1858 [inline]
ffffffff8cab7f20 (console_owner){-.-.}-{0:0}, at: console_emit_next_record kernel/printk/printk.c:2904 [inline]
ffffffff8cab7f20 (console_owner){-.-.}-{0:0}, at: console_flush_all+0x4ac/0xfb0 kernel/printk/printk.c:2966

but task is already holding lock:
ffff88813fffacd8 (&zone->lock){-.-.}-{2:2}, at: free_pcppages_bulk+0x6a/0x610 mm/page_alloc.c:1202

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #4 (&zone->lock){-.-.}-{2:2}:
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x3a/0x50 kernel/locking/spinlock.c:162
       rmqueue_bulk mm/page_alloc.c:2203 [inline]
       __rmqueue_pcplist+0xcd3/0x1430 mm/page_alloc.c:2752
       rmqueue_pcplist mm/page_alloc.c:2794 [inline]
       rmqueue mm/page_alloc.c:2831 [inline]
       get_page_from_freelist+0x31c/0x2d10 mm/page_alloc.c:3221
       __alloc_pages+0x1d0/0x4a0 mm/page_alloc.c:4480
       alloc_page_interleave+0x1e/0x250 mm/mempolicy.c:2131
       alloc_pages+0x22a/0x270 mm/mempolicy.c:2293
       stack_depot_save_flags+0x28d/0x750 lib/stackdepot.c:516
       save_stack+0x16d/0x1f0 mm/page_owner.c:129
       __set_page_owner+0x1f/0x60 mm/page_owner.c:192
       set_page_owner include/linux/page_owner.h:31 [inline]
       post_alloc_hook+0x2cf/0x340 mm/page_alloc.c:1535
       prep_new_page mm/page_alloc.c:1542 [inline]
       get_page_from_freelist+0xdcd/0x2d10 mm/page_alloc.c:3224
       __alloc_pages+0x1d0/0x4a0 mm/page_alloc.c:4480
       alloc_page_interleave+0x1e/0x250 mm/mempolicy.c:2131
       alloc_pages+0x22a/0x270 mm/mempolicy.c:2293
       stack_depot_save_flags+0x28d/0x750 lib/stackdepot.c:516
       kasan_save_stack+0x42/0x50 mm/kasan/common.c:47
       kasan_set_track+0x25/0x30 mm/kasan/common.c:53
       __kasan_slab_alloc+0x81/0x90 mm/kasan/common.c:329
       kasan_slab_alloc include/linux/kasan.h:188 [inline]
       slab_post_alloc_hook mm/slab.h:762 [inline]
       slab_alloc_node mm/slub.c:3478 [inline]
       slab_alloc mm/slub.c:3486 [inline]
       __kmem_cache_alloc_lru mm/slub.c:3493 [inline]
       kmem_cache_alloc+0x16c/0x3b0 mm/slub.c:3502
       kmem_cache_zalloc include/linux/slab.h:710 [inline]
       fill_pool+0x271/0x5d0 lib/debugobjects.c:168
       debug_objects_fill_pool lib/debugobjects.c:615 [inline]
       debug_object_activate+0x149/0x490 lib/debugobjects.c:713
       debug_work_activate kernel/workqueue.c:572 [inline]
       insert_work+0x30/0x230 kernel/workqueue.c:1644
       __queue_work+0x5d0/0x1050 kernel/workqueue.c:1799
       queue_work_on+0xed/0x110 kernel/workqueue.c:1834
       queue_work include/linux/workqueue.h:554 [inline]
       call_usermodehelper_exec+0x1d2/0x4c0 kernel/umh.c:434
       kobject_uevent_env+0xf6d/0x1800 lib/kobject_uevent.c:618
       kset_register+0x1b6/0x2a0 lib/kobject.c:873
       class_register+0x1cb/0x330 drivers/base/class.c:205
       iscsi_transport_init+0x1f9/0x2e0 drivers/scsi/scsi_transport_iscsi.c:4995
       do_one_initcall+0x117/0x630 init/main.c:1232
       do_initcall_level init/main.c:1294 [inline]
       do_initcalls init/main.c:1310 [inline]
       do_basic_setup init/main.c:1329 [inline]
       kernel_init_freeable+0x5c2/0x8f0 init/main.c:1547
       kernel_init+0x1c/0x2a0 init/main.c:1437
       ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
       ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304

-> #3 (&pool->lock){-.-.}-{2:2}:
       __raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
       _raw_spin_lock+0x2e/0x40 kernel/locking/spinlock.c:154
       __queue_work+0x399/0x1050 kernel/workqueue.c:1763
       queue_work_on+0xed/0x110 kernel/workqueue.c:1834
       queue_work include/linux/workqueue.h:554 [inline]
       rpm_suspend+0x1219/0x16f0 drivers/base/power/runtime.c:660
       rpm_idle+0x574/0x6e0 drivers/base/power/runtime.c:534
       __pm_runtime_idle+0xbe/0x160 drivers/base/power/runtime.c:1102
       pm_runtime_put include/linux/pm_runtime.h:460 [inline]
       __device_attach+0x382/0x4b0 drivers/base/dd.c:1048
       bus_probe_device+0x17c/0x1c0 drivers/base/bus.c:532
       device_add+0x117e/0x1aa0 drivers/base/core.c:3624
       serial_base_port_add+0x353/0x4b0 drivers/tty/serial/serial_base_bus.c:178
       serial_core_port_device_add drivers/tty/serial/serial_core.c:3310 [inline]
       serial_core_register_port+0x137/0x1b00 drivers/tty/serial/serial_core.c:3351
       serial8250_register_8250_port+0x140d/0x2080 drivers/tty/serial/8250/8250_core.c:1139
       serial_pnp_probe+0x47d/0x880 drivers/tty/serial/8250/8250_pnp.c:478
       pnp_device_probe+0x2a3/0x4c0 drivers/pnp/driver.c:111
       call_driver_probe drivers/base/dd.c:579 [inline]
       really_probe+0x234/0xc90 drivers/base/dd.c:658
       __driver_probe_device+0x1de/0x4b0 drivers/base/dd.c:800
       driver_probe_device+0x4c/0x1a0 drivers/base/dd.c:830
       __driver_attach+0x274/0x570 drivers/base/dd.c:1216
       bus_for_each_dev+0x13c/0x1d0 drivers/base/bus.c:368
       bus_add_driver+0x2e9/0x630 drivers/base/bus.c:673
       driver_register+0x15c/0x4a0 drivers/base/driver.c:246
       serial8250_init+0xba/0x4b0 drivers/tty/serial/8250/8250_core.c:1240
       do_one_initcall+0x117/0x630 init/main.c:1232
       do_initcall_level init/main.c:1294 [inline]
       do_initcalls init/main.c:1310 [inline]
       do_basic_setup init/main.c:1329 [inline]
       kernel_init_freeable+0x5c2/0x8f0 init/main.c:1547
       kernel_init+0x1c/0x2a0 init/main.c:1437
       ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
       ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304

-> #2 (&dev->power.lock){-.-.}-{2:2}:
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x3a/0x50 kernel/locking/spinlock.c:162
       __pm_runtime_resume+0xab/0x170 drivers/base/power/runtime.c:1169
       pm_runtime_get include/linux/pm_runtime.h:408 [inline]
       __uart_start+0x1b0/0x420 drivers/tty/serial/serial_core.c:148
       uart_write+0x2ff/0x5b0 drivers/tty/serial/serial_core.c:618
       process_output_block drivers/tty/n_tty.c:579 [inline]
       n_tty_write+0x422/0x1130 drivers/tty/n_tty.c:2384
       iterate_tty_write drivers/tty/tty_io.c:1017 [inline]
       file_tty_write.constprop.0+0x519/0x9b0 drivers/tty/tty_io.c:1088
       tty_write drivers/tty/tty_io.c:1109 [inline]
       redirected_tty_write drivers/tty/tty_io.c:1132 [inline]
       redirected_tty_write+0xa6/0xc0 drivers/tty/tty_io.c:1112
       call_write_iter include/linux/fs.h:1986 [inline]
       new_sync_write fs/read_write.c:491 [inline]
       vfs_write+0x650/0xe40 fs/read_write.c:584
       ksys_write+0x12f/0x250 fs/read_write.c:637
       do_syscall_x64 arch/x86/entry/common.c:51 [inline]
       do_syscall_64+0x38/0xb0 arch/x86/entry/common.c:81
       entry_SYSCALL_64_after_hwframe+0x63/0xcd

-> #1 (&port_lock_key){-.-.}-{2:2}:
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x3a/0x50 kernel/locking/spinlock.c:162
       serial8250_console_write+0x57e/0x1060 drivers/tty/serial/8250/8250_port.c:3408
       console_emit_next_record kernel/printk/printk.c:2910 [inline]
       console_flush_all+0x4eb/0xfb0 kernel/printk/printk.c:2966
       console_unlock+0x10c/0x260 kernel/printk/printk.c:3035
       vprintk_emit+0x17f/0x5f0 kernel/printk/printk.c:2307
       vprintk+0x7b/0x90 kernel/printk/printk_safe.c:45
       _printk+0xc8/0x100 kernel/printk/printk.c:2332
       register_console+0xa67/0x10d0 kernel/printk/printk.c:3524
       univ8250_console_init+0x35/0x50 drivers/tty/serial/8250/8250_core.c:717
       console_init+0xba/0x5c0 kernel/printk/printk.c:3667
       start_kernel+0x25a/0x480 init/main.c:1004
       x86_64_start_reservations+0x18/0x30 arch/x86/kernel/head64.c:556
       x86_64_start_kernel+0xb2/0xc0 arch/x86/kernel/head64.c:537
       secondary_startup_64_no_verify+0x166/0x16b

-> #0 (console_owner){-.-.}-{0:0}:
       check_prev_add kernel/locking/lockdep.c:3134 [inline]
       check_prevs_add kernel/locking/lockdep.c:3253 [inline]
       validate_chain kernel/locking/lockdep.c:3868 [inline]
       __lock_acquire+0x2e3d/0x5de0 kernel/locking/lockdep.c:5136
       lock_acquire kernel/locking/lockdep.c:5753 [inline]
       lock_acquire+0x1ae/0x510 kernel/locking/lockdep.c:5718
       console_lock_spinning_enable kernel/printk/printk.c:1858 [inline]
       console_emit_next_record kernel/printk/printk.c:2904 [inline]
       console_flush_all+0x4c1/0xfb0 kernel/printk/printk.c:2966
       console_unlock+0x10c/0x260 kernel/printk/printk.c:3035
       vprintk_emit+0x17f/0x5f0 kernel/printk/printk.c:2307
       vprintk+0x7b/0x90 kernel/printk/printk_safe.c:45
       _printk+0xc8/0x100 kernel/printk/printk.c:2332
       __warn_printk+0x158/0x350 kernel/panic.c:720
       del_page_from_free_list+0x36e/0x490 mm/page_alloc.c:699
       __free_one_page+0x3eb/0xa50 mm/page_alloc.c:830
       free_pcppages_bulk+0x2f3/0x610 mm/page_alloc.c:1233
       free_unref_page_list+0x859/0x1050 mm/page_alloc.c:2568
       shrink_folio_list+0x2815/0x3f00 mm/vmscan.c:1500
       evict_folios+0x6bf/0x1940 mm/vmscan.c:4519
       try_to_shrink_lruvec+0x769/0xb00 mm/vmscan.c:4695
       shrink_one+0x45f/0x700 mm/vmscan.c:4739
       shrink_many mm/vmscan.c:4793 [inline]
       lru_gen_shrink_node mm/vmscan.c:4910 [inline]
       shrink_node+0x215f/0x3850 mm/vmscan.c:5850
       kswapd_shrink_node mm/vmscan.c:6655 [inline]
       balance_pgdat+0xa32/0x1b80 mm/vmscan.c:6845
       kswapd+0x5be/0xbf0 mm/vmscan.c:7105
       kthread+0x33c/0x440 kernel/kthread.c:388
       ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
       ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304

other info that might help us debug this:

Chain exists of:
  console_owner --> &pool->lock --> &zone->lock

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&zone->lock);
                               lock(&pool->lock);
                               lock(&zone->lock);
  lock(console_owner);

 *** DEADLOCK ***

5 locks held by kswapd0/80:
 #0: ffffffff8cd159a0 (fs_reclaim){+.+.}-{0:0}, at: balance_pgdat+0x1b4/0x1b80 mm/vmscan.c:6733
 #1: ffff8880b99425d8 (&pcp->lock){+.+.}-{2:2}, at: spin_trylock include/linux/spinlock.h:361 [inline]
 #1: ffff8880b99425d8 (&pcp->lock){+.+.}-{2:2}, at: free_unref_page_list+0xb16/0x1050 mm/page_alloc.c:2549
 #2: ffff88813fffacd8 (&zone->lock){-.-.}-{2:2}, at: free_pcppages_bulk+0x6a/0x610 mm/page_alloc.c:1202
 #3: ffffffff8cb98360 (console_lock){+.+.}-{0:0}, at: console_trylock_spinning kernel/printk/printk.c:1927 [inline]
 #3: ffffffff8cb98360 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x162/0x5f0 kernel/printk/printk.c:2306
 #4: ffffffff8cb983d0 (console_srcu){....}-{0:0}, at: rcu_lock_acquire include/linux/rcupdate.h:303 [inline]
 #4: ffffffff8cb983d0 (console_srcu){....}-{0:0}, at: srcu_read_lock_nmisafe include/linux/srcu.h:232 [inline]
 #4: ffffffff8cb983d0 (console_srcu){....}-{0:0}, at: console_srcu_read_lock kernel/printk/printk.c:292 [inline]
 #4: ffffffff8cb983d0 (console_srcu){....}-{0:0}, at: console_flush_all+0x12d/0xfb0 kernel/printk/printk.c:2958

stack backtrace:
CPU: 1 PID: 80 Comm: kswapd0 Not tainted 6.6.0-rc1-next-20230915-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 08/04/2023
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xd9/0x1b0 lib/dump_stack.c:106
 check_noncircular+0x311/0x3f0 kernel/locking/lockdep.c:2187
 check_prev_add kernel/locking/lockdep.c:3134 [inline]
 check_prevs_add kernel/locking/lockdep.c:3253 [inline]
 validate_chain kernel/locking/lockdep.c:3868 [inline]
 __lock_acquire+0x2e3d/0x5de0 kernel/locking/lockdep.c:5136
 lock_acquire kernel/locking/lockdep.c:5753 [inline]
 lock_acquire+0x1ae/0x510 kernel/locking/lockdep.c:5718
 console_lock_spinning_enable kernel/printk/printk.c:1858 [inline]
 console_emit_next_record kernel/printk/printk.c:2904 [inline]
 console_flush_all+0x4c1/0xfb0 kernel/printk/printk.c:2966
 console_unlock+0x10c/0x260 kernel/printk/printk.c:3035
 vprintk_emit+0x17f/0x5f0 kernel/printk/printk.c:2307
 vprintk+0x7b/0x90 kernel/printk/printk_safe.c:45
 _printk+0xc8/0x100 kernel/printk/printk.c:2332
 __warn_printk+0x158/0x350 kernel/panic.c:720
 del_page_from_free_list+0x36e/0x490 mm/page_alloc.c:699
 __free_one_page+0x3eb/0xa50 mm/page_alloc.c:830
 free_pcppages_bulk+0x2f3/0x610 mm/page_alloc.c:1233
 free_unref_page_list+0x859/0x1050 mm/page_alloc.c:2568
 shrink_folio_list+0x2815/0x3f00 mm/vmscan.c:1500
 evict_folios+0x6bf/0x1940 mm/vmscan.c:4519
 try_to_shrink_lruvec+0x769/0xb00 mm/vmscan.c:4695
 shrink_one+0x45f/0x700 mm/vmscan.c:4739
 shrink_many mm/vmscan.c:4793 [inline]
 lru_gen_shrink_node mm/vmscan.c:4910 [inline]
 shrink_node+0x215f/0x3850 mm/vmscan.c:5850
 kswapd_shrink_node mm/vmscan.c:6655 [inline]
 balance_pgdat+0xa32/0x1b80 mm/vmscan.c:6845
 kswapd+0x5be/0xbf0 mm/vmscan.c:7105
 kthread+0x33c/0x440 kernel/kthread.c:388
 ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
 </TASK>
page type is 0, passed migratetype is 1 (nr=512)
WARNING: CPU: 1 PID: 80 at mm/page_alloc.c:699 del_page_from_free_list+0x36e/0x490 mm/page_alloc.c:699
Modules linked in:
CPU: 1 PID: 80 Comm: kswapd0 Not tainted 6.6.0-rc1-next-20230915-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 08/04/2023
RIP: 0010:del_page_from_free_list+0x36e/0x490 mm/page_alloc.c:699
Code: 89 ef be 07 00 00 00 e8 e0 f6 ff ff 44 89 e1 44 89 f2 48 c7 c7 20 b6 99 8a 48 89 c6 b8 01 00 00 00 d3 e0 89 c1 e8 d2 3b 7c ff <0f> 0b e9 d2 fc ff ff 48 c7 c6 80 b7 99 8a 48 89 df e8 9c 46 f4 ff
RSP: 0018:ffffc900020af1d0 EFLAGS: 00010082
RAX: 0000000000000000 RBX: ffffea0001bd8000 RCX: 0000000000000000
RDX: ffff888012d15940 RSI: ffffffff814e0396 RDI: 0000000000000001
RBP: 000000000006f600 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000009
R13: ffff88813fffa700 R14: 0000000000000001 R15: ffffea0001bd8000
FS:  0000000000000000(0000) GS:ffff8880b9900000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00005555568a5938 CR3: 000000000c976000 CR4: 00000000003526e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 __free_one_page+0x3eb/0xa50 mm/page_alloc.c:830
 free_pcppages_bulk+0x2f3/0x610 mm/page_alloc.c:1233
 free_unref_page_list+0x859/0x1050 mm/page_alloc.c:2568
 shrink_folio_list+0x2815/0x3f00 mm/vmscan.c:1500
 evict_folios+0x6bf/0x1940 mm/vmscan.c:4519
 try_to_shrink_lruvec+0x769/0xb00 mm/vmscan.c:4695
 shrink_one+0x45f/0x700 mm/vmscan.c:4739
 shrink_many mm/vmscan.c:4793 [inline]
 lru_gen_shrink_node mm/vmscan.c:4910 [inline]
 shrink_node+0x215f/0x3850 mm/vmscan.c:5850
 kswapd_shrink_node mm/vmscan.c:6655 [inline]
 balance_pgdat+0xa32/0x1b80 mm/vmscan.c:6845
 kswapd+0x5be/0xbf0 mm/vmscan.c:7105
 kthread+0x33c/0x440 kernel/kthread.c:388
 ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
 </TASK>

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/09/17 05:11 linux-next dfa449a58323 0b6a67ac .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-linux-next-kasan-gce-root possible deadlock in console_flush_all
* Struck through repros no longer work on HEAD.