syzbot


possible deadlock in console_trylock_spinning

Status: auto-obsoleted due to no activity on 2023/11/27 19:44
Reported-by: syzbot+c206e31feec0763acc6b@syzkaller.appspotmail.com
First crash: 577d, last: 459d
Similar bugs (3)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in console_trylock_spinning serial C done inconclusive 168 920d 1981d 0/28 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 C done 70 15d 358d 0/3 upstream: reported C repro on 2023/11/29 03:09
upstream possible deadlock in console_trylock_spinning (2) serial 3 150d 161d 0/28 auto-obsoleted due to no activity on 2024/10/02 11:14

Sample crash report:
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 0
======================================================
WARNING: possible circular locking dependency detected
5.15.108-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.4/14717 is trying to acquire lock:
ffffffff8c9104a0 (console_owner){-...}-{0:0}, at: console_trylock_spinning+0x185/0x3f0 kernel/printk/printk.c:1879

but task is already holding lock:
ffff8880193fb958 (&port->lock){-.-.}-{2:2}, at: tty_insert_flip_string_and_push_buffer+0x3a/0x390 drivers/tty/tty_buffer.c:585

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (&port->lock){-.-.}-{2:2}:
       lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5622
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0xd1/0x120 kernel/locking/spinlock.c:162
       tty_port_tty_get drivers/tty/tty_port.c:289 [inline]
       tty_port_default_wakeup+0x21/0x100 drivers/tty/tty_port.c:48
       serial8250_tx_chars+0x60d/0x800 drivers/tty/serial/8250/8250_port.c:1847
       serial8250_handle_irq+0x3c4/0x480 drivers/tty/serial/8250/8250_port.c:1937
       serial8250_default_handle_irq+0xc8/0x1e0 drivers/tty/serial/8250/8250_port.c:1954
       serial8250_interrupt+0xa1/0x1e0 drivers/tty/serial/8250/8250_core.c:127
       __handle_irq_event_percpu+0x292/0xa70 kernel/irq/handle.c:156
       handle_irq_event_percpu kernel/irq/handle.c:196 [inline]
       handle_irq_event+0xff/0x2b0 kernel/irq/handle.c:213
       handle_edge_irq+0x245/0xbf0 kernel/irq/chip.c:822
       generic_handle_irq_desc include/linux/irqdesc.h:158 [inline]
       handle_irq arch/x86/kernel/irq.c:231 [inline]
       __common_interrupt+0xd7/0x1f0 arch/x86/kernel/irq.c:250
       common_interrupt+0x9f/0xc0 arch/x86/kernel/irq.c:240
       asm_common_interrupt+0x22/0x40 arch/x86/include/asm/idtentry.h:629
       native_safe_halt arch/x86/include/asm/irqflags.h:51 [inline]
       arch_safe_halt arch/x86/include/asm/irqflags.h:89 [inline]
       acpi_safe_halt drivers/acpi/processor_idle.c:109 [inline]
       acpi_idle_do_entry+0x10f/0x340 drivers/acpi/processor_idle.c:570
       acpi_idle_enter+0x352/0x4f0 drivers/acpi/processor_idle.c:705
       cpuidle_enter_state+0x521/0xef0 drivers/cpuidle/cpuidle.c:237
       cpuidle_enter+0x59/0x90 drivers/cpuidle/cpuidle.c:351
       call_cpuidle kernel/sched/idle.c:158 [inline]
       cpuidle_idle_call kernel/sched/idle.c:239 [inline]
       do_idle+0x3e4/0x670 kernel/sched/idle.c:306
       cpu_startup_entry+0x14/0x20 kernel/sched/idle.c:403
       start_kernel+0x48c/0x535 init/main.c:1144
       secondary_startup_64_no_verify+0xb1/0xbb

-> #1 (&port_lock_key){-.-.}-{2:2}:
       lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5622
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0xd1/0x120 kernel/locking/spinlock.c:162
       serial8250_console_write+0x19d/0x1180 drivers/tty/serial/8250/8250_port.c:3365
       console_unlock+0xced/0x12b0 kernel/printk/printk.c:2734
       vprintk_emit+0xba/0x150 kernel/printk/printk.c:2268
       _printk+0xd1/0x111 kernel/printk/printk.c:2289
       register_console+0x68c/0x970 kernel/printk/printk.c:3074
       univ8250_console_init+0x41/0x43 drivers/tty/serial/8250/8250_core.c:690
       console_init+0x18c/0x652 kernel/printk/printk.c:3174
       start_kernel+0x2f7/0x535 init/main.c:1072
       secondary_startup_64_no_verify+0xb1/0xbb

