syzbot


possible deadlock in __queue_work (2)

Status: auto-closed as invalid on 2021/10/17 12:42
Reported-by: syzbot+22265255cba038721721@syzkaller.appspotmail.com
First crash: 1256d, last: 1256d
Similar bugs (5)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.14 possible deadlock in __queue_work 7 1623d 1732d 0/1 auto-closed as invalid on 2020/10/15 10:06
linux-4.19 possible deadlock in __queue_work 3 1566d 1661d 0/1 auto-closed as invalid on 2020/12/11 19:10
upstream possible deadlock in __queue_work (2) serial 16 1004d 1004d 0/28 closed as invalid on 2022/02/27 14:14
upstream possible deadlock in __queue_work (3) serial 1 784d 780d 0/28 auto-obsoleted due to no activity on 2023/02/02 03:51
upstream possible deadlock in __queue_work serial 2 1251d 1309d 20/28 fixed on 2021/11/10 00:50

Sample crash report:
======================================================
WARNING: possible circular locking dependency detected
4.19.195-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.3/19943 is trying to acquire lock:
000000003aff6768 (&pool->lock/1){-.-.}, at: spin_lock include/linux/spinlock.h:329 [inline]
000000003aff6768 (&pool->lock/1){-.-.}, at: __queue_work+0x34a/0x1100 kernel/workqueue.c:1419

but task is already holding lock:
0000000079c09d8d (&port_lock_key){-.-.}, at: serial8250_handle_irq.part.0+0x21/0x3d0 drivers/tty/serial/8250/8250_port.c:1869

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&port_lock_key){-.-.}:
       serial8250_console_write+0x89b/0xad0 drivers/tty/serial/8250/8250_port.c:3270
       call_console_drivers kernel/printk/printk.c:1764 [inline]
       console_unlock+0xbb6/0x1110 kernel/printk/printk.c:2460
       vprintk_emit+0x2d1/0x740 kernel/printk/printk.c:1965
       vprintk_func+0x79/0x180 kernel/printk/printk_safe.c:405
       printk+0xba/0xed kernel/printk/printk.c:2040
       register_console+0x87f/0xc90 kernel/printk/printk.c:2776
       univ8250_console_init+0x3a/0x46 drivers/tty/serial/8250/8250_core.c:684
       console_init+0x4cb/0x718 kernel/printk/printk.c:2862
       start_kernel+0x686/0x911 init/main.c:659
       secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:243

-> #2 (console_owner){-...}:
       vprintk_emit+0x2d1/0x740 kernel/printk/printk.c:1965
       vprintk_func+0x79/0x180 kernel/printk/printk_safe.c:405
       printk+0xba/0xed kernel/printk/printk.c:2040
       show_pwq kernel/workqueue.c:4495 [inline]
       show_workqueue_state.cold+0x3e4/0x104e kernel/workqueue.c:4591
       try_to_freeze_tasks.cold+0x77/0x406 kernel/power/process.c:97
       freeze_kernel_threads+0x53/0xd1 kernel/power/process.c:177
       suspend_freeze_processes kernel/power/power.h:264 [inline]
       suspend_prepare kernel/power/suspend.c:365 [inline]
       enter_state kernel/power/suspend.c:581 [inline]
       pm_suspend kernel/power/suspend.c:618 [inline]
       pm_suspend.cold+0x1041/0x1665 kernel/power/suspend.c:610
       state_store+0xe5/0x220 kernel/power/main.c:532
       kobj_attr_store+0x50/0x80 lib/kobject.c:811
       sysfs_kf_write+0x110/0x160 fs/sysfs/file.c:140
       kernfs_fop_write+0x2b0/0x470 fs/kernfs/file.c:316
       __vfs_write+0xf7/0x770 fs/read_write.c:485
       __kernel_write+0x109/0x370 fs/read_write.c:506
       write_pipe_buf+0x153/0x1f0 fs/splice.c:798
       splice_from_pipe_feed fs/splice.c:503 [inline]
       __splice_from_pipe+0x389/0x800 fs/splice.c:627
       splice_from_pipe fs/splice.c:662 [inline]
       default_file_splice_write+0xd8/0x180 fs/splice.c:810
       do_splice_from fs/splice.c:852 [inline]
       direct_splice_actor+0x115/0x160 fs/splice.c:1025
       splice_direct_to_actor+0x33f/0x8d0 fs/splice.c:980
       do_splice_direct+0x1a7/0x270 fs/splice.c:1068
       do_sendfile+0x550/0xc30 fs/read_write.c:1447
       __do_sys_sendfile64 fs/read_write.c:1502 [inline]
       __se_sys_sendfile64+0xc4/0x160 fs/read_write.c:1494
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #1 (&(&pool->lock)->rlock){-.-.}:
       spin_lock include/linux/spinlock.h:329 [inline]
       __queue_work+0x34a/0x1100 kernel/workqueue.c:1419
       queue_work_on+0x17e/0x1f0 kernel/workqueue.c:1489
       queue_work include/linux/workqueue.h:512 [inline]
       schedule_work include/linux/workqueue.h:570 [inline]
       put_pwq+0x15a/0x1b0 kernel/workqueue.c:1091
       put_pwq_unlocked kernel/workqueue.c:1108 [inline]
       put_pwq_unlocked kernel/workqueue.c:1100 [inline]
       destroy_workqueue+0x649/0x790 kernel/workqueue.c:4248
       do_floppy_init drivers/block/floppy.c:4738 [inline]
       floppy_async_init+0x1eed/0x2026 drivers/block/floppy.c:4755
       async_run_entry_fn+0xd3/0x6f0 kernel/async.c:127
       process_one_work+0x864/0x1570 kernel/workqueue.c:2153
       worker_thread+0x64c/0x1130 kernel/workqueue.c:2296
       kthread+0x33f/0x460 kernel/kthread.c:259
       ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

