[....] Starting enhanced syslogd: rsyslogd[ 15.950357] audit: type=1400 audit(1520759715.528:5): avc: denied { syslog } for pid=3933 comm="rsyslogd" capability=34 scontext=system_u:system_r:kernel_t:s0 tcontext=system_u:system_r:kernel_t:s0 tclass=capability2 permissive=1 [?25l[?1c7[ ok 8[?25h[?0c. [....] Starting periodic command scheduler: cron[?25l[?1c7[ ok 8[?25h[?0c. Starting mcstransd: [....] Starting file context maintaining daemon: restorecond[?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: [ 18.736754] audit: type=1400 audit(1520759718.314:6): avc: denied { map } for pid=4071 comm="bash" path="/bin/bash" dev="sda1" ino=1457 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1 Warning: Permanently added '10.128.0.46' (ECDSA) to the list of known hosts. executing program executing program executing program [ 25.467474] audit: type=1400 audit(1520759725.045:7): avc: denied { map } for pid=4086 comm="syzkaller968584" path="/root/syzkaller968584669" dev="sda1" ino=16481 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1 [ 25.495454] ------------[ cut here ]------------ [ 25.500886] ODEBUG: free active (active state 0) object type: work_struct hint: process_one_req+0x0/0x6c0 [ 25.510650] WARNING: CPU: 1 PID: 21 at lib/debugobjects.c:291 debug_print_object+0x166/0x220 [ 25.519197] Kernel panic - not syncing: panic_on_warn set ... [ 25.519197] [ 25.526531] CPU: 1 PID: 21 Comm: kworker/u4:1 Not tainted 4.16.0-rc4+ #349 [ 25.533597] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 25.542929] Workqueue: ib_addr process_one_req [ 25.547482] Call Trace: [ 25.550042] dump_stack+0x194/0x24d [ 25.553638] ? arch_local_irq_restore+0x53/0x53 [ 25.558277] ? vsnprintf+0x1ed/0x1900 [ 25.562048] panic+0x1e4/0x41c [ 25.565208] ? refcount_error_report+0x214/0x214 [ 25.569938] ? show_regs_print_info+0x18/0x18 [ 25.574406] ? __warn+0x1c1/0x200 [ 25.577830] ? debug_print_object+0x166/0x220 [ 25.582294] __warn+0x1dc/0x200 [ 25.585542] ? debug_print_object+0x166/0x220 [ 25.590004] report_bug+0x1f4/0x2b0 [ 25.593603] fixup_bug.part.11+0x37/0x80 [ 25.597633] do_error_trap+0x2d7/0x3e0 [ 25.601488] ? vprintk_default+0x28/0x30 [ 25.605516] ? math_error+0x400/0x400 [ 25.609286] ? printk+0xaa/0xca [ 25.612533] ? show_regs_print_info+0x18/0x18 [ 25.617006] ? __usermodehelper_disable+0x2f0/0x2f0 [ 25.621993] ? trace_hardirqs_off_thunk+0x1a/0x1c [ 25.626813] do_invalid_op+0x1b/0x20 [ 25.630504] invalid_op+0x1b/0x40 [ 25.633927] RIP: 0010:debug_print_object+0x166/0x220 [ 25.638996] RSP: 0018:ffff8801d9447210 EFLAGS: 00010086 [ 25.644326] RAX: dffffc0000000008 RBX: 0000000000000003 RCX: ffffffff815abbee [ 25.651562] RDX: 0000000000000000 RSI: 1ffff1003b288df2 RDI: 1ffff1003b288dc7 [ 25.658851] RBP: ffff8801d9447250 R08: 0000000000000000 R09: 1ffff1003b288d99 [ 25.666088] R10: ffffed003b288e71 R11: ffffffff86f398b8 R12: 0000000000000001 [ 25.673329] R13: ffffffff86f15180 R14: ffffffff86408500 R15: ffffffff8147aed0 [ 25.680572] ? __usermodehelper_disable+0x2f0/0x2f0 [ 25.685561] ? vprintk_func+0x5e/0xc0 [ 25.689336] debug_check_no_obj_freed+0x662/0xf1f [ 25.694147] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.699317] ? free_obj_work+0x690/0x690 [ 25.703349] ? trace_hardirqs_on+0xd/0x10 [ 25.707469] ? cma_deref_id+0x2c/0x30 [ 25.711237] ? __lock_is_held+0xb6/0x140 [ 25.715273] ? debug_check_no_locks_freed+0x264/0x3c0 [ 25.720433] ? cma_work_handler+0x1d0/0x1d0 [ 25.724727] kfree+0xc7/0x260 [ 25.727812] process_one_req+0x2e7/0x6c0 [ 25.731851] ? addr_resolve+0xbc0/0xbc0 [ 25.735796] ? __lock_is_held+0xb6/0x140 [ 25.739841] process_one_work+0xc47/0x1bb0 [ 25.744049] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.749210] ? trace_hardirqs_on+0xd/0x10 [ 25.753335] ? pwq_dec_nr_in_flight+0x450/0x450 [ 25.757993] ? __schedule+0x903/0x1ec0 [ 25.761858] ? trace_hardirqs_off+0x10/0x10 [ 25.766154] ? lock_downgrade+0x980/0x980 [ 25.770274] ? do_wait_intr_irq+0x3e0/0x3e0 [ 25.774570] ? lock_acquire+0x1d5/0x580 [ 25.778510] ? lock_acquire+0x1d5/0x580 [ 25.782452] ? worker_thread+0x4a3/0x1990 [ 25.786567] ? lock_downgrade+0x980/0x980 [ 25.790690] ? lock_release+0xa40/0xa40 [ 25.794634] ? pr_cont_work+0x130/0x130 [ 25.798577] ? do_raw_spin_trylock+0x190/0x190 [ 25.803132] worker_thread+0x223/0x1990 [ 25.807076] ? finish_task_switch+0x1c1/0x7e0 [ 25.811554] ? process_one_work+0x1bb0/0x1bb0 [ 25.816019] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 25.821011] ? trace_hardirqs_on+0xd/0x10 [ 25.825128] ? _raw_spin_unlock_irq+0x27/0x70 [ 25.829589] ? finish_task_switch+0x1c1/0x7e0 [ 25.834049] ? finish_task_switch+0x182/0x7e0 [ 25.838515] ? copy_overflow+0x20/0x20 [ 25.842381] ? __schedule+0x903/0x1ec0 [ 25.846240] ? trace_hardirqs_off+0x10/0x10 [ 25.850531] ? find_held_lock+0x35/0x1d0 [ 25.854562] ? find_held_lock+0x35/0x1d0 [ 25.858592] ? complete+0x62/0x80 [ 25.862017] ? __schedule+0x1ec0/0x1ec0 [ 25.865956] ? do_wait_intr_irq+0x3e0/0x3e0 [ 25.870245] ? __lockdep_init_map+0xe4/0x650 [ 25.874635] ? do_raw_spin_trylock+0x190/0x190 [ 25.879187] ? lockdep_init_map+0x9/0x10 [ 25.883214] ? _raw_spin_unlock_irqrestore+0x31/0xc0 [ 25.888287] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 25.893291] ? trace_hardirqs_on+0xd/0x10 [ 25.897407] ? __kthread_parkme+0x176/0x240 [ 25.901699] kthread+0x33c/0x400 [ 25.905034] ? process_one_work+0x1bb0/0x1bb0 [ 25.909494] ? kthread_stop+0x7a0/0x7a0 [ 25.913447] ret_from_fork+0x3a/0x50 [ 25.917139] [ 25.917141] ====================================================== [ 25.917143] WARNING: possible circular locking dependency detected [ 25.917144] 4.16.0-rc4+ #349 Not tainted [ 25.917146] ------------------------------------------------------ [ 25.917147] kworker/u4:1/21 is trying to acquire lock: [ 25.917148] ((console_sem).lock){..-.}, at: [<000000002d7bbb29>] down_trylock+0x13/0x70 [ 25.917153] [ 25.917154] but task is already holding lock: [ 25.917155] (&obj_hash[i].lock){-.-.}, at: [<000000001f77f3d4>] debug_check_no_obj_freed+0x1e9/0xf1f [ 25.917159] [ 25.917160] which lock already depends on the new lock. [ 25.917161] [ 25.917162] [ 25.917163] the existing dependency chain (in reverse order) is: [ 25.917164] [ 25.917165] -> #3 (&obj_hash[i].lock){-.-.}: [ 25.917169] _raw_spin_lock_irqsave+0x96/0xc0 [ 25.917170] __debug_object_init+0x109/0x1040 [ 25.917172] debug_object_init+0x17/0x20 [ 25.917173] hrtimer_init+0x8c/0x410 [ 25.917174] init_dl_task_timer+0x1b/0x50 [ 25.917175] __sched_fork+0x2bb/0xb60 [ 25.917176] init_idle+0x75/0x820 [ 25.917178] sched_init+0xb19/0xc43 [ 25.917179] start_kernel+0x452/0x819 [ 25.917180] x86_64_start_reservations+0x2a/0x2c [ 25.917181] x86_64_start_kernel+0x77/0x7a [ 25.917183] secondary_startup_64+0xa5/0xb0 [ 25.917183] [ 25.917184] -> #2 (&rq->lock){-.-.}: [ 25.917188] _raw_spin_lock+0x2a/0x40 [ 25.917189] task_fork_fair+0x7a/0x690 [ 25.917190] sched_fork+0x450/0xc10 [ 25.917192] copy_process.part.38+0x1758/0x4b60 [ 25.917193] _do_fork+0x1f7/0xf70 [ 25.917194] kernel_thread+0x34/0x40 [ 25.917195] rest_init+0x22/0xf0 [ 25.917196] start_kernel+0x7f1/0x819 [ 25.917198] x86_64_start_reservations+0x2a/0x2c [ 25.917199] x86_64_start_kernel+0x77/0x7a [ 25.917200] secondary_startup_64+0xa5/0xb0 [ 25.917201] [ 25.917202] -> #1 (&p->pi_lock){-.-.}: [ 25.917206] _raw_spin_lock_irqsave+0x96/0xc0 [ 25.917207] try_to_wake_up+0xbc/0x15f0 [ 25.917208] wake_up_process+0x10/0x20 [ 25.917209] __up.isra.0+0x1cc/0x2c0 [ 25.917210] up+0x13b/0x1d0 [ 25.917212] __up_console_sem+0xb2/0x1a0 [ 25.917213] console_unlock+0x5af/0xfb0 [ 25.917214] vprintk_emit+0x5c3/0xb90 [ 25.917215] vprintk_default+0x28/0x30 [ 25.917216] vprintk_func+0x57/0xc0 [ 25.917217] printk+0xaa/0xca [ 25.917219] kauditd_hold_skb+0x163/0x180 [ 25.917220] kauditd_send_queue+0xfa/0x140 [ 25.917221] kauditd_thread+0x660/0x940 [ 25.917222] kthread+0x33c/0x400 [ 25.917223] ret_from_fork+0x3a/0x50 [ 25.917224] [ 25.917225] -> #0 ((console_sem).lock){..-.}: [ 25.917229] lock_acquire+0x1d5/0x580 [ 25.917230] _raw_spin_lock_irqsave+0x96/0xc0 [ 25.917231] down_trylock+0x13/0x70 [ 25.917233] __down_trylock_console_sem+0xa2/0x1e0 [ 25.917234] console_trylock+0x15/0x70 [ 25.917235] vprintk_emit+0x5b5/0xb90 [ 25.917236] vprintk_default+0x28/0x30 [ 25.917238] vprintk_func+0x57/0xc0 [ 25.917239] printk+0xaa/0xca [ 25.917240] __warn_printk+0x90/0xf0 [ 25.917241] debug_print_object+0x166/0x220 [ 25.917242] debug_check_no_obj_freed+0x662/0xf1f [ 25.917244] kfree+0xc7/0x260 [ 25.917245] process_one_req+0x2e7/0x6c0 [ 25.917246] process_one_work+0xc47/0x1bb0 [ 25.917247] worker_thread+0x223/0x1990 [ 25.917248] kthread+0x33c/0x400 [ 25.917250] ret_from_fork+0x3a/0x50 [ 25.917250] [ 25.917252] other info that might help us debug this: [ 25.917252] [ 25.917253] Chain exists of: [ 25.917254] (console_sem).lock --> &rq->lock --> &obj_hash[i].lock [ 25.917259] [ 25.917260] Possible unsafe locking scenario: [ 25.917261] [ 25.917262] CPU0 CPU1 [ 25.917263] ---- ---- [ 25.917264] lock(&obj_hash[i].lock); [ 25.917267] lock(&rq->lock); [ 25.917270] lock(&obj_hash[i].lock); [ 25.917272] lock((console_sem).lock); [ 25.917274] [ 25.917275] *** DEADLOCK *** [ 25.917276] [ 25.917277] 3 locks held by kworker/u4:1/21: [ 25.917278] #0: ((wq_completion)"ib_addr"){+.+.}, at: [<000000002371a2e7>] process_one_work+0xb12/0x1bb0 [ 25.917283] #1: ((work_completion)(&(&req->work)->work)){+.+.}, at: [<000000009b313a08>] process_one_work+0xb89/0x1bb0 [ 25.917287] #2: (&obj_hash[i].lock){-.-.}, at: [<000000001f77f3d4>] debug_check_no_obj_freed+0x1e9/0xf1f [ 25.917292] [ 25.917293] stack backtrace: [ 25.917295] CPU: 1 PID: 21 Comm: kworker/u4:1 Not tainted 4.16.0-rc4+ #349 [ 25.917297] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 25.917299] Workqueue: ib_addr process_one_req [ 25.917300] Call Trace: [ 25.917301] dump_stack+0x194/0x24d [ 25.917303] ? arch_local_irq_restore+0x53/0x53 [ 25.917304] print_circular_bug.isra.38+0x2cd/0x2dc [ 25.917305] ? save_trace+0xe0/0x2b0 [ 25.917306] __lock_acquire+0x30a8/0x3e00 [ 25.917308] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.917309] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.917311] ? __lock_acquire+0x664/0x3e00 [ 25.917312] ? trace_hardirqs_off+0x10/0x10 [ 25.917313] ? __lock_acquire+0x664/0x3e00 [ 25.917314] ? trace_hardirqs_off+0x10/0x10 [ 25.917315] ? find_held_lock+0x35/0x1d0 [ 25.917317] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.917318] ? trace_hardirqs_off+0x10/0x10 [ 25.917320] ? print_irqtrace_events+0x270/0x270 [ 25.917321] lock_acquire+0x1d5/0x580 [ 25.917322] ? lock_acquire+0x1d5/0x580 [ 25.917323] ? down_trylock+0x13/0x70 [ 25.917324] ? lock_release+0xa40/0xa40 [ 25.917325] ? vprintk_emit+0x43b/0xb90 [ 25.917326] ? lock_downgrade+0x980/0x980 [ 25.917328] ? kvm_sched_clock_read+0x25/0x40 [ 25.917329] ? sched_clock+0x31/0x40 [ 25.917330] ? sched_clock_cpu+0x1b/0x180 [ 25.917331] ? vprintk_emit+0x5b5/0xb90 [ 25.917333] _raw_spin_lock_irqsave+0x96/0xc0 [ 25.917334] ? down_trylock+0x13/0x70 [ 25.917335] down_trylock+0x13/0x70 [ 25.917336] ? vprintk_emit+0x5b5/0xb90 [ 25.917337] __down_trylock_console_sem+0xa2/0x1e0 [ 25.917338] console_trylock+0x15/0x70 [ 25.917340] vprintk_emit+0x5b5/0xb90 [ 25.917341] ? console_unlock+0xfb0/0xfb0 [ 25.917342] ? __might_sleep+0x95/0x190 [ 25.917343] ? addr_handler+0xa3/0x380 [ 25.917344] ? __mutex_lock+0x16f/0x1a80 [ 25.917345] ? addr_handler+0xa3/0x380 [ 25.917347] ? trace_hardirqs_off+0x10/0x10 [ 25.917348] ? rcu_note_context_switch+0x710/0x710 [ 25.917349] ? mutex_lock_io_nested+0x1900/0x1900 [ 25.917351] ? __usermodehelper_disable+0x2f0/0x2f0 [ 25.917352] vprintk_default+0x28/0x30 [ 25.917353] vprintk_func+0x57/0xc0 [ 25.917354] printk+0xaa/0xca [ 25.917355] ? show_regs_print_info+0x18/0x18 [ 25.917356] ? __warn_printk+0x84/0xf0 [ 25.917357] ? addr_resolve+0xbc0/0xbc0 [ 25.917359] __warn_printk+0x90/0xf0 [ 25.917360] ? test_taint+0x20/0x20 [ 25.917361] ? lock_release+0xa40/0xa40 [ 25.917362] ? print_irqtrace_events+0x270/0x270 [ 25.917363] ? addr_resolve+0xbc0/0xbc0 [ 25.917368] debug_print_object+0x166/0x220 [ 25.917369] debug_check_no_obj_freed+0x662/0xf1f [ 25.917371] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.917372] ? free_obj_work+0x690/0x690 [ 25.917373] ? trace_hardirqs_on+0xd/0x10 [ 25.917374] ? cma_deref_id+0x2c/0x30 [ 25.917375] ? __lock_is_held+0xb6/0x140 [ 25.917377] ? debug_check_no_locks_freed+0x264/0x3c0 [ 25.917378] ? cma_work_handler+0x1d0/0x1d0 [ 25.917379] kfree+0xc7/0x260 [ 25.917380] process_one_req+0x2e7/0x6c0 [ 25.917381] ? addr_resolve+0xbc0/0xbc0 [ 25.917383] ? __lock_is_held+0xb6/0x140 [ 25.917384] process_one_work+0xc47/0x1bb0 [ 25.917385] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.917387] ? trace_hardirqs_on+0xd/0x10 [ 25.917388] ? pwq_dec_nr_in_flight+0x450/0x450 [ 25.917389] ? __schedule+0x903/0x1ec0 [ 25.917390] ? trace_hardirqs_off+0x10/0x10 [ 25.917391] ? lock_downgrade+0x980/0x980 [ 25.917393] ? do_wait_intr_irq+0x3e0/0x3e0 [ 25.917394] ? lock_acquire+0x1d5/0x580 [ 25.917395] ? lock_acquire+0x1d5/0x580 [ 25.917396] ? worker_thread+0x4a3/0x1990 [ 25.917397] ? lock_downgrade+0x980/0x980 [ 25.917399] ? lock_release+0xa40/0xa40 [ 25.917400] ? pr_cont_work+0x130/0x130 [ 25.917401] ? do_raw_spin_trylock+0x190/0x190 [ 25.917402] worker_thread+0x223/0x1990 [ 25.917403] ? finish_task_switch+0x1c1/0x7e0 [ 25.917405] ? process_one_work+0x1bb0/0x1bb0 [ 25.917406] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 25.917407] ? trace_hardirqs_on+0xd/0x10 [ 25.917409] ? _raw_spin_unlock_irq+0x27/0x70 [ 25.917410] ? finish_task_switch+0x1c1/0x7e0 [ 25.917411] ? finish_task_switch+0x182/0x7e0 [ 25.917412] ? copy_overflow+0x20/0x20 [ 25.917414] ? __schedule+0x903/0x1ec0 [ 25.917415] ? trace_hardirqs_off+0x10/0x10 [ 25.917416] ? find_held_lock+0x35/0x1d0 [ 25.917417] ? find_held_lock+0x35/0x1d0 [ 25.917418] ? complete+0x62/0x80 [ 25.917420] ? __schedule+0x1ec0/0x1ec0 [ 25.917421] ? do_wait_intr_irq+0x3e0/0x3e0 [ 25.917422] ? __lockdep_init_map+0xe4/0x650 [ 25.917424] ? do_raw_spin_trylock+0x190/0x190 [ 25.917425] ? lockdep_init_map+0x9/0x10 [ 25.917426] ? _raw_spin_unlock_irqrestore+0x31/0xc0 [ 25.917428] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 25.917429] ? trace_hardirqs_on+0xd/0x10 [ 25.917430] ? __kthread_parkme+0x176/0x240 [ 25.917431] kthread+0x33c/0x400 [ 25.917433] ? process_one_work+0x1bb0/0x1bb0 [ 25.917434] ? kthread_stop+0x7a0/0x7a0 [ 25.917435] ret_from_fork+0x3a/0x50 [ 26.985328] Shutting down cpus with NMI [ 27.905383] Dumping ftrace buffer: [ 27.908900] (ftrace buffer empty) [ 27.912579] Kernel Offset: disabled [ 27.916180] Rebooting in 86400 seconds..