-> #0 (console_owner){-...}-{0:0}:
       check_prev_add kernel/locking/lockdep.c:3053 [inline]
       check_prevs_add kernel/locking/lockdep.c:3172 [inline]
       validate_chain+0x1646/0x58b0 kernel/locking/lockdep.c:3787
       __lock_acquire+0x1295/0x1ff0 kernel/locking/lockdep.c:5011
       lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5622
       console_trylock_spinning+0x1a5/0x3f0 kernel/printk/printk.c:1896
       vprintk_emit+0xa1/0x150 kernel/printk/printk.c:2267
       _printk+0xd1/0x111 kernel/printk/printk.c:2289
       fail_dump lib/fault-inject.c:45 [inline]
       should_fail+0x36c/0x4c0 lib/fault-inject.c:146
       should_failslab+0x5/0x20 mm/slab_common.c:1337
       slab_pre_alloc_hook+0x53/0xc0 mm/slab.h:494
       slab_alloc_node mm/slub.c:3134 [inline]
       slab_alloc mm/slub.c:3228 [inline]
       __kmalloc+0x6e/0x300 mm/slub.c:4403
       kmalloc include/linux/slab.h:596 [inline]
       tty_buffer_alloc drivers/tty/tty_buffer.c:177 [inline]
       __tty_buffer_request_room+0x1ef/0x500 drivers/tty/tty_buffer.c:276
       tty_insert_flip_string_fixed_flag drivers/tty/tty_buffer.c:322 [inline]
       tty_insert_flip_string include/linux/tty_flip.h:41 [inline]
       tty_insert_flip_string_and_push_buffer+0x7c/0x390 drivers/tty/tty_buffer.c:586
       process_output_block drivers/tty/n_tty.c:592 [inline]
       n_tty_write+0xd7e/0x1280 drivers/tty/n_tty.c:2322
       do_tty_write drivers/tty/tty_io.c:1038 [inline]
       file_tty_write+0x561/0x920 drivers/tty/tty_io.c:1110
       call_write_iter include/linux/fs.h:2103 [inline]
       new_sync_write fs/read_write.c:507 [inline]
       vfs_write+0xacf/0xe50 fs/read_write.c:594
       ksys_write+0x1a2/0x2c0 fs/read_write.c:647
       do_syscall_x64 arch/x86/entry/common.c:50 [inline]
       do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
       entry_SYSCALL_64_after_hwframe+0x61/0xcb

other info that might help us debug this:

Chain exists of:
  console_owner --> &port_lock_key --> &port->lock

 Possible unsafe locking scenario:

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

 *** DEADLOCK ***

5 locks held by syz-executor.4/14717:
 #0: ffff888033111098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:252
 #1: ffff888033111130 (&tty->atomic_write_lock){+.+.}-{3:3}, at: tty_write_lock drivers/tty/tty_io.c:961 [inline]
 #1: ffff888033111130 (&tty->atomic_write_lock){+.+.}-{3:3}, at: do_tty_write drivers/tty/tty_io.c:984 [inline]
 #1: ffff888033111130 (&tty->atomic_write_lock){+.+.}-{3:3}, at: file_tty_write+0x24f/0x920 drivers/tty/tty_io.c:1110
 #2: ffff8880331112e8 (&o_tty->termios_rwsem/1){++++}-{3:3}, at: n_tty_write+0x252/0x1280 drivers/tty/n_tty.c:2305
 #3: ffffc9000b1d7378 (&ldata->output_lock){+.+.}-{3:3}, at: process_output_block drivers/tty/n_tty.c:547 [inline]
 #3: ffffc9000b1d7378 (&ldata->output_lock){+.+.}-{3:3}, at: n_tty_write+0x6b9/0x1280 drivers/tty/n_tty.c:2322
 #4: ffff8880193fb958 (&port->lock){-.-.}-{2:2}, at: tty_insert_flip_string_and_push_buffer+0x3a/0x390 drivers/tty/tty_buffer.c:585