-> #0 (&pool->lock/1){-.-.}:
       __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
       _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
       spin_lock include/linux/spinlock.h:329 [inline]
       __queue_work+0x34a/0x1100 kernel/workqueue.c:1419
       queue_work_on+0x17e/0x1f0 kernel/workqueue.c:1489
       serial8250_rx_chars+0xcc/0xf0 drivers/tty/serial/8250/8250_port.c:1763
       serial8250_handle_irq.part.0+0x289/0x3d0 drivers/tty/serial/8250/8250_port.c:1888
       serial8250_handle_irq drivers/tty/serial/8250/8250_port.c:1866 [inline]
       serial8250_default_handle_irq+0xae/0x220 drivers/tty/serial/8250/8250_port.c:1909
       serial8250_interrupt+0x101/0x240 drivers/tty/serial/8250/8250_core.c:125
       __handle_irq_event_percpu+0x27e/0x8e0 kernel/irq/handle.c:149
       handle_irq_event_percpu kernel/irq/handle.c:189 [inline]
       handle_irq_event+0x102/0x290 kernel/irq/handle.c:206
       handle_edge_irq+0x260/0xcf0 kernel/irq/chip.c:797
       generic_handle_irq_desc include/linux/irqdesc.h:155 [inline]
       handle_irq+0x35/0x50 arch/x86/kernel/irq_64.c:87
       do_IRQ+0x93/0x1c0 arch/x86/kernel/irq.c:246
       ret_from_intr+0x0/0x1e
       arch_local_irq_restore arch/x86/include/asm/paravirt.h:789 [inline]
       __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
       _raw_spin_unlock_irqrestore+0xa3/0xe0 kernel/locking/spinlock.c:184
       __debug_object_init+0x410/0x9b0 lib/debugobjects.c:418
       init_timer_on_stack_key kernel/time/timer.c:746 [inline]
       schedule_timeout+0x100/0xfe0 kernel/time/timer.c:1816
       schedule_timeout_interruptible kernel/time/timer.c:1838 [inline]
       msleep_interruptible+0xa7/0x120 kernel/time/timer.c:1984
       send_break.part.0+0x116/0x230 drivers/tty/tty_io.c:2418
       send_break drivers/tty/tty_io.c:2478 [inline]
       tty_ioctl+0x12a7/0x15c0 drivers/tty/tty_io.c:2634
       vfs_ioctl fs/ioctl.c:46 [inline]
       file_ioctl fs/ioctl.c:501 [inline]
       do_vfs_ioctl+0xcdb/0x12e0 fs/ioctl.c:688
       ksys_ioctl+0x9b/0xc0 fs/ioctl.c:705
       __do_sys_ioctl fs/ioctl.c:712 [inline]
       __se_sys_ioctl fs/ioctl.c:710 [inline]
       __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:710
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

other info that might help us debug this:

Chain exists of:
  &pool->lock/1 --> console_owner --> &port_lock_key

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&port_lock_key);
                               lock(console_owner);
                               lock(&port_lock_key);
  lock(&pool->lock/1);

 *** DEADLOCK ***

3 locks held by syz-executor.3/19943:
 #0: 00000000cb0bdd08 (&tty->atomic_write_lock){+.+.}, at: tty_write_lock drivers/tty/tty_io.c:886 [inline]
 #0: 00000000cb0bdd08 (&tty->atomic_write_lock){+.+.}, at: send_break.part.0+0x21/0x230 drivers/tty/tty_io.c:2412
 #1: 00000000dc599515 (&(&i->lock)->rlock){-.-.}, at: spin_lock include/linux/spinlock.h:329 [inline]
 #1: 00000000dc599515 (&(&i->lock)->rlock){-.-.}, at: serial8250_interrupt+0x3a/0x240 drivers/tty/serial/8250/8250_core.c:115
 #2: 0000000079c09d8d (&port_lock_key){-.-.}, at: serial8250_handle_irq.part.0+0x21/0x3d0 drivers/tty/serial/8250/8250_port.c:1869

