[....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [ 42.197548] audit: type=1800 audit(1545932790.549:25): pid=7953 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="cron" dev="sda1" ino=2414 res=0 [ 42.234798] audit: type=1800 audit(1545932790.549:26): pid=7953 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 res=0 [ 42.261549] audit: type=1800 audit(1545932790.549:27): pid=7953 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="restorecond" dev="sda1" ino=2436 res=0 [....] Starting periodic command scheduler: cron[?25l[?1c7[ ok 8[?25h[?0c. [....] Starting OpenBSD Secure Shell server: sshd[?25l[?1c7[ ok 8[?25h[?0c. Debian GNU/Linux 7 syzkaller ttyS0 Warning: Permanently added '10.128.0.117' (ECDSA) to the list of known hosts. executing program syzkaller login: [ 603.690223] hrtimer: interrupt took 45237 ns [ 859.553315] BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck for 255s! [ 859.561683] Showing busy workqueues and worker pools: [ 859.567015] workqueue events: flags=0x0 [ 859.571066] pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=2/256 [ 859.579131] pending: psi_update_work, cache_reap [ 859.584260] [ 859.584265] ====================================================== [ 859.584268] WARNING: possible circular locking dependency detected [ 859.584271] 4.20.0-rc7-next-20181224 #189 Not tainted [ 859.584274] ------------------------------------------------------ [ 859.584277] swapper/0/0 is trying to acquire lock: [ 859.584279] 00000000000c57f9 (console_owner){-.-.}, at: console_unlock+0x575/0x1040 [ 859.584287] [ 859.584289] but task is already holding lock: [ 859.584291] 00000000082da322 (&(&pool->lock)->rlock){-.-.}, at: show_workqueue_state.cold.50+0xad0/0x159a [ 859.584300] [ 859.584302] which lock already depends on the new lock. [ 859.584304] [ 859.584305] [ 859.584308] the existing dependency chain (in reverse order) is: [ 859.584309] [ 859.584310] -> #4 (&(&pool->lock)->rlock){-.-.}: [ 859.584318] _raw_spin_lock+0x2d/0x40 [ 859.584320] __queue_work+0x2ff/0x1440 [ 859.584323] queue_work_on+0x19a/0x1e0 [ 859.584325] put_pwq+0x175/0x1c0 [ 859.584327] put_pwq_unlocked.part.28+0x34/0x70 [ 859.584330] destroy_workqueue+0x868/0x9c0 [ 859.584332] floppy_async_init+0x1fb4/0x210b [ 859.584334] async_run_entry_fn+0x1c4/0x7f0 [ 859.584337] process_one_work+0xc90/0x1c40 [ 859.584339] worker_thread+0x17f/0x1390 [ 859.584341] kthread+0x35a/0x440 [ 859.584343] ret_from_fork+0x3a/0x50 [ 859.584344] [ 859.584345] -> #3 (&pool->lock/1){..-.}: [ 859.584354] _raw_spin_lock+0x2d/0x40 [ 859.584356] __queue_work+0x2ff/0x1440 [ 859.584358] queue_work_on+0x19a/0x1e0 [ 859.584361] tty_schedule_flip+0x14c/0x1d0 [ 859.584363] tty_flip_buffer_push+0x15/0x20 [ 859.584365] pty_write+0x19d/0x1f0 [ 859.584367] n_tty_write+0xc5b/0x11f0 [ 859.584369] tty_write+0x3f1/0x880 [ 859.584372] __vfs_write+0x119/0xab0 [ 859.584374] vfs_write+0x1fc/0x580 [ 859.584376] ksys_write+0x101/0x260 [ 859.584378] __x64_sys_write+0x73/0xb0 [ 859.584380] do_syscall_64+0x1b9/0x820 [ 859.584383] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 859.584384] [ 859.584385] -> #2 (&(&port->lock)->rlock){-.-.}: [ 859.584393] _raw_spin_lock_irqsave+0x99/0xd0 [ 859.584396] tty_port_tty_get+0x20/0x80 [ 859.584398] tty_port_default_wakeup+0x15/0x40 [ 859.584400] tty_port_tty_wakeup+0x5d/0x70 [ 859.584403] uart_write_wakeup+0x44/0x60 [ 859.584405] serial8250_tx_chars+0x4be/0xb60 [ 859.584408] serial8250_handle_irq.part.23+0x1c1/0x2f0 [ 859.584410] serial8250_default_handle_irq+0xc8/0x150 [ 859.584413] serial8250_interrupt+0xef/0x190 [ 859.584415] __handle_irq_event_percpu+0x1e6/0xb00 [ 859.584418] handle_irq_event_percpu+0xa0/0x1d0 [ 859.584420] handle_irq_event+0xa7/0x135 [ 859.584423] handle_edge_irq+0x227/0x880 [ 859.584425] handle_irq+0x252/0x3d8 [ 859.584427] do_IRQ+0x98/0x1c0 [ 859.584429] ret_from_intr+0x0/0x1e [ 859.584431] _raw_spin_unlock_irqrestore+0xaf/0xd0 [ 859.584433] uart_write+0x4b2/0x740 [ 859.584436] n_tty_write+0x6c1/0x11f0 [ 859.584438] tty_write+0x3f1/0x880 [ 859.584440] redirected_tty_write+0xaf/0xc0 [ 859.584442] __vfs_write+0x119/0xab0 [ 859.584444] vfs_write+0x1fc/0x580 [ 859.584446] ksys_write+0x101/0x260 [ 859.584449] __x64_sys_write+0x73/0xb0 [ 859.584451] do_syscall_64+0x1b9/0x820 [ 859.584453] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 859.584455] [ 859.584456] -> #1 (&port_lock_key){-.-.}: [ 859.584464] _raw_spin_lock_irqsave+0x99/0xd0 [ 859.584466] serial8250_console_write+0x25f/0xac0 [ 859.584469] univ8250_console_write+0x5f/0x70 [ 859.584471] console_unlock+0xcda/0x1040 [ 859.584473] vprintk_emit+0x39c/0x990 [ 859.584476] vprintk_default+0x28/0x30 [ 859.584478] vprintk_func+0x7e/0x181 [ 859.584480] printk+0xa7/0xcf [ 859.584482] register_console+0x7a5/0xbb0 [ 859.584485] univ8250_console_init+0x3f/0x4b [ 859.584487] console_init+0x6b4/0x9e7 [ 859.584489] start_kernel+0x5e3/0x8ae [ 859.584492] x86_64_start_reservations+0x29/0x2b [ 859.584494] x86_64_start_kernel+0x76/0x79 [ 859.584496] secondary_startup_64+0xa4/0xb0 [ 859.584498] [ 859.584499] -> #0 (console_owner){-.-.}: [ 859.584506] lock_acquire+0x1ed/0x520 [ 859.584509] console_unlock+0x5e2/0x1040 [ 859.584511] vprintk_emit+0x39c/0x990 [ 859.584513] vprintk_default+0x28/0x30 [ 859.584515] vprintk_func+0x7e/0x181 [ 859.584517] printk+0xa7/0xcf [ 859.584520] show_workqueue_state.cold.50+0xc6c/0x159a [ 859.584522] wq_watchdog_timer_fn+0x6ea/0x810 [ 859.584524] call_timer_fn+0x272/0x920 [ 859.584527] __run_timers+0x7e5/0xc70 [ 859.584529] run_timer_softirq+0x88/0xb0 [ 859.584531] __do_softirq+0x30c/0xb2e [ 859.584533] irq_exit+0x17f/0x1c0 [ 859.584536] smp_apic_timer_interrupt+0x1cb/0x760 [ 859.584538] apic_timer_interrupt+0xf/0x20 [ 859.584540] native_safe_halt+0x6/0x10 [ 859.584542] default_idle+0xbf/0x490 [ 859.584544] arch_cpu_idle+0x10/0x20 [ 859.584547] default_idle_call+0x6d/0x90 [ 859.584549] do_idle+0x3db/0x5b0 [ 859.584551] cpu_startup_entry+0x18/0x20 [ 859.584553] rest_init+0x243/0x372 [ 859.584556] arch_call_rest_init+0xe/0x1b [ 859.584559] start_kernel+0x873/0x8ae [ 859.584562] x86_64_start_reservations+0x29/0x2b [ 859.584564] x86_64_start_kernel+0x76/0x79 [ 859.584566] secondary_startup_64+0xa4/0xb0 [ 859.584567] [ 859.584570] other info that might help us debug this: [ 859.584571] [ 859.584573] Chain exists of: [ 859.584574] console_owner --> &pool->lock/1 --> &(&pool->lock)->rlock [ 859.584585] [ 859.584587] Possible unsafe locking scenario: [ 859.584588] [ 859.584591] CPU0 CPU1 [ 859.584593] ---- ---- [ 859.584594] lock(&(&pool->lock)->rlock); [ 859.584599] lock(&pool->lock/1); [ 859.584606] lock(&(&pool->lock)->rlock); [ 859.584610] lock(console_owner); [ 859.584614] [ 859.584616] *** DEADLOCK *** [ 859.584617] [ 859.584619] 4 locks held by swapper/0/0: [ 859.584620] #0: 00000000991f54b6 ((&wq_watchdog_timer)){+.-.}, at: call_timer_fn+0x1db/0x920 [ 859.584630] #1: 00000000cb7fa016 (rcu_read_lock_sched){....}, at: show_workqueue_state+0x0/0x1d0 [ 859.584639] #2: 00000000082da322 (&(&pool->lock)->rlock){-.-.}, at: show_workqueue_state.cold.50+0xad0/0x159a [ 859.584649] #3: 000000006036b8a8 (console_lock){+.+.}, at: vprintk_emit+0x37d/0x990 [ 859.584658] [ 859.584660] stack backtrace: [ 859.584664] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.20.0-rc7-next-20181224 #189 [ 859.584668] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 859.584670] Call Trace: [ 859.584671] [ 859.584673] dump_stack+0x1d3/0x2c6 [ 859.584676] ? dump_stack_print_info.cold.1+0x20/0x20 [ 859.584678] ? vprintk_func+0x85/0x181 [ 859.584681] print_circular_bug.isra.34.cold.58+0x1bd/0x27d [ 859.584683] ? save_trace+0xe0/0x290 [ 859.584686] __lock_acquire+0x3360/0x4c20 [ 859.584688] ? mark_held_locks+0x130/0x130 [ 859.584690] ? put_dec+0x3b/0xf0 [ 859.584692] ? number+0x972/0xca0 [ 859.584694] ? __sanitizer_cov_trace_cmp4+0x20/0x20 [ 859.584697] ? format_decode+0x1b2/0xaf0 [ 859.584699] ? enable_ptr_key_workfn+0x30/0x30 [ 859.584701] ? mark_held_locks+0x130/0x130 [ 859.584704] ? __sanitizer_cov_trace_const_cmp8+0x18/0x20 [ 859.584706] ? vsnprintf+0x20d/0x1b60 [ 859.584709] ? graph_lock+0x270/0x270 [ 859.584711] ? pointer+0x930/0x930 [ 859.584713] ? __sanitizer_cov_trace_cmp8+0x18/0x20 [ 859.584716] ? __sanitizer_cov_trace_cmp4+0x16/0x20 [ 859.584718] ? find_held_lock+0x36/0x1c0 [ 859.584720] lock_acquire+0x1ed/0x520 [ 859.584723] ? console_unlock+0x575/0x1040 [ 859.584725] ? lock_release+0xa00/0xa00 [ 859.584727] ? kasan_check_read+0x11/0x20 [ 859.584730] ? do_raw_spin_unlock+0xa7/0x330 [ 859.584732] ? do_raw_spin_trylock+0x270/0x270 [ 859.584735] ? trace_hardirqs_on+0x310/0x310 [ 859.584737] console_unlock+0x5e2/0x1040 [ 859.584739] ? console_unlock+0x575/0x1040 [ 859.584741] ? devkmsg_read+0xa50/0xa50 [ 859.584744] ? trace_hardirqs_on+0x310/0x310 [ 859.584746] ? vprintk_emit+0x37d/0x990 [ 859.584748] ? _raw_spin_unlock_irqrestore+0x6d/0xd0 [ 859.584751] ? vprintk_emit+0x37d/0x990 [ 859.584753] ? __down_trylock_console_sem+0x155/0x200 [ 859.584755] vprintk_emit+0x39c/0x990 [ 859.584758] ? wake_up_klogd+0x180/0x180 [ 859.584760] ? task_prio+0x50/0x50 [ 859.584762] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 859.584765] ? check_preemption_disabled+0x48/0x280 [ 859.584767] ? mark_held_locks+0xc7/0x130 [ 859.584770] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 859.584772] vprintk_default+0x28/0x30 [ 859.584774] vprintk_func+0x7e/0x181 [ 859.584776] ? printk+0xa7/0xcf [ 859.584777] printk+0xa7/0xcf [ 859.584780] ? kmsg_dump_rewind_nolock+0xe4/0xe4 [ 859.584783] show_workqueue_state.cold.50+0xc6c/0x159a [ 859.584785] ? print_worker_info+0x540/0x540 [ 859.584787] ? native_apic_msr_eoi_write+0x20/0x20 [ 859.584790] ? arch_irq_work_raise+0x103/0x150 [ 859.584792] ? __sanitizer_cov_trace_cmp8+0x18/0x20 [ 859.584795] ? radix_tree_next_chunk+0x5b9/0xe20 [ 859.584797] ? radix_tree_cpu_dead+0x160/0x160 [ 859.584800] ? vprintk_emit+0x297/0x990 [ 859.584802] ? graph_lock+0x270/0x270 [ 859.584804] ? wake_up_klogd+0x180/0x180 [ 859.584806] ? find_held_lock+0x36/0x1c0 [ 859.584809] ? wq_watchdog_timer_fn+0x5b4/0x810 [ 859.584811] ? lock_downgrade+0x900/0x900 [ 859.584813] ? check_preemption_disabled+0x48/0x280 [ 859.584816] ? kasan_check_read+0x11/0x20 [ 859.584818] ? rcu_dynticks_curr_cpu_in_eqs+0xa2/0x170 [ 859.584821] ? rcu_read_unlock_special+0x370/0x370 [ 859.584823] wq_watchdog_timer_fn+0x6ea/0x810 [ 859.584825] ? show_workqueue_state+0x1d0/0x1d0 [ 859.584828] ? wq_calc_node_cpumask+0x390/0x390 [ 859.584830] ? find_held_lock+0x36/0x1c0 [ 859.584832] ? graph_lock+0x270/0x270 [ 859.584835] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 859.584837] ? check_preemption_disabled+0x48/0x280 [ 859.584840] ? __lock_is_held+0xb5/0x140 [ 859.584842] call_timer_fn+0x272/0x920 [ 859.584844] ? show_workqueue_state+0x1d0/0x1d0 [ 859.584846] ? process_timeout+0x40/0x40 [ 859.584849] ? __run_timers+0x7da/0xc70 [ 859.584851] ? _raw_spin_unlock_irq+0x27/0x80 [ 859.584853] ? _raw_spin_unlock_irq+0x27/0x80 [ 859.584856] ? show_workqueue_state+0x1d0/0x1d0 [ 859.584858] ? lockdep_hardirqs_on+0x19e/0x5c0 [ 859.584860] ? trace_hardirqs_on+0xbd/0x310 [ 859.584863] ? kasan_check_read+0x11/0x20 [ 859.584865] ? __run_timers+0x7da/0xc70 [ 859.584867] ? __bpf_trace_preemptirq_template+0x30/0x30 [ 859.584870] ? show_workqueue_state+0x1d0/0x1d0 [ 859.584878] __run_timers+0x7e5/0xc70 [ 859.584880] ? __bpf_trace_t [ 859.584885] Lost 77 message(s)! [ 860.640159] workqueue events_power_efficient: flags=0x80 [ 860.645587] pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/256 [ 860.651718] pending: neigh_periodic_work [ 860.656190] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 [ 860.662332] pending: gc_worker [ 860.665913] workqueue mm_percpu_wq: flags=0x8 [ 860.670380] pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/256 [ 860.676506] pending: vmstat_update