stack backtrace:
CPU: 0 PID: 14717 Comm: syz-executor.4 Not tainted 5.15.108-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/14/2023
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
 check_noncircular+0x2f8/0x3b0 kernel/locking/lockdep.c:2133
 check_prev_add kernel/locking/lockdep.c:3053 [inline]
 check_prevs_add kernel/locking/lockdep.c:3172 [inline]
 validate_chain+0x1646/0x58b0 kernel/locking/lockdep.c:3787
 __lock_acquire+0x1295/0x1ff0 kernel/locking/lockdep.c:5011
 lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5622
 console_trylock_spinning+0x1a5/0x3f0 kernel/printk/printk.c:1896
 vprintk_emit+0xa1/0x150 kernel/printk/printk.c:2267
 _printk+0xd1/0x111 kernel/printk/printk.c:2289
 fail_dump lib/fault-inject.c:45 [inline]
 should_fail+0x36c/0x4c0 lib/fault-inject.c:146
 should_failslab+0x5/0x20 mm/slab_common.c:1337
 slab_pre_alloc_hook+0x53/0xc0 mm/slab.h:494
 slab_alloc_node mm/slub.c:3134 [inline]
 slab_alloc mm/slub.c:3228 [inline]
 __kmalloc+0x6e/0x300 mm/slub.c:4403
 kmalloc include/linux/slab.h:596 [inline]
 tty_buffer_alloc drivers/tty/tty_buffer.c:177 [inline]
 __tty_buffer_request_room+0x1ef/0x500 drivers/tty/tty_buffer.c:276
 tty_insert_flip_string_fixed_flag drivers/tty/tty_buffer.c:322 [inline]
 tty_insert_flip_string include/linux/tty_flip.h:41 [inline]
 tty_insert_flip_string_and_push_buffer+0x7c/0x390 drivers/tty/tty_buffer.c:586
 process_output_block drivers/tty/n_tty.c:592 [inline]
 n_tty_write+0xd7e/0x1280 drivers/tty/n_tty.c:2322
 do_tty_write drivers/tty/tty_io.c:1038 [inline]
 file_tty_write+0x561/0x920 drivers/tty/tty_io.c:1110
 call_write_iter include/linux/fs.h:2103 [inline]
 new_sync_write fs/read_write.c:507 [inline]
 vfs_write+0xacf/0xe50 fs/read_write.c:594
 ksys_write+0x1a2/0x2c0 fs/read_write.c:647
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x61/0xcb
RIP: 0033:0x7f318351a169
Code: 28 00 00 00 75 05 48 83 c4 28 c3 e8 f1 19 00 00 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f3181a8c168 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f3183639f80 RCX: 00007f318351a169
RDX: 0000000000001042 RSI: 00000000200001c0 RDI: 0000000000000003
RBP: 00007f3181a8c1d0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
R13: 00007ffd970ffdbf R14: 00007f3181a8c300 R15: 0000000000022000
 </TASK>
CPU: 0 PID: 14717 Comm: syz-executor.4 Not tainted 5.15.108-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/14/2023
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
 fail_dump lib/fault-inject.c:52 [inline]
 should_fail+0x38a/0x4c0 lib/fault-inject.c:146
 should_failslab+0x5/0x20 mm/slab_common.c:1337
 slab_pre_alloc_hook+0x53/0xc0 mm/slab.h:494
 slab_alloc_node mm/slub.c:3134 [inline]
 slab_alloc mm/slub.c:3228 [inline]
 __kmalloc+0x6e/0x300 mm/slub.c:4403
 kmalloc include/linux/slab.h:596 [inline]
 tty_buffer_alloc drivers/tty/tty_buffer.c:177 [inline]
 __tty_buffer_request_room+0x1ef/0x500 drivers/tty/tty_buffer.c:276
 tty_insert_flip_string_fixed_flag drivers/tty/tty_buffer.c:322 [inline]
 tty_insert_flip_string include/linux/tty_flip.h:41 [inline]
 tty_insert_flip_string_and_push_buffer+0x7c/0x390 drivers/tty/tty_buffer.c:586
 process_output_block drivers/tty/n_tty.c:592 [inline]
 n_tty_write+0xd7e/0x1280 drivers/tty/n_tty.c:2322
 do_tty_write drivers/tty/tty_io.c:1038 [inline]
 file_tty_write+0x561/0x920 drivers/tty/tty_io.c:1110
 call_write_iter include/linux/fs.h:2103 [inline]
 new_sync_write fs/read_write.c:507 [inline]
 vfs_write+0xacf/0xe50 fs/read_write.c:594
 ksys_write+0x1a2/0x2c0 fs/read_write.c:647
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x61/0xcb
RIP: 0033:0x7f318351a169
Code: 28 00 00 00 75 05 48 83 c4 28 c3 e8 f1 19 00 00 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f3181a8c168 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f3183639f80 RCX: 00007f318351a169
RDX: 0000000000001042 RSI: 00000000200001c0 RDI: 0000000000000003
RBP: 00007f3181a8c1d0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
R13: 00007ffd970ffdbf R14: 00007f3181a8c300 R15: 0000000000022000
 </TASK>

Crashes (4):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/04/24 10:31 linux-5.15.y 3299fb36854f 2b32bd34 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in console_trylock_spinning
2023/08/19 19:43 linux-5.15.y f6f7927ac664 d216d8a0 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 possible deadlock in console_trylock_spinning
2023/07/15 20:04 linux-5.15.y d54cfc420586 35d9ecc5 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 possible deadlock in console_trylock_spinning
2023/04/25 10:52 linux-5.15.y 3299fb36854f 65320f8e .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 possible deadlock in console_trylock_spinning
* Struck through repros no longer work on HEAD.