------------[ cut here ]------------ ====================================================== WARNING: possible circular locking dependency detected syzkaller #0 Not tainted ------------------------------------------------------ kworker/0:5/5320 is trying to acquire lock: ffffffff8e7509a0 (console_owner){....}-{0:0}, at: rcu_try_lock_acquire include/linux/rcupdate.h:317 [inline] ffffffff8e7509a0 (console_owner){....}-{0:0}, at: srcu_read_lock_nmisafe include/linux/srcu.h:428 [inline] ffffffff8e7509a0 (console_owner){....}-{0:0}, at: console_srcu_read_lock kernel/printk/printk.c:291 [inline] ffffffff8e7509a0 (console_owner){....}-{0:0}, at: console_flush_one_record kernel/printk/printk.c:3246 [inline] ffffffff8e7509a0 (console_owner){....}-{0:0}, at: console_flush_all+0x123/0xb20 kernel/printk/printk.c:3343 but task is already holding lock: ffff88801fc3a598 (&pool->lock){-.-.}-{2:2}, at: start_flush_work kernel/workqueue.c:4241 [inline] ffff88801fc3a598 (&pool->lock){-.-.}-{2:2}, at: __flush_work+0x1ef/0xc50 kernel/workqueue.c:4292 which lock already depends on the new lock. the existing dependency chain (in reverse order) is: -> #3 (&pool->lock){-.-.}-{2:2}: __raw_spin_lock include/linux/spinlock_api_smp.h:158 [inline] _raw_spin_lock+0x2e/0x40 kernel/locking/spinlock.c:154 __queue_work+0x80b/0x1020 kernel/workqueue.c:-1 queue_work_on+0x106/0x1d0 kernel/workqueue.c:2405 queue_work include/linux/workqueue.h:669 [inline] rpm_suspend+0xe85/0x1750 drivers/base/power/runtime.c:688 __pm_runtime_idle+0x12f/0x1a0 drivers/base/power/runtime.c:1129 pm_runtime_put include/linux/pm_runtime.h:551 [inline] __device_attach+0x34f/0x450 drivers/base/dd.c:1111 device_initial_probe+0xa1/0xd0 drivers/base/dd.c:1148 bus_probe_device+0x12a/0x220 drivers/base/bus.c:613 device_add+0x7b6/0xb70 drivers/base/core.c:3691 serial_base_port_add+0x18f/0x260 drivers/tty/serial/serial_base_bus.c:186 serial_core_port_device_add drivers/tty/serial/serial_core.c:3260 [inline] serial_core_register_port+0x375/0x28a0 drivers/tty/serial/serial_core.c:3299 serial8250_register_8250_port+0x1658/0x1fd0 drivers/tty/serial/8250/8250_core.c:822 serial_pnp_probe+0x568/0x7f0 drivers/tty/serial/8250/8250_pnp.c:480 pnp_device_probe+0x30b/0x4c0 drivers/pnp/driver.c:111 call_driver_probe drivers/base/dd.c:-1 [inline] really_probe+0x267/0xaf0 drivers/base/dd.c:721 __driver_probe_device+0x18c/0x320 drivers/base/dd.c:863 driver_probe_device+0x4f/0x240 drivers/base/dd.c:893 __driver_attach+0x34c/0x640 drivers/base/dd.c:1287 bus_for_each_dev+0x23b/0x2c0 drivers/base/bus.c:383 bus_add_driver+0x345/0x670 drivers/base/bus.c:756 driver_register+0x23a/0x320 drivers/base/driver.c:249 serial8250_init+0x8f/0x160 drivers/tty/serial/8250/8250_platform.c:317 do_one_initcall+0x250/0x8d0 init/main.c:1382 do_initcall_level+0x104/0x190 init/main.c:1444 do_initcalls+0x59/0xa0 init/main.c:1460 kernel_init_freeable+0x2a6/0x3e0 init/main.c:1692 kernel_init+0x1d/0x1d0 init/main.c:1582 ret_from_fork+0x51e/0xb90 arch/x86/kernel/process.c:158 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245 -> #2 (&dev->power.lock){-...}-{3:3}: __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:132 [inline] _raw_spin_lock_irqsave+0x40/0x60 kernel/locking/spinlock.c:162 __pm_runtime_resume+0x10f/0x180 drivers/base/power/runtime.c:1196 pm_runtime_get include/linux/pm_runtime.h:494 [inline] __uart_start+0x171/0x460 drivers/tty/serial/serial_core.c:149 uart_write+0x265/0xa10 drivers/tty/serial/serial_core.c:633 process_output_block drivers/tty/n_tty.c:557 [inline] n_tty_write+0xd84/0x12a0 drivers/tty/n_tty.c:2366 iterate_tty_write drivers/tty/tty_io.c:1006 [inline] file_tty_write+0x559/0xa20 drivers/tty/tty_io.c:1081 new_sync_write fs/read_write.c:595 [inline] vfs_write+0x61d/0xb90 fs/read_write.c:688 ksys_write+0x150/0x270 fs/read_write.c:740 do_syscall_x64 arch/x86/entry/syscall_64.c:63 [inline] do_syscall_64+0x14d/0xf80 arch/x86/entry/syscall_64.c:94 entry_SYSCALL_64_after_hwframe+0x77/0x7f -> #1 (&port_lock_key){-...}-{3:3}: __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:132 [inline] _raw_spin_lock_irqsave+0x40/0x60 kernel/locking/spinlock.c:162 uart_port_lock_irqsave include/linux/serial_core.h:717 [inline] serial8250_console_write+0x150/0x1ba0 drivers/tty/serial/8250/8250_port.c:3316 console_emit_next_record kernel/printk/printk.c:3183 [inline] console_flush_one_record kernel/printk/printk.c:3269 [inline] console_flush_all+0x718/0xb20 kernel/printk/printk.c:3343 __console_flush_and_unlock kernel/printk/printk.c:3373 [inline] console_unlock+0xd1/0x1c0 kernel/printk/printk.c:3413 vprintk_emit+0x485/0x560 kernel/printk/printk.c:2479 _printk+0xdd/0x130 kernel/printk/printk.c:2504 register_console+0xbc2/0xfa0 kernel/printk/printk.c:4208 univ8250_console_init+0x3a/0x70 drivers/tty/serial/8250/8250_core.c:515 console_init+0x10b/0x4d0 kernel/printk/printk.c:4407 start_kernel+0x22b/0x3d0 init/main.c:1147 x86_64_start_reservations+0x24/0x30 arch/x86/kernel/head64.c:310 x86_64_start_kernel+0x143/0x1c0 arch/x86/kernel/head64.c:291 common_startup_64+0x13e/0x147 -> #0 (console_owner){....}-{0:0}: check_prev_add kernel/locking/lockdep.c:3165 [inline] check_prevs_add kernel/locking/lockdep.c:3284 [inline] validate_chain kernel/locking/lockdep.c:3908 [inline] __lock_acquire+0x15a5/0x2cf0 kernel/locking/lockdep.c:5237 lock_acquire+0xf0/0x2e0 kernel/locking/lockdep.c:5868 console_lock_spinning_enable kernel/printk/printk.c:1902 [inline] console_emit_next_record kernel/printk/printk.c:3177 [inline] console_flush_one_record kernel/printk/printk.c:3269 [inline] console_flush_all+0x6c1/0xb20 kernel/printk/printk.c:3343 __console_flush_and_unlock kernel/printk/printk.c:3373 [inline] console_unlock+0xd1/0x1c0 kernel/printk/printk.c:3413 vprintk_emit+0x485/0x560 kernel/printk/printk.c:2479 _printk+0xdd/0x130 kernel/printk/printk.c:2504 __report_bug+0x317/0x540 lib/bug.c:240 report_bug_entry+0x19a/0x290 lib/bug.c:266 handle_bug+0xce/0x200 arch/x86/kernel/traps.c:430 exc_invalid_op+0x1a/0x50 arch/x86/kernel/traps.c:489 asm_exc_invalid_op+0x1a/0x20 arch/x86/include/asm/idtentry.h:616 check_flush_dependency+0x312/0x3c0 kernel/workqueue.c:3801 start_flush_work kernel/workqueue.c:4255 [inline] __flush_work+0x411/0xc50 kernel/workqueue.c:4292 hfs_file_fsync+0xee/0x140 fs/hfs/inode.c:710 generic_write_sync include/linux/fs.h:2640 [inline] dio_complete+0x5f4/0x790 fs/direct-io.c:313 process_one_work kernel/workqueue.c:3276 [inline] process_scheduled_works+0xb6e/0x18c0 kernel/workqueue.c:3359 worker_thread+0xa53/0xfc0 kernel/workqueue.c:3440 kthread+0x388/0x470 kernel/kthread.c:436 ret_from_fork+0x51e/0xb90 arch/x86/kernel/process.c:158 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245 other info that might help us debug this: Chain exists of: console_owner --> &dev->power.lock --> &pool->lock Possible unsafe locking scenario: CPU0 CPU1 ---- ---- lock(&pool->lock); lock(&dev->power.lock); lock(&pool->lock); lock(console_owner); *** DEADLOCK *** 7 locks held by kworker/0:5/5320: #0: ffff888012692d48 ((wq_completion)dio/loop0){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3251 [inline] #0: ffff888012692d48 ((wq_completion)dio/loop0){+.+.}-{0:0}, at: process_scheduled_works+0xa52/0x18c0 kernel/workqueue.c:3359 #1: ffffc9000f67fc40 ((work_completion)(&dio->complete_work)){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3252 [inline] #1: ffffc9000f67fc40 ((work_completion)(&dio->complete_work)){+.+.}-{0:0}, at: process_scheduled_works+0xa8d/0x18c0 kernel/workqueue.c:3359 #2: ffff8880127fb6a0 (&sb->s_type->i_mutex_key#25){+.+.}-{4:4}, at: inode_lock include/linux/fs.h:1028 [inline] #2: ffff8880127fb6a0 (&sb->s_type->i_mutex_key#25){+.+.}-{4:4}, at: hfs_file_fsync+0x9a/0x140 fs/hfs/inode.c:703 #3: ffffffff8e75e5e0 (rcu_read_lock){....}-{1:3}, at: rcu_lock_acquire include/linux/rcupdate.h:312 [inline] #3: ffffffff8e75e5e0 (rcu_read_lock){....}-{1:3}, at: rcu_read_lock include/linux/rcupdate.h:850 [inline] #3: ffffffff8e75e5e0 (rcu_read_lock){....}-{1:3}, at: start_flush_work kernel/workqueue.c:4234 [inline] #3: ffffffff8e75e5e0 (rcu_read_lock){....}-{1:3}, at: __flush_work+0x100/0xc50 kernel/workqueue.c:4292 #4: ffff88801fc3a598 (&pool->lock){-.-.}-{2:2}, at: start_flush_work kernel/workqueue.c:4241 [inline] #4: ffff88801fc3a598 (&pool->lock){-.-.}-{2:2}, at: __flush_work+0x1ef/0xc50 kernel/workqueue.c:4292 #5: ffffffff8e750a00 (console_lock){+.+.}-{0:0}, at: _printk+0xdd/0x130 kernel/printk/printk.c:2504 #6: ffffffff8e638298 (console_srcu){....}-{0:0}, at: rcu_try_lock_acquire include/linux/rcupdate.h:317 [inline] #6: ffffffff8e638298 (console_srcu){....}-{0:0}, at: srcu_read_lock_nmisafe include/linux/srcu.h:428 [inline] #6: ffffffff8e638298 (console_srcu){....}-{0:0}, at: console_srcu_read_lock kernel/printk/printk.c:291 [inline] #6: ffffffff8e638298 (console_srcu){....}-{0:0}, at: console_flush_one_record kernel/printk/printk.c:3246 [inline] #6: ffffffff8e638298 (console_srcu){....}-{0:0}, at: console_flush_all+0x123/0xb20 kernel/printk/printk.c:3343 stack backtrace: CPU: 0 UID: 0 PID: 5320 Comm: kworker/0:5 Not tainted syzkaller #0 PREEMPT(full) Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-debian-1.16.3-2 04/01/2014 Workqueue: dio/loop0 dio_aio_complete_work Call Trace: dump_stack_lvl+0xe8/0x150 lib/dump_stack.c:120 print_circular_bug+0x2e1/0x300 kernel/locking/lockdep.c:2043 check_noncircular+0x12e/0x150 kernel/locking/lockdep.c:2175 check_prev_add kernel/locking/lockdep.c:3165 [inline] check_prevs_add kernel/locking/lockdep.c:3284 [inline] validate_chain kernel/locking/lockdep.c:3908 [inline] __lock_acquire+0x15a5/0x2cf0 kernel/locking/lockdep.c:5237 lock_acquire+0xf0/0x2e0 kernel/locking/lockdep.c:5868 console_lock_spinning_enable kernel/printk/printk.c:1902 [inline] console_emit_next_record kernel/printk/printk.c:3177 [inline] console_flush_one_record kernel/printk/printk.c:3269 [inline] console_flush_all+0x6c1/0xb20 kernel/printk/printk.c:3343 __console_flush_and_unlock kernel/printk/printk.c:3373 [inline] console_unlock+0xd1/0x1c0 kernel/printk/printk.c:3413 vprintk_emit+0x485/0x560 kernel/printk/printk.c:2479 _printk+0xdd/0x130 kernel/printk/printk.c:2504 __report_bug+0x317/0x540 lib/bug.c:240 report_bug_entry+0x19a/0x290 lib/bug.c:266 handle_bug+0xce/0x200 arch/x86/kernel/traps.c:430 exc_invalid_op+0x1a/0x50 arch/x86/kernel/traps.c:489 asm_exc_invalid_op+0x1a/0x20 arch/x86/include/asm/idtentry.h:616 RIP: 0010:check_flush_dependency+0x312/0x3c0 kernel/workqueue.c:3801 Code: 00 00 fc ff df 80 3c 08 00 74 08 4c 89 f7 e8 05 ec a3 00 49 8b 16 48 81 c3 78 01 00 00 4c 89 ef 4c 89 e6 48 89 d9 4c 8b 04 24 <67> 48 0f b9 3a e9 53 ff ff ff 44 89 f1 80 e1 07 80 c1 03 38 c1 0f RSP: 0018:ffffc9000f67f840 EFLAGS: 00010086 RAX: 1ffff110039b4a03 RBX: ffff88801aca6178 RCX: ffff88801aca6178 RDX: ffffffff82595cf0 RSI: ffff888012692d78 RDI: ffffffff9014e930 RBP: ffff88801ef7d808 R08: ffffffff82b29060 R09: 1ffff11007fef129 R10: dffffc0000000000 R11: ffffed1007fef12a R12: ffff888012692d78 R13: ffffffff9014e930 R14: ffff88801cda5018 R15: ffff88801cda5020 start_flush_work kernel/workqueue.c:4255 [inline] __flush_work+0x411/0xc50 kernel/workqueue.c:4292 hfs_file_fsync+0xee/0x140 fs/hfs/inode.c:710 generic_write_sync include/linux/fs.h:2640 [inline] dio_complete+0x5f4/0x790 fs/direct-io.c:313 process_one_work kernel/workqueue.c:3276 [inline] process_scheduled_works+0xb6e/0x18c0 kernel/workqueue.c:3359 worker_thread+0xa53/0xfc0 kernel/workqueue.c:3440 kthread+0x388/0x470 kernel/kthread.c:436 ret_from_fork+0x51e/0xb90 arch/x86/kernel/process.c:158 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245 workqueue: WQ_MEM_RECLAIM dio/loop0:dio_aio_complete_work is flushing !WQ_MEM_RECLAIM events_long:flush_mdb WARNING: kernel/workqueue.c:3805 at check_flush_dependency+0x28f/0x3c0 kernel/workqueue.c:3801, CPU#0: kworker/0:5/5320 Modules linked in: CPU: 0 UID: 0 PID: 5320 Comm: kworker/0:5 Not tainted syzkaller #0 PREEMPT(full) Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-debian-1.16.3-2 04/01/2014 Workqueue: dio/loop0 dio_aio_complete_work RIP: 0010:check_flush_dependency+0x312/0x3c0 kernel/workqueue.c:3801 Code: 00 00 fc ff df 80 3c 08 00 74 08 4c 89 f7 e8 05 ec a3 00 49 8b 16 48 81 c3 78 01 00 00 4c 89 ef 4c 89 e6 48 89 d9 4c 8b 04 24 <67> 48 0f b9 3a e9 53 ff ff ff 44 89 f1 80 e1 07 80 c1 03 38 c1 0f RSP: 0018:ffffc9000f67f840 EFLAGS: 00010086 RAX: 1ffff110039b4a03 RBX: ffff88801aca6178 RCX: ffff88801aca6178 RDX: ffffffff82595cf0 RSI: ffff888012692d78 RDI: ffffffff9014e930 RBP: ffff88801ef7d808 R08: ffffffff82b29060 R09: 1ffff11007fef129 R10: dffffc0000000000 R11: ffffed1007fef12a R12: ffff888012692d78 R13: ffffffff9014e930 R14: ffff88801cda5018 R15: ffff88801cda5020 FS: 0000000000000000(0000) GS:ffff88808ca4c000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00007ffffffff000 CR3: 000000000bb52000 CR4: 0000000000352ef0 Call Trace: start_flush_work kernel/workqueue.c:4255 [inline] __flush_work+0x411/0xc50 kernel/workqueue.c:4292 hfs_file_fsync+0xee/0x140 fs/hfs/inode.c:710 generic_write_sync include/linux/fs.h:2640 [inline] dio_complete+0x5f4/0x790 fs/direct-io.c:313 process_one_work kernel/workqueue.c:3276 [inline] process_scheduled_works+0xb6e/0x18c0 kernel/workqueue.c:3359 worker_thread+0xa53/0xfc0 kernel/workqueue.c:3440 kthread+0x388/0x470 kernel/kthread.c:436 ret_from_fork+0x51e/0xb90 arch/x86/kernel/process.c:158 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245 ---------------- Code disassembly (best guess): 0: 00 00 add %al,(%rax) 2: fc cld 3: ff lcall (bad) 4: df 80 3c 08 00 74 filds 0x7400083c(%rax) a: 08 4c 89 f7 or %cl,-0x9(%rcx,%rcx,4) e: e8 05 ec a3 00 call 0xa3ec18 13: 49 8b 16 mov (%r14),%rdx 16: 48 81 c3 78 01 00 00 add $0x178,%rbx 1d: 4c 89 ef mov %r13,%rdi 20: 4c 89 e6 mov %r12,%rsi 23: 48 89 d9 mov %rbx,%rcx 26: 4c 8b 04 24 mov (%rsp),%r8 * 2a: 67 48 0f b9 3a ud1 (%edx),%rdi <-- trapping instruction 2f: e9 53 ff ff ff jmp 0xffffff87 34: 44 89 f1 mov %r14d,%ecx 37: 80 e1 07 and $0x7,%cl 3a: 80 c1 03 add $0x3,%cl 3d: 38 c1 cmp %al,%cl 3f: 0f .byte 0xf