possible deadlock in console_trylock_spinning (2)

Status: auto-obsoleted due to no activity on 2024/10/02 11:14
Subsystems: serial
[Documentation on labels]
Reported-by: syzbot+8f689f8825d60fb97dbe@syzkaller.appspotmail.com
First crash: 799d, last: 784d
▶ ▼ Discussions (1)
Title Replies (including bot) Last reply
[syzbot] [serial?] possible deadlock in console_trylock_spinning (2) 0 (1) 2024/06/13 10:56
▶ ▼ Similar bugs (3)
Kernel Title Rank 🛈 Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in console_trylock_spinning serial 4 syz, C done inconclusive 168 1555d 2615d 0/29 auto-obsoleted due to no activity on 2022/10/10 16:31
linux-5.15 possible deadlock in console_trylock_spinning (2) origin:lts-only 4 syz, C done 185 29d 993d 0/3 upstream: reported C repro on 2023/11/29 03:09
linux-5.15 possible deadlock in console_trylock_spinning 4 4 1094d 1211d 0/3 auto-obsoleted due to no activity on 2023/11/27 19:44

Sample crash report:
sp0: Synchronizing with TNC
------------[ cut here ]------------
======================================================
WARNING: possible circular locking dependency detected
6.10.0-rc3-syzkaller-gac2193b4b460 #0 Tainted: G        W         
------------------------------------------------------
syz-executor.3/8095 is trying to acquire lock:
ffff80008f36cea0 (console_owner){-.-.}-{0:0}, at: console_trylock_spinning+0x1cc/0x3d8 kernel/printk/printk.c:1977

but task is already holding lock:
ffff800093dcec98 (&port_lock_key){-.-.}-{2:2}, at: uart_port_lock_irqsave include/linux/serial_core.h:618 [inline]
ffff800093dcec98 (&port_lock_key){-.-.}-{2:2}, at: uart_write+0x114/0x2ec drivers/tty/serial/serial_core.c:624

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #1 (&port_lock_key){-.-.}-{2:2}:
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x5c/0x7c kernel/locking/spinlock.c:162
       uart_port_lock_irqsave include/linux/serial_core.h:618 [inline]
       pl011_console_write+0x148/0x724 drivers/tty/serial/amba-pl011.c:2316
       console_emit_next_record kernel/printk/printk.c:2928 [inline]
       console_flush_all+0x570/0xafc kernel/printk/printk.c:2994
       console_unlock+0xfc/0x3d4 kernel/printk/printk.c:3063
       vprintk_emit+0x1e8/0x344 kernel/printk/printk.c:2345
       vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2360
       vprintk+0x200/0x2d4 kernel/printk/printk_safe.c:45
       _printk+0xdc/0x128 kernel/printk/printk.c:2370
       register_console+0x700/0xa8c kernel/printk/printk.c:3596
       uart_configure_port drivers/tty/serial/serial_core.c:2664 [inline]
       serial_core_add_one_port drivers/tty/serial/serial_core.c:3192 [inline]
       serial_core_register_port+0x1428/0x1bf4 drivers/tty/serial/serial_core.c:3429
       serial_ctrl_register_port+0x28/0x38 drivers/tty/serial/serial_ctrl.c:41
       uart_add_one_port+0x28/0x38 drivers/tty/serial/serial_port.c:136
       pl011_register_port+0x1b4/0x44c drivers/tty/serial/amba-pl011.c:2744
       sbsa_uart_probe+0x488/0x608 drivers/tty/serial/amba-pl011.c:2914
       platform_probe+0x148/0x1c0 drivers/base/platform.c:1404
       really_probe+0x38c/0x8fc drivers/base/dd.c:656
       __driver_probe_device+0x194/0x374 drivers/base/dd.c:798
       driver_probe_device+0x78/0x330 drivers/base/dd.c:828
       __device_attach_driver+0x2a8/0x4f4 drivers/base/dd.c:956
       bus_for_each_drv+0x228/0x2bc drivers/base/bus.c:457
       __device_attach+0x2b4/0x434 drivers/base/dd.c:1028
       device_initial_probe+0x24/0x34 drivers/base/dd.c:1077
       bus_probe_device+0x178/0x240 drivers/base/bus.c:532
       device_add+0x728/0xa6c drivers/base/core.c:3721
       platform_device_add+0x3e8/0x6e8 drivers/base/platform.c:716
       platform_device_register_full+0x4ec/0x604 drivers/base/platform.c:844
       acpi_create_platform_device+0x5bc/0x744 drivers/acpi/acpi_platform.c:177
       acpi_default_enumeration+0x6c/0xdc drivers/acpi/scan.c:2184
       acpi_bus_attach+0x8b8/0xaa8 drivers/acpi/scan.c:2293
       acpi_dev_for_one_check+0xa0/0xb4 drivers/acpi/bus.c:1143
       device_for_each_child+0xec/0x174 drivers/base/core.c:4050
       acpi_dev_for_each_child+0xc4/0x108 drivers/acpi/bus.c:1155
       acpi_bus_attach+0x358/0xaa8 drivers/acpi/scan.c:2298
       acpi_dev_for_one_check+0xa0/0xb4 drivers/acpi/bus.c:1143
       device_for_each_child+0xec/0x174 drivers/base/core.c:4050
       acpi_dev_for_each_child+0xc4/0x108 drivers/acpi/bus.c:1155
       acpi_bus_attach+0x358/0xaa8 drivers/acpi/scan.c:2298
       acpi_bus_scan+0x118/0x4f0 drivers/acpi/scan.c:2579
       acpi_scan_init+0x214/0x6b0 drivers/acpi/scan.c:2714
       acpi_init+0x190/0x254 drivers/acpi/bus.c:1460
       do_one_initcall+0x24c/0x9c0 init/main.c:1267
       do_initcall_level+0x154/0x214 init/main.c:1329
       do_initcalls+0x58/0xac init/main.c:1345
       do_basic_setup+0x8c/0xa0 init/main.c:1364
       kernel_init_freeable+0x324/0x478 init/main.c:1578
       kernel_init+0x24/0x2a0 init/main.c:1467
       ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:860

