[info] Using makefile-style concurrent boot in runlevel 2. [ 26.395374] audit: type=1800 audit(1542632320.454:21): pid=5829 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="bootlogs" dev="sda1" ino=2419 res=0 [....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [....] 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 syzkaller login: [ 31.747229] sshd (5969) used greatest stack depth: 15632 bytes left Warning: Permanently added '10.128.0.86' (ECDSA) to the list of known hosts. executing program [ 716.218846] BUG: workqueue lockup - pool cpus=0 node=0 flags=0x0 nice=0 stuck for 282s! [ 716.227936] Showing busy workqueues and worker pools: [ 716.233279] workqueue events: flags=0x0 [ 716.237369] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=5/256 [ 716.245618] in-flight: 12:rtc_timer_do_work [ 716.250279] pending: defense_work_handler, vmstat_shepherd, psi_update_work, cache_reap [ 716.258821] [ 716.258824] ====================================================== [ 716.258828] WARNING: possible circular locking dependency detected [ 716.258830] 4.20.0-rc1-next-20181109+ #110 Not tainted [ 716.258834] ------------------------------------------------------ [ 716.258837] kworker/0:1/12 is trying to acquire lock: [ 716.258839] 000000006fddbef3 (console_owner){-.-.}, at: console_unlock+0x570/0x1190 [ 716.258847] [ 716.258849] but task is already holding lock: [ 716.258851] 00000000b72d6307 (&(&pool->lock)->rlock){-.-.}, at: show_workqueue_state.cold.49+0xad0/0x159a [ 716.258860] [ 716.258862] which lock already depends on the new lock. [ 716.258864] [ 716.258865] [ 716.258868] the existing dependency chain (in reverse order) is: [ 716.258870] [ 716.258871] -> #4 (&(&pool->lock)->rlock){-.-.}: [ 716.258879] _raw_spin_lock+0x2d/0x40 [ 716.258882] __queue_work+0x2ff/0x1440 [ 716.258884] queue_work_on+0x19a/0x1e0 [ 716.258886] put_pwq+0x175/0x1c0 [ 716.258888] put_pwq_unlocked.part.27+0x34/0x70 [ 716.258891] destroy_workqueue+0x868/0x9c0 [ 716.258893] floppy_async_init+0x1fe4/0x213b [ 716.258896] async_run_entry_fn+0x1c4/0x7f0 [ 716.258898] process_one_work+0xc8b/0x1c40 [ 716.258901] worker_thread+0x17f/0x1390 [ 716.258903] kthread+0x35a/0x440 [ 716.258905] ret_from_fork+0x3a/0x50 [ 716.258906] [ 716.258908] -> #3 (&pool->lock/1){..-.}: [ 716.258916] _raw_spin_lock+0x2d/0x40 [ 716.258919] __queue_work+0x2ff/0x1440 [ 716.258921] queue_work_on+0x19a/0x1e0 [ 716.258923] tty_schedule_flip+0x14c/0x1d0 [ 716.258926] tty_flip_buffer_push+0x15/0x20 [ 716.258928] pty_write+0x19d/0x1f0 [ 716.258930] n_tty_write+0xc5b/0x11a0 [ 716.258932] tty_write+0x3f1/0x880 [ 716.258935] __vfs_write+0x119/0x9f0 [ 716.258937] vfs_write+0x1fc/0x560 [ 716.258939] ksys_write+0x101/0x260 [ 716.258942] __x64_sys_write+0x73/0xb0 [ 716.258944] do_syscall_64+0x1b9/0x820 [ 716.258947] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 716.258948] [ 716.258950] -> #2 (&(&port->lock)->rlock){-.-.}: [ 716.258969] _raw_spin_lock_irqsave+0x99/0xd0 [ 716.258971] tty_port_tty_get+0x20/0x80 [ 716.258973] tty_port_default_wakeup+0x15/0x40 [ 716.258976] tty_port_tty_wakeup+0x5d/0x70 [ 716.258978] uart_write_wakeup+0x44/0x60 [ 716.258981] serial8250_tx_chars+0x4be/0xb60 [ 716.258984] serial8250_handle_irq.part.23+0x1ee/0x280 [ 716.258987] serial8250_default_handle_irq+0xc8/0x150 [ 716.258989] serial8250_interrupt+0xef/0x190 [ 716.258992] __handle_irq_event_percpu+0x195/0xb20 [ 716.258995] handle_irq_event_percpu+0xa0/0x1d0 [ 716.258998] handle_irq_event+0xa7/0x135 [ 716.259000] handle_edge_irq+0x227/0x880 [ 716.259002] handle_irq+0x252/0x3d8 [ 716.259004] do_IRQ+0x98/0x1c0 [ 716.259006] ret_from_intr+0x0/0x1e [ 716.259009] _raw_spin_unlock_irqrestore+0xaf/0xd0 [ 716.259011] uart_write+0x4b2/0x740 [ 716.259014] n_tty_write+0x6c1/0x11a0 [ 716.259016] tty_write+0x3f1/0x880 [ 716.259018] redirected_tty_write+0xaf/0xc0 [ 716.259021] __vfs_write+0x119/0x9f0 [ 716.259023] vfs_write+0x1fc/0x560 [ 716.259025] ksys_write+0x101/0x260 [ 716.259028] __x64_sys_write+0x73/0xb0 [ 716.259030] do_syscall_64+0x1b9/0x820 [ 716.259033] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 716.259034] [ 716.259035] -> #1 (&port_lock_key){-.-.}: [ 716.259043] _raw_spin_lock_irqsave+0x99/0xd0 [ 716.259046] serial8250_console_write+0x8e8/0xb10 [ 716.259048] univ8250_console_write+0x5f/0x70 [ 716.259051] console_unlock+0xb1a/0x1190 [ 716.259053] vprintk_emit+0x391/0x990 [ 716.259055] vprintk_default+0x28/0x30 [ 716.259058] vprintk_func+0x7e/0x181 [ 716.259060] printk+0xa7/0xcf [ 716.259062] register_console+0x8df/0xcf0 [ 716.259064] univ8250_console_init+0x3f/0x4b [ 716.259067] console_init+0x6a2/0x9cd [ 716.259069] start_kernel+0x70b/0xa2b [ 716.259076] x86_64_start_reservations+0x2e/0x30 [ 716.259078] x86_64_start_kernel+0x76/0x79 [ 716.259081] secondary_startup_64+0xa4/0xb0 [ 716.259082] [ 716.259084] -> #0 (console_owner){-.-.}: [ 716.259091] lock_acquire+0x1ed/0x520 [ 716.259093] console_unlock+0x5dd/0x1190 [ 716.259096] vprintk_emit+0x391/0x990 [ 716.259098] vprintk_default+0x28/0x30 [ 716.259100] vprintk_func+0x7e/0x181 [ 716.259102] printk+0xa7/0xcf [ 716.259105] show_workqueue_state.cold.49+0xc6c/0x159a [ 716.259108] wq_watchdog_timer_fn+0x6ea/0x810 [ 716.259110] call_timer_fn+0x26d/0x920 [ 716.259112] __run_timers+0x7e0/0xc60 [ 716.259115] run_timer_softirq+0x88/0xb0 [ 716.259117] __do_softirq+0x308/0xb7e [ 716.259119] irq_exit+0x17f/0x1c0 [ 716.259122] smp_apic_timer_interrupt+0x1cb/0x760 [ 716.259124] apic_timer_interrupt+0xf/0x20 [ 716.259126] write_comp_data+0x0/0x70 [ 716.259129] rtc_timer_do_work+0x3dd/0x11a0 [ 716.259131] process_one_work+0xc8b/0x1c40 [ 716.259134] worker_thread+0x17f/0x1390 [ 716.259136] kthread+0x35a/0x440 [ 716.259138] ret_from_fork+0x3a/0x50 [ 716.259139] [ 716.259142] other info that might help us debug this: [ 716.259143] [ 716.259145] Chain exists of: [ 716.259146] console_owner --> &pool->lock/1 --> &(&pool->lock)->rlock [ 716.259157] [ 716.259159] Possible unsafe locking scenario: [ 716.259161] [ 716.259163] CPU0 CPU1 [ 716.259166] ---- ---- [ 716.259167] lock(&(&pool->lock)->rlock); [ 716.259172] lock(&pool->lock/1); [ 716.259179] lock(&(&pool->lock)->rlock); [ 716.259183] lock(console_owner); [ 716.259187] [ 716.259189] *** DEADLOCK *** [ 716.259191] [ 716.259193] 7 locks held by kworker/0:1/12: [ 716.259194] #0: 0000000021dff466 ((wq_completion)"events"){+.+.}, at: process_one_work+0xb43/0x1c40 [ 716.259204] #1: 00000000e567a6bc ((work_completion)(&rtc->irqwork)){+.+.}, at: process_one_work+0xb9a/0x1c40 [ 716.259214] #2: 00000000552ee651 (&rtc->ops_lock){+.+.}, at: rtc_timer_do_work+0x131/0x11a0 [ 716.259223] #3: 00000000584300ba ((&wq_watchdog_timer)){+.-.}, at: call_timer_fn+0x1db/0x920 [ 716.259233] #4: 00000000aab3f4f6 (rcu_read_lock_sched){....}, at: show_workqueue_state+0x0/0x1d0 [ 716.259242] #5: 00000000b72d6307 (&(&pool->lock)->rlock){-.-.}, at: show_workqueue_state.cold.49+0xad0/0x159a [ 716.259252] #6: 000000000367773e (console_lock){+.+.}, at: vprintk_emit+0x372/0x990 [ 716.259261] [ 716.259263] stack backtrace: [ 716.259267] CPU: 0 PID: 12 Comm: kworker/0:1 Not tainted 4.20.0-rc1-next-20181109+ #110 [ 716.259271] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 716.259274] Workqueue: events rtc_timer_do_work [ 716.259277] Call Trace: [ 716.259279] [ 716.259281] dump_stack+0x244/0x39d [ 716.259284] ? dump_stack_print_info.cold.1+0x20/0x20 [ 716.259286] ? vprintk_func+0x85/0x181 [ 716.259289] print_circular_bug.isra.35.cold.56+0x1bd/0x27d [ 716.259291] ? save_trace+0xe0/0x290 [ 716.259293] __lock_acquire+0x3399/0x4c20 [ 716.259296] ? mark_held_locks+0x130/0x130 [ 716.259299] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 716.259301] ? put_dec+0x3b/0xf0 [ 716.259304] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 716.259306] ? __sanitizer_cov_trace_cmp1+0x10/0x20 [ 716.259309] ? __sanitizer_cov_trace_const_cmp1+0x1a/0x20 [ 716.259312] ? enable_ptr_key_workfn+0x30/0x30 [ 716.259314] ? put_dec+0xf0/0xf0 [ 716.259317] ? __sanitizer_cov_trace_const_cmp8+0x18/0x20 [ 716.259319] ? vsnprintf+0x20d/0x1b60 [ 716.259321] lock_acquire+0x1ed/0x520 [ 716.259324] ? console_unlock+0x570/0x1190 [ 716.259326] ? lock_release+0xa10/0xa10 [ 716.259328] ? kasan_check_read+0x11/0x20 [ 716.259331] ? do_raw_spin_unlock+0xa7/0x330 [ 716.259333] ? do_raw_spin_trylock+0x270/0x270 [ 716.259336] ? msg_print_text+0x19a/0x1d0 [ 716.259338] console_unlock+0x5dd/0x1190 [ 716.259340] ? console_unlock+0x570/0x1190 [ 716.259343] ? kmsg_dump_get_buffer+0xac0/0xac0 [ 716.259345] ? trace_hardirqs_on+0x310/0x310 [ 716.259348] ? vprintk_emit+0x372/0x990 [ 716.259350] ? _raw_spin_unlock_irqrestore+0x6d/0xd0 [ 716.259353] ? vprintk_emit+0x372/0x990 [ 716.259355] ? __down_trylock_console_sem+0x151/0x1f0 [ 716.259358] vprintk_emit+0x391/0x990 [ 716.259360] ? wake_up_klogd+0x180/0x180 [ 716.259362] ? print_usage_bug+0xc0/0xc0 [ 716.259365] ? find_held_lock+0x36/0x1c0 [ 716.259367] vprintk_default+0x28/0x30 [ 716.259369] vprintk_func+0x7e/0x181 [ 716.259371] ? printk+0xa7/0xcf [ 716.259373] printk+0xa7/0xcf [ 716.259376] ? kmsg_dump_rewind_nolock+0xe4/0xe4 [ 716.259378] show_workqueue_state.cold.49+0xc6c/0x159a [ 716.259381] ? llist_add_batch+0x106/0x170 [ 716.259383] ? check_preemption_disabled+0x48/0x280 [ 716.259386] ? print_worker_info+0x540/0x540 [ 716.259388] ? tick_nohz_tick_stopped+0x1a/0x90 [ 716.259391] ? __sanitizer_cov_trace_cmp8+0x18/0x20 [ 716.259394] ? radix_tree_next_chunk+0x5b9/0xe20 [ 716.259396] ? radix_tree_cpu_dead+0x160/0x160 [ 716.259398] ? vprintk_emit+0x293/0x990 [ 716.259401] ? graph_lock+0x270/0x270 [ 716.259403] ? wake_up_klogd+0x180/0x180 [ 716.259406] ? update_cfs_rq_load_avg.part.68+0x253/0x2e0 [ 716.259408] ? find_held_lock+0x36/0x1c0 [ 716.259411] ? wq_watchdog_timer_fn+0x5b4/0x810 [ 716.259413] ? lock_downgrade+0x900/0x900 [ 716.259416] ? check_preemption_disabled+0x48/0x280 [ 716.259418] ? kasan_check_read+0x11/0x20 [ 716.259421] ? rcu_dynticks_curr_cpu_in_eqs+0xa2/0x170 [ 716.259424] ? rcu_read_unlock_special+0x370/0x370 [ 716.259426] wq_watchdog_timer_fn+0x6ea/0x810 [ 716.259429] ? show_workqueue_state+0x1d0/0x1d0 [ 716.259432] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 716.259434] ? rcu_read_unlock+0x16/0x60 [ 716.259437] ? check_preemption_disabled+0x48/0x280 [ 716.259439] ? graph_lock+0x270/0x270 [ 716.259442] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 716.259445] ? check_preemption_disabled+0x48/0x280 [ 716.259447] ? __lock_is_held+0xb5/0x140 [ 716.259450] call_timer_fn+0x26d/0x920 [ 716.259452] ? show_workqueue_state+0x1d0/0x1d0 [ 716.259454] ? process_timeout+0x40/0x40 [ 716.259457] ? mark_held_locks+0xc7/0x130 [ 716.259459] ? _raw_spin_unlock_irq+0x27/0x80 [ 716.259462] ? _raw_spin_unlock_irq+0x27/0x80 [ 716.259464] ? show_workqueue_state+0x1d0/0x1d0 [ 716.259467] ? lockdep_hardirqs_on+0x296/0x5b0 [ 716.259469] ? trace_hardirqs_on+0xbd/0x310 [ 716.259472] ? kasan_check_read+0x11/0x20 [ 716.259474] ? __run_timers+0x7d5/0xc60 [ 716.259477] ? trace_hardirqs_off_caller+0x300/0x300 [ 716.259478] ? show_workqueu [ 716.259483] Lost 113 message(s)! [ 717.289530] workqueue events_power_efficient: flags=0x80 [ 717.294973] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=2/256 [ 717.301114] pending: neigh_periodic_work, neigh_periodic_work [ 717.307464] workqueue mm_percpu_wq: flags=0x8 [ 717.311961] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 [ 717.318096] pending: vmstat_update [ 717.322052] workqueue ipv6_addrconf: flags=0x40008 [ 717.326969] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/1 [ 717.332934] pending: addrconf_verify_work [ 717.337494] pool 0: cpus=0 node=0 flags=0x0 nice=0 hung=283s workers=2 idle: 2921