BUG: workqueue lockup - pool cpus=0 node=0 flags=0x0 nice=0 stuck for 258s! INFO: task kworker/u4:73:2542 blocked for more than 140 seconds. Showing busy workqueues and worker pools: Not tainted 4.14.134+ #19 workqueue events: flags=0x0 pwq 0: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. cpus=0 kworker/u4:73 D node=0 flags=0x0 nice=0 active=5/256 in-flight: 4654:rtc_timer_do_work pending: free_obj_work, vmstat_shepherd, bpf_map_free_deferred, bpf_prog_free_deferred ====================================================== WARNING: possible circular locking dependency detected 4.14.134+ #19 Not tainted ------------------------------------------------------ kworker/0:3/4654 is trying to acquire lock: (console_owner){-.-.}, at: [<000000006478ae30>] console_trylock_spinning kernel/printk/printk.c:1652 [inline] (console_owner){-.-.}, at: [<000000006478ae30>] vprintk_emit+0x1b8/0x330 kernel/printk/printk.c:1916 but task is already holding lock: (&(&pool->lock)->rlock){-.-.}, at: [<00000000d19bc57a>] show_workqueue_state kernel/workqueue.c:4518 [inline] (&(&pool->lock)->rlock){-.-.}, at: [<00000000d19bc57a>] show_workqueue_state.cold+0x22f/0xeb3 kernel/workqueue.c:4491 which lock already depends on the new lock. the existing dependency chain (in reverse order) is: -> #4 (&(&pool->lock)->rlock){-.-.}: -> #3 (&pool->lock/1){..-.}: -> #2 (&(&port->lock)->rlock){-.-.}: -> #1 (&port_lock_key){-.-.}: -> #0 (console_owner){-.-.}: other info that might help us debug this: Chain exists of: console_owner --> &pool->lock/1 --> &(&pool->lock)->rlock Possible unsafe locking scenario: CPU0 CPU1 ---- ---- lock(&(&pool->lock)->rlock); lock(&pool->lock/1); lock(&(&pool->lock)->rlock); lock(console_owner); *** DEADLOCK *** 6 locks held by kworker/0:3/4654: #0: ("events"){+.+.}, at: [<00000000072447b0>] process_one_work+0x6ff/0x1580 kernel/workqueue.c:2105 #1: ((&rtc->irqwork)){+.+.}, at: [<000000001552a8ed>] process_one_work+0x735/0x1580 kernel/workqueue.c:2109 #2: (&rtc->ops_lock){+.+.}, at: [<00000000aa5ccd3c>] rtc_timer_do_work+0xc9/0x610 drivers/rtc/interface.c:868 #3: (kernel/workqueue.c:5442){+.-.}, at: [<000000002f94854a>] lockdep_copy_map include/linux/lockdep.h:174 [inline] #3: (kernel/workqueue.c:5442){+.-.}, at: [<000000002f94854a>] call_timer_fn+0xc6/0x6a0 kernel/time/timer.c:1269 #4: (rcu_read_lock_sched){....}, at: [<00000000ab9a6899>] show_workqueue_state+0x0/0x100 kernel/workqueue.c:4390 #5: (&(&pool->lock)->rlock){-.-.}, at: [<00000000d19bc57a>] show_workqueue_state kernel/workqueue.c:4518 [inline] #5: (&(&pool->lock)->rlock){-.-.}, at: [<00000000d19bc57a>] show_workqueue_state.cold+0x22f/0xeb3 kernel/workqueue.c:4491 stack backtrace: CPU: 0 PID: 4654 Comm: kworker/0:3 Not tainted 4.14.134+ #19 Workqueue: events rtc_timer_do_work Call Trace: __dump_stack lib/dump_stack.c:17 [inline] dump_stack+0xca/0x134 lib/dump_stack.c:53 print_circular_bug.isra.0.cold+0x2dc/0x425 kernel/locking/lockdep.c:1258 workqueue events_unbound: flags=0x2 26784 2542 2 0x80000000 pwq 4: cpus=0-1 flags=0x4 nice=0 active=4/512 in-flight: 2546:fsnotify_connector_destroy_workfn fsnotify_connector_destroy_workfn, 2542:fsnotify_mark_destroy_workfn Workqueue: events_unbound fsnotify_mark_destroy_workfn fsnotify_mark_destroy_workfn BAR(3696) workqueue events_power_efficient: flags=0x80 pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=2/256 pending: process_srcu, neigh_periodic_work workqueue mm_percpu_wq: flags=0x8 pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 pending: Call Trace: vmstat_update pool 0: cpus=0 node=0 flags=0x0 nice=0 hung=258s workers=3 idle: 22829 29469 pool 4: cpus=0-1 flags=0x4 nice=0 hung=168s workers=5 idle: 2548 21617 2544 schedule+0x92/0x1c0 kernel/sched/core.c:3498 schedule_timeout+0x752/0xe90 kernel/time/timer.c:1721 do_wait_for_common kernel/sched/completion.c:91 [inline] __wait_for_common kernel/sched/completion.c:112 [inline] wait_for_common+0x29c/0x470 kernel/sched/completion.c:123 __synchronize_srcu+0x12a/0x210 kernel/rcu/srcutree.c:898 fsnotify_mark_destroy_workfn+0xfd/0x310 fs/notify/mark.c:757 process_one_work+0x7f1/0x1580 kernel/workqueue.c:2134 worker_thread+0xdd/0xdf0 kernel/workqueue.c:2271 kthread+0x31f/0x430 kernel/kthread.c:232 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:404 INFO: task kworker/u4:75:2546 blocked for more than 140 seconds. Not tainted 4.14.134+ #19 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. kworker/u4:75 D26784 2546 2 0x80000000 Workqueue: events_unbound fsnotify_connector_destroy_workfn Call Trace: schedule+0x92/0x1c0 kernel/sched/core.c:3498 schedule_timeout+0x752/0xe90 kernel/time/timer.c:1721 do_wait_for_common kernel/sched/completion.c:91 [inline] __wait_for_common kernel/sched/completion.c:112 [inline] wait_for_common+0x29c/0x470 kernel/sched/completion.c:123 __synchronize_srcu+0x12a/0x210 kernel/rcu/srcutree.c:898 fsnotify_connector_destroy_workfn+0x49/0xa0 fs/notify/mark.c:156 process_one_work+0x7f1/0x1580 kernel/workqueue.c:2134 worker_thread+0xdd/0xdf0 kernel/workqueue.c:2271 kthread+0x31f/0x430 kernel/kthread.c:232 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:404 INFO: task syz-executor.2:3696 blocked for more than 140 seconds. Not tainted 4.14.134+ #19 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.2 D28808 3696 1551 0x00000004 Call Trace: schedule+0x92/0x1c0 kernel/sched/core.c:3498 schedule_timeout+0x752/0xe90 kernel/time/timer.c:1721 do_wait_for_common kernel/sched/completion.c:91 [inline] __wait_for_common kernel/sched/completion.c:112 [inline] wait_for_common+0x29c/0x470 kernel/sched/completion.c:123 flush_work+0x3e2/0x720 kernel/workqueue.c:2908 fsnotify_destroy_group+0x131/0x2f0 fs/notify/group.c:85 inotify_release+0x33/0x40 fs/notify/inotify/inotify_user.c:280 __fput+0x25e/0x710 fs/file_table.c:210 task_work_run+0x125/0x1a0 kernel/task_work.c:113 tracehook_notify_resume include/linux/tracehook.h:191 [inline] exit_to_usermode_loop+0x13b/0x160 arch/x86/entry/common.c:164 prepare_exit_to_usermode arch/x86/entry/common.c:199 [inline] syscall_return_slowpath arch/x86/entry/common.c:270 [inline] do_syscall_64+0x3a3/0x520 arch/x86/entry/common.c:297 INFO: lockdep is turned off. NMI backtrace for cpu 1 CPU: 1 PID: 23 Comm: khungtaskd Not tainted 4.14.134+ #19 Call Trace: __dump_stack lib/dump_stack.c:17 [inline] dump_stack+0xca/0x134 lib/dump_stack.c:53 nmi_cpu_backtrace.cold+0x47/0x86 lib/nmi_backtrace.c:101 Sending NMI from CPU 1 to CPUs 0: NMI backtrace for cpu 0 CPU: 0 PID: 1630 Comm: rs:main Q:Reg Not tainted 4.14.134+ #19 task: 000000004f758be0 task.stack: 00000000fcea81d0 RIP: 0010:__read_once_size include/linux/compiler.h:183 [inline] RIP: 0010:__sanitizer_cov_trace_pc+0x1d/0x60 kernel/kcov.c:67 RSP: 0018:ffff8881d008f768 EFLAGS: 00000246 RAX: ffff8881d0ba1780 RBX: 0000000000000000 RCX: 1ffffffff0d0286c RDX: 0000000000000000 RSI: 0000000000000800 RDI: ffff8881d1db6b38 RBP: ffff8881c858fd00 R08: ffffffff86bfc4e2 R09: 0000000000000000 R10: ffffed10390b1fab R11: ffff8881c858fd5f R12: ffff8881d2c18aa8 R13: ffff8881c858fd00 R14: ffff8881c858fd30 R15: 0000000000000000 FS: 00007fb712021700(0000) GS:ffff8881d7600000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00007fa75e6b4834 CR3: 00000001d1d5a002 CR4: 00000000001606b0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600 Call Trace: generic_make_request_checks+0x181/0x1010 block/blk-core.c:2067 generic_make_request+0x7e/0x880 block/blk-core.c:2183 submit_bio+0xa7/0x390 block/blk-core.c:2301 submit_bio_wait+0xff/0x170 block/bio.c:1012 blkdev_issue_flush+0x218/0x320 block/blk-flush.c:531 ext4_sync_file+0xb2f/0x1250 fs/ext4/fsync.c:157 vfs_fsync_range+0x106/0x260 fs/sync.c:196 generic_write_sync include/linux/fs.h:2697 [inline] ext4_file_write_iter+0x83c/0xd60 fs/ext4/file.c:275 call_write_iter include/linux/fs.h:1788 [inline] new_sync_write fs/read_write.c:471 [inline] __vfs_write+0x401/0x5a0 fs/read_write.c:484 vfs_write+0x17f/0x4d0 fs/read_write.c:546 SYSC_write fs/read_write.c:594 [inline] SyS_write+0x102/0x250 fs/read_write.c:586 do_syscall_64+0x19b/0x520 arch/x86/entry/common.c:292 Code: d6 8a 71 03 00 00 00 00 e9 90 ed ff ff 90 65 48 8b 04 25 c0 de 01 00 48 85 c0 74 1a 65 8b 15 cb e1 b0 7b 81 e2 00 01 1f 00 75 0b <8b> 90 a8 11 00 00 83 fa 01 74 01 c3 48 c7 c2 00 00 00 81 48 81