-> #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:3869 [inline]
       __lock_acquire+0x3384/0x763c kernel/locking/lockdep.c:5137
       lock_acquire+0x240/0x728 kernel/locking/lockdep.c:5754
       console_trylock_spinning+0x1f8/0x3d8 kernel/printk/printk.c:1994
       vprintk_emit+0x1cc/0x344 kernel/printk/printk.c:2344
       vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2360
       vprintk+0x200/0x2d4 kernel/printk/printk_safe.c:45
       _printk+0xdc/0x128 kernel/printk/printk.c:2370
       __report_bug lib/bug.c:195 [inline]
       report_bug+0x3b8/0x5b0 lib/bug.c:219
       bug_handler+0x50/0x1fc arch/arm64/kernel/traps.c:978
       call_break_hook arch/arm64/kernel/debug-monitors.c:321 [inline]
       brk_handler+0x17c/0x2e0 arch/arm64/kernel/debug-monitors.c:328
       do_debug_exception+0x1e4/0x398 arch/arm64/mm/fault.c:909
       el1_dbg+0x64/0x80 arch/arm64/kernel/entry-common.c:472
       el1h_64_sync_handler+0x40/0xac arch/arm64/kernel/entry-common.c:512
       el1h_64_sync+0x64/0x68 arch/arm64/kernel/entry.S:593
       spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
       uart_port_unlock_irqrestore include/linux/serial_core.h:669 [inline]
       uart_write+0x280/0x2ec drivers/tty/serial/serial_core.c:626
       tnc_init drivers/net/hamradio/6pack.c:531 [inline]
       sixpack_open+0x5d8/0x8b0 drivers/net/hamradio/6pack.c:628
       tty_ldisc_open+0x9c/0x14c drivers/tty/tty_ldisc.c:432
       tty_set_ldisc+0x2f8/0x4e0 drivers/tty/tty_ldisc.c:563
       tiocsetd+0x100/0x13c drivers/tty/tty_io.c:2439
       tty_ioctl+0xba0/0xd8c drivers/tty/tty_io.c:2739
       vfs_ioctl fs/ioctl.c:51 [inline]
       __do_sys_ioctl fs/ioctl.c:907 [inline]
       __se_sys_ioctl fs/ioctl.c:893 [inline]
       __arm64_sys_ioctl+0x14c/0x1c8 fs/ioctl.c:893
       __invoke_syscall arch/arm64/kernel/syscall.c:34 [inline]
       invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:48
       el0_svc_common+0x130/0x23c arch/arm64/kernel/syscall.c:133
       do_el0_svc+0x48/0x58 arch/arm64/kernel/syscall.c:152
       el0_svc+0x54/0x168 arch/arm64/kernel/entry-common.c:712
       el0t_64_sync_handler+0x84/0xfc arch/arm64/kernel/entry-common.c:730
       el0t_64_sync+0x190/0x194 arch/arm64/kernel/entry.S:598

