[....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [ 41.103391] audit: type=1800 audit(1547887465.858:25): pid=7803 uid=0 auid=4294967295 ses=4294967295 subj=_ op=collect_data cause=failed(directio) comm="startpar" name="cron" dev="sda1" ino=2414 res=0 [ 41.138892] audit: type=1800 audit(1547887465.858:26): pid=7803 uid=0 auid=4294967295 ses=4294967295 subj=_ op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 res=0 [ 41.159849] audit: type=1800 audit(1547887465.868:27): pid=7803 uid=0 auid=4294967295 ses=4294967295 subj=_ 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.239' (ECDSA) to the list of known hosts. syzkaller login: [ 683.732660] hrtimer: interrupt took 39722 ns [ 859.551509] BUG: workqueue lockup - pool cpus=0 node=0 flags=0x0 nice=0 stuck for 175s! [ 859.559987] BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck for 175s! [ 859.568302] BUG: workqueue lockup - pool cpus=0-1 flags=0x4 nice=0 stuck for 171s! [ 859.576130] Showing busy workqueues and worker pools: [ 859.581475] workqueue events: flags=0x0 [ 859.585613] pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/256 [ 859.594281] pending: cache_reap [ 859.597923] [ 859.597930] ====================================================== [ 859.597950] WARNING: possible circular locking dependency detected [ 859.597954] 5.0.0-rc2+ #33 Not tainted [ 859.597960] ------------------------------------------------------ [ 859.597965] syz-executor921/7969 is trying to acquire lock: [ 859.597968] 00000000cdc6d589 (console_owner){-.-.}, at: console_unlock+0x4d3/0x11e0 [ 859.597983] [ 859.597987] but task is already holding lock: [ 859.597990] 000000006690aa45 (&(&pool->lock)->rlock){-.-.}, at: show_workqueue_state.cold+0xac5/0x15a8 [ 859.598005] [ 859.598010] which lock already depends on the new lock. [ 859.598011] [ 859.598014] [ 859.598019] the existing dependency chain (in reverse order) is: [ 859.598021] [ 859.598023] -> #4 (&(&pool->lock)->rlock){-.-.}: [ 859.598052] _raw_spin_lock+0x2f/0x40 [ 859.598056] __queue_work+0x2d9/0x1450 [ 859.598060] queue_work_on+0x192/0x200 [ 859.598063] put_pwq+0x178/0x1d0 [ 859.598067] put_pwq_unlocked.part.0+0x34/0x70 [ 859.598086] destroy_workqueue+0x854/0x9b0 [ 859.598090] floppy_async_init+0x1fcb/0x2122 [ 859.598094] async_run_entry_fn+0x1ab/0x7f0 [ 859.598098] process_one_work+0xd0c/0x1ce0 [ 859.598102] worker_thread+0x143/0x14a0 [ 859.598105] kthread+0x357/0x430 [ 859.598109] ret_from_fork+0x3a/0x50 [ 859.598111] [ 859.598113] -> #3 (&pool->lock/1){..-.}: [ 859.598127] _raw_spin_lock+0x2f/0x40 [ 859.598131] __queue_work+0x2d9/0x1450 [ 859.598135] queue_work_on+0x192/0x200 [ 859.598138] tty_schedule_flip+0x149/0x1e0 [ 859.598142] tty_flip_buffer_push+0x16/0x20 [ 859.598146] pty_write+0x1a6/0x200 [ 859.598149] n_tty_write+0xb9e/0x1220 [ 859.598168] tty_write+0x45b/0x7a0 [ 859.598171] __vfs_write+0x116/0xb40 [ 859.598174] vfs_write+0x20c/0x580 [ 859.598178] ksys_write+0x105/0x260 [ 859.598181] __x64_sys_write+0x73/0xb0 [ 859.598185] do_syscall_64+0x1a3/0x800 [ 859.598189] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 859.598191] [ 859.598193] -> #2 (&(&port->lock)->rlock){-.-.}: [ 859.598206] _raw_spin_lock_irqsave+0x95/0xcd [ 859.598209] tty_port_tty_get+0x22/0x80 [ 859.598213] tty_port_default_wakeup+0x16/0x40 [ 859.598217] tty_port_tty_wakeup+0x5d/0x70 [ 859.598220] uart_write_wakeup+0x46/0x70 [ 859.598224] serial8250_tx_chars+0x4a4/0xb20 [ 859.598228] serial8250_handle_irq.part.0+0x1be/0x2e0 [ 859.598232] serial8250_default_handle_irq+0xc5/0x150 [ 859.598236] serial8250_interrupt+0xfb/0x1a0 [ 859.598240] __handle_irq_event_percpu+0x1c6/0xb10 [ 859.598244] handle_irq_event_percpu+0xa0/0x1d0 [ 859.598247] handle_irq_event+0xa7/0x134 [ 859.598251] handle_edge_irq+0x232/0x8a0 [ 859.598254] handle_irq+0x252/0x3d8 [ 859.598257] do_IRQ+0x99/0x1d0 [ 859.598261] ret_from_intr+0x0/0x1e [ 859.598264] native_safe_halt+0x2/0x10 [ 859.598268] arch_cpu_idle+0x10/0x20 [ 859.598271] default_idle_call+0x36/0x90 [ 859.598274] do_idle+0x386/0x5d0 [ 859.598278] cpu_startup_entry+0x1b/0x20 [ 859.598281] start_secondary+0x435/0x620 [ 859.598285] secondary_startup_64+0xa4/0xb0 [ 859.598287] [ 859.598289] -> #1 (&port_lock_key){-.-.}: [ 859.598302] _raw_spin_lock_irqsave+0x95/0xcd [ 859.598306] serial8250_console_write+0x253/0xab0 [ 859.598309] univ8250_console_write+0x5f/0x70 [ 859.598313] console_unlock+0xcff/0x11e0 [ 859.598316] vprintk_emit+0x370/0x960 [ 859.598320] vprintk_default+0x28/0x30 [ 859.598323] vprintk_func+0x7e/0x189 [ 859.598326] printk+0xba/0xed [ 859.598330] register_console+0x74d/0xb50 [ 859.598333] univ8250_console_init+0x3e/0x4b [ 859.598337] console_init+0x6af/0x9f3 [ 859.598340] start_kernel+0x5dc/0x8b7 [ 859.598344] x86_64_start_reservations+0x29/0x2b [ 859.598348] x86_64_start_kernel+0x77/0x7b [ 859.598351] secondary_startup_64+0xa4/0xb0 [ 859.598353] [ 859.598355] -> #0 (console_owner){-.-.}: [ 859.598368] lock_acquire+0x1db/0x570 [ 859.598371] console_unlock+0x53d/0x11e0 [ 859.598375] vprintk_emit+0x370/0x960 [ 859.598378] vprintk_default+0x28/0x30 [ 859.598381] vprintk_func+0x7e/0x189 [ 859.598384] printk+0xba/0xed [ 859.598388] show_workqueue_state.cold+0xc5f/0x15a8 [ 859.598392] wq_watchdog_timer_fn+0x6bd/0x7e0 [ 859.598395] call_timer_fn+0x254/0x900 [ 859.598399] __run_timers+0x6fc/0xd50 [ 859.598402] run_timer_softirq+0x88/0xb0 [ 859.598405] __do_softirq+0x30b/0xb11 [ 859.598408] irq_exit+0x180/0x1d0 [ 859.598412] smp_apic_timer_interrupt+0x1b7/0x760 [ 859.598415] apic_timer_interrupt+0xf/0x20 [ 859.598418] __kmalloc+0x2b4/0x740 [ 859.598422] iter_file_splice_write+0x267/0xfc0 [ 859.598426] direct_splice_actor+0x126/0x1a0 [ 859.598430] splice_direct_to_actor+0x3be/0x9d0 [ 859.598433] do_splice_direct+0x2c7/0x420 [ 859.598436] do_sendfile+0x61a/0xe60 [ 859.598440] __x64_sys_sendfile64+0x15a/0x240 [ 859.598444] do_syscall_64+0x1a3/0x800 [ 859.598448] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 859.598450] [ 859.598454] other info that might help us debug this: [ 859.598456] [ 859.598458] Chain exists of: [ 859.598460] console_owner --> &pool->lock/1 --> &(&pool->lock)->rlock [ 859.598479] [ 859.598482] Possible unsafe locking scenario: [ 859.598484] [ 859.598488] CPU0 CPU1 [ 859.598491] ---- ---- [ 859.598493] lock(&(&pool->lock)->rlock); [ 859.598502] lock(&pool->lock/1); [ 859.598512] lock(&(&pool->lock)->rlock); [ 859.598519] lock(console_owner); [ 859.598526] [ 859.598529] *** DEADLOCK *** [ 859.598531] [ 859.598534] 5 locks held by syz-executor921/7969: [ 859.598536] #0: 000000000c2ff4aa (sb_writers#3){.+.+}, at: do_sendfile+0xad7/0xe60 [ 859.598568] #1: 00000000b7319400 ((&wq_watchdog_timer)){+.-.}, at: call_timer_fn+0x1b4/0x900 [ 859.598584] #2: 00000000927f62fa (rcu_read_lock_sched){....}, at: show_workqueue_state+0x0/0x180 [ 859.598600] #3: 000000006690aa45 (&(&pool->lock)->rlock){-.-.}, at: show_workqueue_state.cold+0xac5/0x15a8 [ 859.598616] #4: 00000000a12e56e9 (console_lock){+.+.}, at: vprintk_emit+0x351/0x960 [ 859.598631] [ 859.598634] stack backtrace: [ 859.598639] CPU: 0 PID: 7969 Comm: syz-executor921 Not tainted 5.0.0-rc2+ #33 [ 859.598646] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 859.598649] Call Trace: [ 859.598651] [ 859.598655] dump_stack+0x1db/0x2d0 [ 859.598659] ? dump_stack_print_info.cold+0x20/0x20 [ 859.598663] ? print_stack_trace+0x77/0xb0 [ 859.598666] ? vprintk_func+0x86/0x189 [ 859.598670] print_circular_bug.isra.0.cold+0x1cc/0x28f [ 859.598674] __lock_acquire+0x3014/0x4a30 [ 859.598678] ? mark_held_locks+0x100/0x100 [ 859.598696] ? memcpy+0x46/0x50 [ 859.598700] ? add_lock_to_list.isra.0+0x450/0x450 [ 859.598704] ? sprintf+0xc0/0x100 [ 859.598707] ? scnprintf+0x140/0x140 [ 859.598711] ? console_unlock+0x518/0x11e0 [ 859.598715] ? find_held_lock+0x35/0x120 [ 859.598718] lock_acquire+0x1db/0x570 [ 859.598722] ? console_unlock+0x4d3/0x11e0 [ 859.598726] ? lock_release+0xc40/0xc40 [ 859.598730] ? do_raw_spin_trylock+0x270/0x270 [ 859.598733] ? lock_acquire+0x1db/0x570 [ 859.598737] console_unlock+0x53d/0x11e0 [ 859.598741] ? console_unlock+0x4d3/0x11e0 [ 859.598745] ? devkmsg_read+0xbc0/0xbc0 [ 859.598749] ? _raw_spin_unlock_irqrestore+0xa4/0xe0 [ 859.598753] ? vprintk_emit+0x351/0x960 [ 859.598757] ? __down_trylock_console_sem+0x148/0x210 [ 859.598760] vprintk_emit+0x370/0x960 [ 859.598764] ? wake_up_klogd+0x180/0x180 [ 859.598767] ? mark_held_locks+0xb1/0x100 [ 859.598771] ? console_unlock+0x8ac/0x11e0 [ 859.598775] vprintk_default+0x28/0x30 [ 859.598778] vprintk_func+0x7e/0x189 [ 859.598782] ? printk+0xba/0xed [ 859.598785] printk+0xba/0xed [ 859.598789] ? kmsg_dump_rewind_nolock+0xe4/0xe4 [ 859.598793] show_workqueue_state.cold+0xc5f/0x15a8 [ 859.598797] ? print_worker_info+0x540/0x540 [ 859.598801] ? add_lock_to_list.isra.0+0x450/0x450 [ 859.598805] ? wake_up_klogd+0x180/0x180 [ 859.598809] ? __lock_acquire+0x572/0x4a30 [ 859.598828] ? wq_watchdog_timer_fn+0x587/0x7e0 [ 859.598832] ? wq_watchdog_timer_fn+0x587/0x7e0 [ 859.598837] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 859.598841] ? lock_downgrade+0x910/0x910 [ 859.598844] ? kasan_check_read+0x11/0x20 [ 859.598849] ? rcu_dynticks_curr_cpu_in_eqs+0xa2/0x170 [ 859.598854] ? rcu_read_unlock_special+0x380/0x380 [ 859.598858] wq_watchdog_timer_fn+0x6bd/0x7e0 [ 859.598861] ? print_usage_bug+0xd0/0xd0 [ 859.598866] ? show_workqueue_state+0x180/0x180 [ 859.598870] ? add_lock_to_list.isra.0+0x450/0x450 [ 859.598921] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 859.598925] ? check_preemption_disabled+0x48/0x290 [ 859.598929] ? __lock_is_held+0xb6/0x140 [ 859.598933] call_timer_fn+0x254/0x900 [ 859.598937] ? show_workqueue_state+0x180/0x180 [ 859.598941] ? process_timeout+0x40/0x40 [ 859.598945] ? _raw_spin_unlock_irq+0x28/0x90 [ 859.598949] ? _raw_spin_unlock_irq+0x28/0x90 [ 859.598953] ? lockdep_hardirqs_on+0x19b/0x5d0 [ 859.598957] ? trace_hardirqs_on+0xbd/0x310 [ 859.598961] ? kasan_check_read+0x11/0x20 [ 859.598981] ? trace_hardirqs_off_caller+0x300/0x300 [ 859.598985] ? show_workqueue_state+0x180/0x180 [ 859.598989] ? show_workqueue_state+0x180/0x180 [ 859.598993] __run_timers+0x6fc/0xd50 [ 859.598997] ? __bpf_trace_timer_expire_entry+0x30/0x30 [ 859.599001] ? print_usage_bug+0xd0/0xd0 [ 859.599005] ? find_held_lock+0x35/0x120 [ 859.599009] ? clockevents_program_event+0x15f/0x380 [ 859.599013] ? add_lock_to_list.isra.0+0x450/0x450 [ 859.599017] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 859.599022] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 859.599026] ? check_preemption_disabled+0x48/0x290 [ 859.599030] ? __lock_is_held+0xb6/0x140 [ 859.599035] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 859.599039] ? check_preemption_disabled+0x48/0x290 [ 859.599043] run_timer_softirq+0x88/0xb0 [ 859.599047] ? rcu_read_lock_sched_held+0x110/0x130 [ 859.599050] __do_softirq+0x30b/0xb11 [ 859.599055] ? __irqentry_text_end+0x1f96d2/0x1f96d2 [ 859.599058] ? kvm_clock_read+0x18/0x30 [ 859.599062] ? kvm_sched_clock_read+0x9/0x20 [ 859.599066] ? sched_clock+0x2e/0x50 [ 859.599070] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 859.599090] ? __sanitizer_cov_trace_const_cmp8+0x18/0x20 [ 859.599095] ? check_preemption_disabled+0x48/0x290 [ 859.599098] irq_exit+0x180/0x1d0 [ 859.599102] smp_apic_timer_interrupt+0x1b7/0x760 [ 859.599107] ? trace_hardirqs_off_thunk+0x1a/0x1c [ 859.599109] [ 859.599131] Lost 59 message(s)! [ 860.635170] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=5/256 [ 860.641351] pending: defense_work_handler, vmstat_shepherd, cache_reap, psi_update_work, check_corruption [ 860.651567] workqueue events_power_efficient: flags=0x80 [ 860.657180] pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=2/256 [ 860.663456] pending: gc_worker, neigh_periodic_work [ 860.668886] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=3/256 [ 860.675060] pending: neigh_periodic_work, do_cache_clean, check_lifetime [ 860.682354] workqueue mm_percpu_wq: flags=0x8 [ 860.686973] pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/256 [ 860.693132] pending: vmstat_update [ 860.697121] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 [ 860.703281] pending: vmstat_update [ 860.707264] workqueue writeback: flags=0x4e [ 860.711634] pwq 4: cpus=0-1 flags=0x4 nice=0 active=1/256 [ 860.717367] pending: wb_workfn [ 860.721022] workqueue dm_bufio_cache: flags=0x8 [ 860.726293] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 [ 860.732453] pending: work_fn [ 860.736187] workqueue ipv6_addrconf: flags=0x40008 [ 860.741285] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/1 [ 860.747311] pending: addrconf_verify_work