[info] Using makefile-style concurrent boot in runlevel 2. [ 24.561467] audit: type=1800 audit(1542636216.805:21): pid=5764 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="bootlogs" dev="sda1" ino=2419 res=0 [ 24.589145] audit: type=1800 audit(1542636216.815:22): pid=5764 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="motd" dev="sda1" ino=2447 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 Warning: Permanently added '10.128.10.55' (ECDSA) to the list of known hosts. executing program syzkaller login: [ 716.161476] BUG: workqueue lockup - pool cpus=0 node=0 flags=0x0 nice=0 stuck for 162s! [ 716.169853] Showing busy workqueues and worker pools: [ 716.175134] workqueue events: flags=0x0 [ 716.179188] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=5/256 [ 716.187347] in-flight: 12:rtc_timer_do_work [ 716.191998] pending: psi_update_work, vmstat_shepherd, cache_reap, check_corruption [ 716.200176] [ 716.200179] ====================================================== [ 716.200182] WARNING: possible circular locking dependency detected [ 716.200185] 4.20.0-rc3+ #340 Not tainted [ 716.200188] ------------------------------------------------------ [ 716.200191] kworker/0:1/12 is trying to acquire lock: [ 716.200193] 00000000734318f6 (console_owner){-.-.}, at: console_unlock+0x570/0x1190 [ 716.200201] [ 716.200203] but task is already holding lock: [ 716.200205] 000000001d2d54f8 (&(&pool->lock)->rlock){-.-.}, at: show_workqueue_state.cold.49+0xad0/0x159a [ 716.200213] [ 716.200216] which lock already depends on the new lock. [ 716.200217] [ 716.200219] [ 716.200222] the existing dependency chain (in reverse order) is: [ 716.200223] [ 716.200224] -> #4 (&(&pool->lock)->rlock){-.-.}: [ 716.200232] _raw_spin_lock+0x2d/0x40 [ 716.200235] __queue_work+0x2ff/0x1440 [ 716.200237] queue_work_on+0x19a/0x1e0 [ 716.200239] put_pwq+0x175/0x1c0 [ 716.200242] put_pwq_unlocked.part.27+0x34/0x70 [ 716.200244] destroy_workqueue+0x868/0x9c0 [ 716.200247] floppy_async_init+0x1fe4/0x213b [ 716.200249] async_run_entry_fn+0x1c4/0x7f0 [ 716.200252] process_one_work+0xc90/0x1c40 [ 716.200254] worker_thread+0x17f/0x1390 [ 716.200256] kthread+0x35a/0x440 [ 716.200258] ret_from_fork+0x3a/0x50 [ 716.200260] [ 716.200261] -> #3 (&pool->lock/1){..-.}: [ 716.200270] _raw_spin_lock+0x2d/0x40 [ 716.200272] __queue_work+0x2ff/0x1440 [ 716.200274] queue_work_on+0x19a/0x1e0 [ 716.200277] tty_schedule_flip+0x14c/0x1d0 [ 716.200279] tty_flip_buffer_push+0x15/0x20 [ 716.200282] pty_write+0x19d/0x1f0 [ 716.200284] n_tty_write+0xc5b/0x11a0 [ 716.200286] tty_write+0x3f1/0x880 [ 716.200288] __vfs_write+0x119/0x9f0 [ 716.200290] vfs_write+0x1fc/0x560 [ 716.200293] ksys_write+0x101/0x260 [ 716.200302] __x64_sys_write+0x73/0xb0 [ 716.200304] do_syscall_64+0x1b9/0x820 [ 716.200307] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 716.200308] [ 716.200310] -> #2 (&(&port->lock)->rlock){-.-.}: [ 716.200318] _raw_spin_lock_irqsave+0x99/0xd0 [ 716.200320] tty_port_tty_get+0x20/0x80 [ 716.200323] tty_port_default_wakeup+0x15/0x40 [ 716.200326] tty_port_tty_wakeup+0x5d/0x70 [ 716.200328] uart_write_wakeup+0x44/0x60 [ 716.200330] serial8250_tx_chars+0x4be/0xb60 [ 716.200333] serial8250_handle_irq.part.23+0x1ee/0x280 [ 716.200336] serial8250_default_handle_irq+0xc8/0x150 [ 716.200339] serial8250_interrupt+0xef/0x190 [ 716.200341] __handle_irq_event_percpu+0x195/0xb30 [ 716.200344] handle_irq_event_percpu+0xa0/0x1d0 [ 716.200346] handle_irq_event+0xa7/0x135 [ 716.200349] handle_edge_irq+0x227/0x880 [ 716.200351] handle_irq+0x252/0x3d8 [ 716.200353] do_IRQ+0x98/0x1c0 [ 716.200355] ret_from_intr+0x0/0x1e [ 716.200358] native_safe_halt+0x6/0x10 [ 716.200360] default_idle+0xbf/0x490 [ 716.200362] arch_cpu_idle+0x10/0x20 [ 716.200365] default_idle_call+0x6d/0x90 [ 716.200367] do_idle+0x49b/0x5c0 [ 716.200369] cpu_startup_entry+0x18/0x20 [ 716.200372] rest_init+0x243/0x372 [ 716.200374] arch_call_rest_init+0xe/0x1b [ 716.200376] start_kernel+0x9f0/0xa2b [ 716.200379] x86_64_start_reservations+0x2e/0x30 [ 716.200381] x86_64_start_kernel+0x76/0x79 [ 716.200384] secondary_startup_64+0xa4/0xb0 [ 716.200385] [ 716.200387] -> #1 (&port_lock_key){-.-.}: [ 716.200395] _raw_spin_lock_irqsave+0x99/0xd0 [ 716.200397] serial8250_console_write+0x8e8/0xb10 [ 716.200400] univ8250_console_write+0x5f/0x70 [ 716.200402] console_unlock+0xb1f/0x1190 [ 716.200405] vprintk_emit+0x391/0x990 [ 716.200407] vprintk_default+0x28/0x30 [ 716.200409] vprintk_func+0x7e/0x181 [ 716.200411] printk+0xa7/0xcf [ 716.200414] register_console+0x8df/0xcf0 [ 716.200416] univ8250_console_init+0x3f/0x4b [ 716.200419] console_init+0x6ac/0x9dc [ 716.200421] start_kernel+0x70b/0xa2b [ 716.200424] x86_64_start_reservations+0x2e/0x30 [ 716.200426] x86_64_start_kernel+0x76/0x79 [ 716.200429] secondary_startup_64+0xa4/0xb0 [ 716.200430] [ 716.200431] -> #0 (console_owner){-.-.}: [ 716.200439] lock_acquire+0x1ed/0x520 [ 716.200441] console_unlock+0x5dd/0x1190 [ 716.200444] vprintk_emit+0x391/0x990 [ 716.200446] vprintk_default+0x28/0x30 [ 716.200448] vprintk_func+0x7e/0x181 [ 716.200450] printk+0xa7/0xcf [ 716.200453] show_workqueue_state.cold.49+0xc6c/0x159a [ 716.200456] wq_watchdog_timer_fn+0x6ea/0x810 [ 716.200458] call_timer_fn+0x272/0x920 [ 716.200460] __run_timers+0x7e5/0xc70 [ 716.200463] run_timer_softirq+0x88/0xb0 [ 716.200465] __do_softirq+0x308/0xb7e [ 716.200467] irq_exit+0x17f/0x1c0 [ 716.200470] smp_apic_timer_interrupt+0x1cb/0x760 [ 716.200472] apic_timer_interrupt+0xf/0x20 [ 716.200475] _raw_spin_unlock_irqrestore+0xaf/0xd0 [ 716.200478] __wake_up_common_lock+0x1d0/0x330 [ 716.200480] __wake_up+0xe/0x10 [ 716.200482] rtc_handle_legacy_irq+0x8f/0xd0 [ 716.200485] rtc_uie_update_irq+0x1f/0x30 [ 716.200487] rtc_timer_do_work+0x287/0x11b0 [ 716.200490] process_one_work+0xc90/0x1c40 [ 716.200492] worker_thread+0x17f/0x1390 [ 716.200494] kthread+0x35a/0x440 [ 716.200497] ret_from_fork+0x3a/0x50 [ 716.200498] [ 716.200501] other info that might help us debug this: [ 716.200502] [ 716.200504] Chain exists of: [ 716.200505] console_owner --> &pool->lock/1 --> &(&pool->lock)->rlock [ 716.200516] [ 716.200518] Possible unsafe locking scenario: [ 716.200520] [ 716.200522] CPU0 CPU1 [ 716.200525] ---- ---- [ 716.200526] lock(&(&pool->lock)->rlock); [ 716.200532] lock(&pool->lock/1); [ 716.200538] lock(&(&pool->lock)->rlock); [ 716.200542] lock(console_owner); [ 716.200547] [ 716.200549] *** DEADLOCK *** [ 716.200550] [ 716.200552] 7 locks held by kworker/0:1/12: [ 716.200554] #0: 0000000095c23de3 ((wq_completion)"events"){+.+.}, at: process_one_work+0xb43/0x1c40 [ 716.200563] #1: 000000008f0f058a ((work_completion)(&rtc->irqwork)){+.+.}, at: process_one_work+0xb9a/0x1c40 [ 716.200573] #2: 00000000290a229a (&rtc->ops_lock){+.+.}, at: rtc_timer_do_work+0x131/0x11b0 [ 716.200583] #3: 00000000b3d173ae ((&wq_watchdog_timer)){+.-.}, at: call_timer_fn+0x1db/0x920 [ 716.200592] #4: 000000005a016925 (rcu_read_lock_sched){....}, at: show_workqueue_state+0x0/0x1d0 [ 716.200602] #5: 000000001d2d54f8 (&(&pool->lock)->rlock){-.-.}, at: show_workqueue_state.cold.49+0xad0/0x159a [ 716.200612] #6: 000000003a93ec57 (console_lock){+.+.}, at: vprintk_emit+0x372/0x990 [ 716.200621] [ 716.200623] stack backtrace: [ 716.200626] CPU: 0 PID: 12 Comm: kworker/0:1 Not tainted 4.20.0-rc3+ #340 [ 716.200631] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 716.200633] Workqueue: events rtc_timer_do_work [ 716.200636] Call Trace: [ 716.200638] [ 716.200640] dump_stack+0x244/0x39d [ 716.200643] ? dump_stack_print_info.cold.1+0x20/0x20 [ 716.200645] ? vprintk_func+0x85/0x181 [ 716.200648] print_circular_bug.isra.35.cold.54+0x1bd/0x27d [ 716.200650] ? save_trace+0xe0/0x290 [ 716.200656] __lock_acquire+0x3399/0x4c20 [ 716.200659] ? mark_held_locks+0x130/0x130 [ 716.200662] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 716.200664] ? put_dec+0x3b/0xf0 [ 716.200667] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 716.200670] ? __sanitizer_cov_trace_const_cmp4+0x10/0x20 [ 716.200672] ? __sanitizer_cov_trace_const_cmp1+0x1a/0x20 [ 716.200675] ? enable_ptr_key_workfn+0x30/0x30 [ 716.200677] ? put_dec+0xf0/0xf0 [ 716.200679] ? zap_class+0x640/0x640 [ 716.200682] ? __sanitizer_cov_trace_const_cmp8+0x18/0x20 [ 716.200684] ? vsnprintf+0x20d/0x1b60 [ 716.200687] lock_acquire+0x1ed/0x520 [ 716.200689] ? console_unlock+0x570/0x1190 [ 716.200691] ? lock_release+0xa00/0xa00 [ 716.200694] ? kasan_check_read+0x11/0x20 [ 716.200696] ? do_raw_spin_unlock+0xa7/0x330 [ 716.200699] ? do_raw_spin_trylock+0x270/0x270 [ 716.200701] ? msg_print_text+0x19a/0x1d0 [ 716.200703] console_unlock+0x5dd/0x1190 [ 716.200706] ? console_unlock+0x570/0x1190 [ 716.200708] ? kmsg_dump_get_buffer+0xac0/0xac0 [ 716.200711] ? trace_hardirqs_on+0x310/0x310 [ 716.200713] ? vprintk_emit+0x372/0x990 [ 716.200716] ? _raw_spin_unlock_irqrestore+0x6d/0xd0 [ 716.200718] ? vprintk_emit+0x372/0x990 [ 716.200721] ? __down_trylock_console_sem+0x151/0x1f0 [ 716.200723] vprintk_emit+0x391/0x990 [ 716.200725] ? wake_up_klogd+0x180/0x180 [ 716.200728] ? print_usage_bug+0xc0/0xc0 [ 716.200730] ? find_held_lock+0x36/0x1c0 [ 716.200732] vprintk_default+0x28/0x30 [ 716.200735] vprintk_func+0x7e/0x181 [ 716.200737] ? printk+0xa7/0xcf [ 716.200739] printk+0xa7/0xcf [ 716.200741] ? kmsg_dump_rewind_nolock+0xe4/0xe4 [ 716.200744] show_workqueue_state.cold.49+0xc6c/0x159a [ 716.200746] ? llist_add_batch+0x106/0x170 [ 716.200749] ? check_preemption_disabled+0x48/0x280 [ 716.200751] ? print_worker_info+0x540/0x540 [ 716.200754] ? tick_nohz_tick_stopped+0x1a/0x90 [ 716.200757] ? __sanitizer_cov_trace_cmp8+0x18/0x20 [ 716.200760] ? radix_tree_next_chunk+0x5b9/0xe20 [ 716.200762] ? radix_tree_cpu_dead+0x160/0x160 [ 716.200764] ? vprintk_emit+0x293/0x990 [ 716.200767] ? zap_class+0x640/0x640 [ 716.200769] ? wake_up_klogd+0x180/0x180 [ 716.200772] ? update_cfs_rq_load_avg.part.68+0x253/0x2e0 [ 716.200774] ? find_held_lock+0x36/0x1c0 [ 716.200777] ? wq_watchdog_timer_fn+0x5b4/0x810 [ 716.200779] ? lock_downgrade+0x900/0x900 [ 716.200782] ? check_preemption_disabled+0x48/0x280 [ 716.200785] ? rcu_read_unlock_special+0x1c0/0x1c0 [ 716.200787] ? kasan_check_read+0x11/0x20 [ 716.200790] ? rcu_dynticks_curr_cpu_in_eqs+0xa2/0x170 [ 716.200792] ? rcu_softirq_qs+0x20/0x20 [ 716.200795] wq_watchdog_timer_fn+0x6ea/0x810 [ 716.200797] ? show_workqueue_state+0x1d0/0x1d0 [ 716.200800] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 716.200802] ? rcu_read_unlock+0x16/0x60 [ 716.200805] ? check_preemption_disabled+0x48/0x280 [ 716.200807] ? zap_class+0x640/0x640 [ 716.200810] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 716.200813] ? check_preemption_disabled+0x48/0x280 [ 716.200815] ? __lock_is_held+0xb5/0x140 [ 716.200817] call_timer_fn+0x272/0x920 [ 716.200820] ? show_workqueue_state+0x1d0/0x1d0 [ 716.200822] ? process_timeout+0x40/0x40 [ 716.200825] ? mark_held_locks+0xc7/0x130 [ 716.200827] ? _raw_spin_unlock_irq+0x27/0x80 [ 716.200830] ? _raw_spin_unlock_irq+0x27/0x80 [ 716.200831] ? show_workq [ 716.200836] Lost 121 message(s)! [ 717.231590] workqueue events_power_efficient: flags=0x80 [ 717.237022] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=2/256 [ 717.243154] pending: do_cache_clean, check_lifetime [ 717.248636] workqueue mm_percpu_wq: flags=0x8 [ 717.253123] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 [ 717.259252] pending: vmstat_update [ 717.263189] workqueue dm_bufio_cache: flags=0x8 [ 717.267839] pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 [ 717.273963] pending: work_fn [ 717.277394] pool 0: cpus=0 node=0 flags=0x0 nice=0 hung=163s workers=2 idle: 5