other info that might help us debug this:

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&port_lock_key);
                               lock(console_owner);
                               lock(&port_lock_key);
  lock(console_owner);

 *** DEADLOCK ***

3 locks held by syz-executor.3/8095:
 #0: ffff0000efe871c0 (&tty->legacy_mutex){+.+.}-{3:3}, at: tty_lock+0x78/0xc8 drivers/tty/tty_mutex.c:18
 #1: ffff0000efe870a0 (&tty->ldisc_sem){++++}-{0:0}, at: ldsem_down_write+0x3c/0x4c drivers/tty/tty_ldsem.c:366
 #2: ffff800093dcec98 (&port_lock_key){-.-.}-{2:2}, at: uart_port_lock_irqsave include/linux/serial_core.h:618 [inline]
 #2: ffff800093dcec98 (&port_lock_key){-.-.}-{2:2}, at: uart_write+0x114/0x2ec drivers/tty/serial/serial_core.c:624

stack backtrace:
CPU: 0 PID: 8095 Comm: syz-executor.3 Tainted: G        W          6.10.0-rc3-syzkaller-gac2193b4b460 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/02/2024
Call trace:
 dump_backtrace+0x1b8/0x1e4 arch/arm64/kernel/stacktrace.c:317
 show_stack+0x2c/0x3c arch/arm64/kernel/stacktrace.c:324
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xe4/0x150 lib/dump_stack.c:114
 dump_stack+0x1c/0x28 lib/dump_stack.c:123
 print_circular_bug+0x150/0x1b8 kernel/locking/lockdep.c:2060
 check_noncircular+0x310/0x404 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:3869 [inline]
 __lock_acquire+0x3384/0x763c kernel/locking/lockdep.c:5137
 lock_acquire+0x240/0x728 kernel/locking/lockdep.c:5754
 console_trylock_spinning+0x1f8/0x3d8 kernel/printk/printk.c:1994
 vprintk_emit+0x1cc/0x344 kernel/printk/printk.c:2344
 vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2360
 vprintk+0x200/0x2d4 kernel/printk/printk_safe.c:45
 _printk+0xdc/0x128 kernel/printk/printk.c:2370
 __report_bug lib/bug.c:195 [inline]
 report_bug+0x3b8/0x5b0 lib/bug.c:219
 bug_handler+0x50/0x1fc arch/arm64/kernel/traps.c:978
 call_break_hook arch/arm64/kernel/debug-monitors.c:321 [inline]
 brk_handler+0x17c/0x2e0 arch/arm64/kernel/debug-monitors.c:328
 do_debug_exception+0x1e4/0x398 arch/arm64/mm/fault.c:909
 el1_dbg+0x64/0x80 arch/arm64/kernel/entry-common.c:472
 el1h_64_sync_handler+0x40/0xac arch/arm64/kernel/entry-common.c:512
 el1h_64_sync+0x64/0x68 arch/arm64/kernel/entry.S:593
 spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
 uart_port_unlock_irqrestore include/linux/serial_core.h:669 [inline]
 uart_write+0x280/0x2ec drivers/tty/serial/serial_core.c:626
 tnc_init drivers/net/hamradio/6pack.c:531 [inline]
 sixpack_open+0x5d8/0x8b0 drivers/net/hamradio/6pack.c:628
 tty_ldisc_open+0x9c/0x14c drivers/tty/tty_ldisc.c:432
 tty_set_ldisc+0x2f8/0x4e0 drivers/tty/tty_ldisc.c:563
 tiocsetd+0x100/0x13c drivers/tty/tty_io.c:2439
 tty_ioctl+0xba0/0xd8c drivers/tty/tty_io.c:2739
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:907 [inline]
 __se_sys_ioctl fs/ioctl.c:893 [inline]
 __arm64_sys_ioctl+0x14c/0x1c8 fs/ioctl.c:893
 __invoke_syscall arch/arm64/kernel/syscall.c:34 [inline]
 invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:48
 el0_svc_common+0x130/0x23c arch/arm64/kernel/syscall.c:133
 do_el0_svc+0x48/0x58 arch/arm64/kernel/syscall.c:152
 el0_svc+0x54/0x168 arch/arm64/kernel/entry-common.c:712
 el0t_64_sync_handler+0x84/0xfc arch/arm64/kernel/entry-common.c:730
 el0t_64_sync+0x190/0x194 arch/arm64/kernel/entry.S:598