stack backtrace:
CPU: 0 PID: 19943 Comm: syz-executor.3 Not tainted 4.19.195-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2ef lib/dump_stack.c:118
 print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1222
 check_prev_add kernel/locking/lockdep.c:1866 [inline]
 check_prevs_add kernel/locking/lockdep.c:1979 [inline]
 validate_chain kernel/locking/lockdep.c:2420 [inline]
 __lock_acquire+0x30c9/0x3ff0 kernel/locking/lockdep.c:3416
 lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3908
 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
 _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:144
 spin_lock include/linux/spinlock.h:329 [inline]
 __queue_work+0x34a/0x1100 kernel/workqueue.c:1419
 queue_work_on+0x17e/0x1f0 kernel/workqueue.c:1489
 serial8250_rx_chars+0xcc/0xf0 drivers/tty/serial/8250/8250_port.c:1763
 serial8250_handle_irq.part.0+0x289/0x3d0 drivers/tty/serial/8250/8250_port.c:1888
 serial8250_handle_irq drivers/tty/serial/8250/8250_port.c:1866 [inline]
 serial8250_default_handle_irq+0xae/0x220 drivers/tty/serial/8250/8250_port.c:1909
 serial8250_interrupt+0x101/0x240 drivers/tty/serial/8250/8250_core.c:125
 __handle_irq_event_percpu+0x27e/0x8e0 kernel/irq/handle.c:149
 handle_irq_event_percpu kernel/irq/handle.c:189 [inline]
 handle_irq_event+0x102/0x290 kernel/irq/handle.c:206
 handle_edge_irq+0x260/0xcf0 kernel/irq/chip.c:797
 generic_handle_irq_desc include/linux/irqdesc.h:155 [inline]
 handle_irq+0x35/0x50 arch/x86/kernel/irq_64.c:87
 do_IRQ+0x93/0x1c0 arch/x86/kernel/irq.c:246
 common_interrupt+0xf/0xf arch/x86/entry/entry_64.S:670
 </IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:789 [inline]
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0xa3/0xe0 kernel/locking/spinlock.c:184
Code: 48 c7 c0 48 82 f1 89 48 ba 00 00 00 00 00 fc ff df 48 c1 e8 03 80 3c 10 00 75 2f 48 83 3d 5c 15 d9 01 00 74 15 48 89 df 57 9d <0f> 1f 44 00 00 eb b2 e8 1b d0 e7 f8 eb c0 0f 0b 0f 0b 48 c7 c7 48
RSP: 0018:ffff88803a897960 EFLAGS: 00000286 ORIG_RAX: ffffffffffffffd6
RAX: 1ffffffff13e3049 RBX: 0000000000000286 RCX: 1ffff1100803c985
RDX: dffffc0000000000 RSI: ffff8880401e4c08 RDI: 0000000000000286
RBP: ffffffff8d3f2548 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000286
R13: ffff8880ab376578 R14: ffffffff8d3f2548 R15: 0000000000000000
 __debug_object_init+0x410/0x9b0 lib/debugobjects.c:418
 init_timer_on_stack_key kernel/time/timer.c:746 [inline]
 schedule_timeout+0x100/0xfe0 kernel/time/timer.c:1816
 schedule_timeout_interruptible kernel/time/timer.c:1838 [inline]
 msleep_interruptible+0xa7/0x120 kernel/time/timer.c:1984
 send_break.part.0+0x116/0x230 drivers/tty/tty_io.c:2418
 send_break drivers/tty/tty_io.c:2478 [inline]
 tty_ioctl+0x12a7/0x15c0 drivers/tty/tty_io.c:2634
 vfs_ioctl fs/ioctl.c:46 [inline]
 file_ioctl fs/ioctl.c:501 [inline]
 do_vfs_ioctl+0xcdb/0x12e0 fs/ioctl.c:688
 ksys_ioctl+0x9b/0xc0 fs/ioctl.c:705
 __do_sys_ioctl fs/ioctl.c:712 [inline]
 __se_sys_ioctl fs/ioctl.c:710 [inline]
 __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:710
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4665d9
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 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 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fa6c3ab5188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665d9
RDX: 0000000000000000 RSI: 0000000000005425 RDI: 0000000000000004
RBP: 00000000004bfcb9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80
R13: 00007fff7ba5260f R14: 00007fa6c3ab5300 R15: 0000000000022000
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 1
audit: type=1804 audit(1624106505.995:116): pid=19997 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir508237569/syzkaller.5Cl8FN/369/bus" dev="sda1" ino=14796 res=1
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
CPU: 0 PID: 19991 Comm: syz-executor.1 Not tainted 4.19.195-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2ef lib/dump_stack.c:118
 fail_dump lib/fault-inject.c:51 [inline]
 should_fail.cold+0xa/0xf lib/fault-inject.c:149
 __should_failslab+0x115/0x180 mm/failslab.c:32
 should_failslab+0x5/0x10 mm/slab_common.c:1588
 slab_pre_alloc_hook mm/slab.h:424 [inline]
 slab_alloc mm/slab.c:3383 [inline]
 kmem_cache_alloc_trace+0x284/0x380 mm/slab.c:3623
 kmalloc include/linux/slab.h:515 [inline]
 key_user_lookup+0x191/0x4e0 security/keys/key.c:84
 keyctl_chown_key+0x476/0xc60 security/keys/keyctl.c:939
 __do_sys_keyctl security/keys/keyctl.c:1748 [inline]
 __se_sys_keyctl+0x2df/0x3f0 security/keys/keyctl.c:1701
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4665d9
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 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 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f01974ea188 EFLAGS: 00000246 ORIG_RAX: 00000000000000fa
RAX: ffffffffffffffda RBX: 000000000056c038 RCX: 00000000004665d9
RDX: 0000000000000cff RSI: 000000000f67a3b5 RDI: 0000000000000004
RBP: 00007f01974ea1d0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
R13: 00007ffd341fc70f R14: 00007f01974ea300 R15: 0000000000022000
audit: type=1804 audit(1624106506.335:117): pid=20014 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.0" name="/root/syzkaller-testdir508237569/syzkaller.5Cl8FN/369/bus" dev="sda1" ino=14796 res=1
audit: type=1804 audit(1624106506.515:118): pid=19985 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir508237569/syzkaller.5Cl8FN/369/bus" dev="sda1" ino=14796 res=1
audit: type=1804 audit(1624106506.515:119): pid=19985 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.0" name="/root/syzkaller-testdir508237569/syzkaller.5Cl8FN/369/bus" dev="sda1" ino=14796 res=1
audit: type=1800 audit(1624106507.145:120): pid=20140 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.0" name=".log" dev="sda1" ino=14841 res=0
audit: type=1800 audit(1624106507.145:121): pid=20140 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.0" name=".log" dev="sda1" ino=14841 res=0
audit: type=1800 audit(1624106507.175:122): pid=20139 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.5" name=".pending_reads" dev="sda1" ino=14853 res=0
audit: type=1800 audit(1624106507.175:123): pid=20139 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.5" name=".pending_reads" dev="sda1" ino=14853 res=0
audit: type=1800 audit(1624106507.455:124): pid=20184 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.3" name=".pending_reads" dev="sda1" ino=14855 res=0
audit: type=1800 audit(1624106507.455:125): pid=20184 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.3" name=".pending_reads" dev="sda1" ino=14855 res=0
xt_NFQUEUE: number of queues (64511) out of range (got 65790)
xt_NFQUEUE: number of queues (64511) out of range (got 65790)
UDF-fs: bad mount option "bs=00000000000000019993" or missing value
xt_NFQUEUE: number of queues (64511) out of range (got 65790)
xt_NFQUEUE: number of queues (64511) out of range (got 65790)
UDF-fs: bad mount option "bs=00000000000000019993" or missing value
UDF-fs: bad mount option "bs=00000000000000019993" or missing value
UDF-fs: bad mount option "bs=00000000000000019993" or missing value
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.0'.
UDF-fs: bad mount option "bs=00000000000000019993" or missing value
UDF-fs: bad mount option "bs=00000000000000019993" or missing value
UDF-fs: bad mount option "bs=00000000000000019993" or missing value
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.0'.
ptrace attach of "/root/syz-executor.4"[13957] was attempted by "/root/syz-executor.4"[20464]
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.5'.
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.0'.
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.5'.
ieee802154 phy0 wpan0: encryption failed: -22
ieee802154 phy1 wpan1: encryption failed: -22
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.5'.
netlink: 32 bytes leftover after parsing attributes in process `syz-executor.0'.
raw_sendmsg: syz-executor.4 forgot to set AF_INET. Fix it!
x_tables: ip6_tables: DNAT target: used from hooks INPUT, but only usable from PREROUTING/OUTPUT

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2021/06/19 12:41 linux-4.19.y eb575cd5d7f6 aba2b2fb .config console log report info ci2-linux-4-19 possible deadlock in __queue_work
* Struck through repros no longer work on HEAD.