WARNING: CPU: 0 PID: 8095 at drivers/tty/serial/serial_core.c:625 spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
WARNING: CPU: 0 PID: 8095 at drivers/tty/serial/serial_core.c:625 uart_port_unlock_irqrestore include/linux/serial_core.h:669 [inline]
WARNING: CPU: 0 PID: 8095 at drivers/tty/serial/serial_core.c:625 uart_write+0x280/0x2ec drivers/tty/serial/serial_core.c:626
Modules linked in:
CPU: 0 PID: 8095 Comm: syz-executor.3 Tainted: G        W          6.10.0-rc3-syzkaller-gac2193b4b460 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/02/2024
pstate: 804000c5 (Nzcv daIF +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
pc : uart_write+0x280/0x2ec include/linux/spinlock.h:406
lr : uart_write+0x278/0x2ec drivers/tty/serial/serial_core.c:625
sp : ffff80009cd07ad0
x29: ffff80009cd07ad0 x28: 1ffff000139a0f68
 x27: dfff800000000000

x26: 0000000000000001
 x25: dfff800000000000 x24: ffff0000c8f38f48
x23: 0000000000000000 x22: ffff800093dcec80 x21: ffff80009cd07b60
x20: 0000000000000001 x19: ffff0000c8f38be8
 x18: 0000000000000019

x17: 000000000002bdb0
 x16: ffff800080350d3c
 x15: ffff7000139a0f40

x14: 1ffff000139a0f40 x13: 0000000000000004 x12: ffffffffffffffff
x11: 0000000000040000
 x10: 000000000001ea5a
 x9 : ffff8000a5604000

x8 : 000000000001ea5b
 x7 : 0000000000000000 x6 : 0000000000000000
x5 : 0000000000000020 x4 : 0000000000000000 x3 : ffff800080350e64
x2 : 0000000000000001
 x1 : 0000000000000000
 x0 : ffff800093dcec80

Call trace:
 spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
 uart_port_unlock_irqrestore include/linux/serial_core.h:669 [inline]
 uart_write+0x280/0x2ec drivers/tty/serial/serial_core.c:626
 tnc_init drivers/net/hamradio/6pack.c:531 [inline]
 sixpack_open+0x5d8/0x8b0 drivers/net/hamradio/6pack.c:628
 tty_ldisc_open+0x9c/0x14c drivers/tty/tty_ldisc.c:432
 tty_set_ldisc+0x2f8/0x4e0 drivers/tty/tty_ldisc.c:563
 tiocsetd+0x100/0x13c drivers/tty/tty_io.c:2439
 tty_ioctl+0xba0/0xd8c drivers/tty/tty_io.c:2739
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:907 [inline]
 __se_sys_ioctl fs/ioctl.c:893 [inline]
 __arm64_sys_ioctl+0x14c/0x1c8 fs/ioctl.c:893
 __invoke_syscall arch/arm64/kernel/syscall.c:34 [inline]
 invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:48
 el0_svc_common+0x130/0x23c arch/arm64/kernel/syscall.c:133
 do_el0_svc+0x48/0x58 arch/arm64/kernel/syscall.c:152
 el0_svc+0x54/0x168 arch/arm64/kernel/entry-common.c:712
 el0t_64_sync_handler+0x84/0xfc arch/arm64/kernel/entry-common.c:730
 el0t_64_sync+0x190/0x194 arch/arm64/kernel/entry.S:598
irq event stamp: 2020
hardirqs last  enabled at (2019): [<ffff8000802ae854>] raw_spin_rq_unlock_irq kernel/sched/sched.h:1418 [inline]
hardirqs last  enabled at (2019): [<ffff8000802ae854>] finish_lock_switch+0xbc/0x1e4 kernel/sched/core.c:5162
hardirqs last disabled at (2020): [<ffff80008b1608a8>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (2020): [<ffff80008b1608a8>] _raw_spin_lock_irqsave+0x2c/0x7c kernel/locking/spinlock.c:162
softirqs last  enabled at (1842): [<ffff80008925f1c4>] neigh_parms_alloc+0x330/0x464 net/core/neighbour.c:1738
softirqs last disabled at (1840): [<ffff80008925f118>] neigh_parms_alloc+0x284/0x464 net/core/neighbour.c:1736
---[ end trace 0000000000000000 ]---

Crashes (3):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/06/24 11:13 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci ac2193b4b460 edc5149a .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-gce-arm64 possible deadlock in console_trylock_spinning
2024/06/21 03:49 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci ac2193b4b460 dac2aa43 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-gce-arm64 possible deadlock in console_trylock_spinning
2024/06/09 10:46 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci 8867bbd4a056 82c05ab8 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-gce-arm64 possible deadlock in console_trylock_spinning
* Struck through repros no longer work on HEAD.