[....] Starting enhanced syslogd: rsyslogd[ 17.298945] audit: type=1400 audit(1520946550.487:5): avc: denied { syslog } for pid=4080 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: [ 21.929739] audit: type=1400 audit(1520946555.118:6): avc: denied { map } for pid=4219 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.18' (ECDSA) to the list of known hosts. [ 377.793498] audit: type=1400 audit(1520946910.982:7): avc: denied { map } for pid=4236 comm="syz-execprog" path="/root/syz-execprog" dev="sda1" ino=16479 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1 2018/03/13 13:15:11 parsed 1 programs 2018/03/13 13:15:11 executed programs: 0 [ 378.040413] audit: type=1400 audit(1520946911.229:8): avc: denied { map } for pid=4236 comm="syz-execprog" path="/root/syzkaller-shm615315308" dev="sda1" ino=16482 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:file_t:s0 tclass=file permissive=1 [ 378.052158] IPVS: ftp: loaded support on port[0] = 21 [ 378.374723] IPv6: ADDRCONF(NETDEV_UP): bridge0: link is not ready [ 378.799156] IPv6: ADDRCONF(NETDEV_UP): bond0: link is not ready [ 378.805297] 8021q: adding VLAN 0 to HW filter on device bond0 [ 378.849249] IPv6: ADDRCONF(NETDEV_UP): veth0: link is not ready [ 378.893791] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 378.909507] ------------[ cut here ]------------ [ 378.915474] ODEBUG: free active (active state 0) object type: work_struct hint: process_one_req+0x0/0x6c0 [ 378.925261] WARNING: CPU: 0 PID: 21 at lib/debugobjects.c:291 debug_print_object+0x166/0x220 [ 378.933808] Kernel panic - not syncing: panic_on_warn set ... [ 378.933808] [ 378.941156] CPU: 0 PID: 21 Comm: kworker/u4:1 Not tainted 4.16.0-rc5+ #262 [ 378.948139] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 378.957470] Workqueue: ib_addr process_one_req [ 378.962298] Call Trace: [ 378.964859] dump_stack+0x194/0x24d [ 378.968469] ? arch_local_irq_restore+0x53/0x53 [ 378.973110] ? vsnprintf+0x1ed/0x1900 [ 378.976894] panic+0x1e4/0x41c [ 378.980070] ? refcount_error_report+0x214/0x214 [ 378.984796] ? show_regs_print_info+0x18/0x18 [ 378.989276] ? __warn+0x1c1/0x200 [ 378.992714] ? debug_print_object+0x166/0x220 [ 378.997176] __warn+0x1dc/0x200 [ 379.000426] ? debug_print_object+0x166/0x220 [ 379.004891] report_bug+0x1f4/0x2b0 [ 379.008558] fixup_bug.part.11+0x37/0x80 [ 379.012937] do_error_trap+0x2d7/0x3e0 [ 379.016796] ? vprintk_default+0x28/0x30 [ 379.020846] ? math_error+0x400/0x400 [ 379.024620] ? printk+0xaa/0xca [ 379.027869] ? show_regs_print_info+0x18/0x18 [ 379.032424] ? __usermodehelper_disable+0x2f0/0x2f0 [ 379.037425] ? trace_hardirqs_off_thunk+0x1a/0x1c [ 379.042241] do_invalid_op+0x1b/0x20 [ 379.045925] invalid_op+0x1b/0x40 [ 379.049350] RIP: 0010:debug_print_object+0x166/0x220 [ 379.054419] RSP: 0018:ffff8801d9447210 EFLAGS: 00010086 [ 379.059752] RAX: dffffc0000000008 RBX: 0000000000000003 RCX: ffffffff815acd3e [ 379.067092] RDX: 0000000000000000 RSI: 1ffff1003b288df2 RDI: 1ffff1003b288dc7 [ 379.074354] RBP: ffff8801d9447250 R08: 0000000000000000 R09: 1ffff1003b288d99 [ 379.081603] R10: ffffed003b288e71 R11: ffffffff86f39b78 R12: 0000000000000001 [ 379.088845] R13: ffffffff86f15440 R14: ffffffff86408680 R15: ffffffff8147c020 [ 379.096103] ? __usermodehelper_disable+0x2f0/0x2f0 [ 379.101100] ? vprintk_func+0x5e/0xc0 [ 379.104882] debug_check_no_obj_freed+0x662/0xf1f [ 379.109704] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 379.114882] ? free_obj_work+0x690/0x690 [ 379.118915] ? trace_hardirqs_on+0xd/0x10 [ 379.123038] ? cma_deref_id+0x2c/0x30 [ 379.126810] ? __lock_is_held+0xb6/0x140 [ 379.130861] ? debug_check_no_locks_freed+0x264/0x3c0 [ 379.136024] ? cma_work_handler+0x1d0/0x1d0 [ 379.140318] kfree+0xc7/0x260 [ 379.143395] process_one_req+0x2e7/0x6c0 [ 379.147428] ? addr_resolve+0xbc0/0xbc0 [ 379.151373] ? __lock_is_held+0xb6/0x140 [ 379.155411] process_one_work+0xc47/0x1bb0 [ 379.159615] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 379.164775] ? trace_hardirqs_on+0xd/0x10 [ 379.169157] ? pwq_dec_nr_in_flight+0x450/0x450 [ 379.173804] ? __schedule+0x903/0x1ec0 [ 379.177668] ? trace_hardirqs_off+0x10/0x10 [ 379.181959] ? lock_downgrade+0x980/0x980 [ 379.186082] ? do_wait_intr_irq+0x3e0/0x3e0 [ 379.190382] ? lock_acquire+0x1d5/0x580 [ 379.194326] ? lock_acquire+0x1d5/0x580 [ 379.198269] ? worker_thread+0x4a3/0x1990 [ 379.202389] ? lock_downgrade+0x980/0x980 [ 379.206508] ? lock_release+0xa40/0xa40 [ 379.210452] ? pr_cont_work+0x130/0x130 [ 379.214399] ? do_raw_spin_trylock+0x190/0x190 [ 379.218954] worker_thread+0x223/0x1990 [ 379.222900] ? finish_task_switch+0x1c1/0x7e0 [ 379.227374] ? process_one_work+0x1bb0/0x1bb0 [ 379.231840] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 379.236828] ? trace_hardirqs_on+0xd/0x10 [ 379.240946] ? _raw_spin_unlock_irq+0x27/0x70 [ 379.245411] ? finish_task_switch+0x1c1/0x7e0 [ 379.249875] ? finish_task_switch+0x182/0x7e0 [ 379.254340] ? copy_overflow+0x20/0x20 [ 379.258209] ? __schedule+0x903/0x1ec0 [ 379.262071] ? trace_hardirqs_off+0x10/0x10 [ 379.266365] ? find_held_lock+0x35/0x1d0 [ 379.270399] ? find_held_lock+0x35/0x1d0 [ 379.274432] ? complete+0x62/0x80 [ 379.277858] ? __schedule+0x1ec0/0x1ec0 [ 379.281800] ? do_wait_intr_irq+0x3e0/0x3e0 [ 379.286102] ? __lockdep_init_map+0xe4/0x650 [ 379.290480] ? do_raw_spin_trylock+0x190/0x190 [ 379.295033] ? lockdep_init_map+0x9/0x10 [ 379.299076] ? _raw_spin_unlock_irqrestore+0x31/0xc0 [ 379.304150] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 379.309136] ? trace_hardirqs_on+0xd/0x10 [ 379.313256] ? __kthread_parkme+0x176/0x240 [ 379.317547] kthread+0x33c/0x400 [ 379.320893] ? process_one_work+0x1bb0/0x1bb0 [ 379.325377] ? kthread_stop+0x7a0/0x7a0 [ 379.329350] ret_from_fork+0x3a/0x50 [ 379.333057] [ 379.333060] ====================================================== [ 379.333061] WARNING: possible circular locking dependency detected [ 379.333063] 4.16.0-rc5+ #262 Not tainted [ 379.333065] ------------------------------------------------------ [ 379.333066] kworker/u4:1/21 is trying to acquire lock: [ 379.333068] ((console_sem).lock){..-.}, at: [<0000000088a53d46>] down_trylock+0x13/0x70 [ 379.333073] [ 379.333074] but task is already holding lock: [ 379.333075] (&obj_hash[i].lock){-.-.}, at: [<0000000084546e22>] debug_check_no_obj_freed+0x1e9/0xf1f [ 379.333079] [ 379.333081] which lock already depends on the new lock. [ 379.333081] [ 379.333082] [ 379.333084] the existing dependency chain (in reverse order) is: [ 379.333085] [ 379.333085] -> #3 (&obj_hash[i].lock){-.-.}: [ 379.333090] _raw_spin_lock_irqsave+0x96/0xc0 [ 379.333092] __debug_object_init+0x109/0x1040 [ 379.333093] debug_object_init+0x17/0x20 [ 379.333094] hrtimer_init+0x8c/0x410 [ 379.333096] init_dl_task_timer+0x1b/0x50 [ 379.333097] __sched_fork+0x2bb/0xb60 [ 379.333098] init_idle+0x75/0x820 [ 379.333099] sched_init+0xb19/0xc43 [ 379.333101] start_kernel+0x452/0x819 [ 379.333102] x86_64_start_reservations+0x2a/0x2c [ 379.333104] x86_64_start_kernel+0x77/0x7a [ 379.333105] secondary_startup_64+0xa5/0xb0 [ 379.333106] [ 379.333106] -> #2 (&rq->lock){-.-.}: [ 379.333111] _raw_spin_lock+0x2a/0x40 [ 379.333112] task_fork_fair+0x7a/0x690 [ 379.333113] sched_fork+0x450/0xc10 [ 379.333115] copy_process.part.38+0x1758/0x4b60 [ 379.333116] _do_fork+0x1f7/0xf70 [ 379.333117] kernel_thread+0x34/0x40 [ 379.333118] rest_init+0x22/0xf0 [ 379.333119] start_kernel+0x7f1/0x819 [ 379.333121] x86_64_start_reservations+0x2a/0x2c [ 379.333122] x86_64_start_kernel+0x77/0x7a [ 379.333124] secondary_startup_64+0xa5/0xb0 [ 379.333124] [ 379.333125] -> #1 (&p->pi_lock){-.-.}: [ 379.333129] _raw_spin_lock_irqsave+0x96/0xc0 [ 379.333131] try_to_wake_up+0xbc/0x15f0 [ 379.333132] wake_up_process+0x10/0x20 [ 379.333133] __up.isra.0+0x1cc/0x2c0 [ 379.333134] up+0x13b/0x1d0 [ 379.333135] __up_console_sem+0xb2/0x1a0 [ 379.333137] console_unlock+0x5af/0xfb0 [ 379.333138] vprintk_emit+0x5c3/0xb90 [ 379.333139] vprintk_default+0x28/0x30 [ 379.333140] vprintk_func+0x57/0xc0 [ 379.333142] printk+0xaa/0xca [ 379.333143] kauditd_hold_skb+0x163/0x180 [ 379.333144] kauditd_send_queue+0xfa/0x140 [ 379.333146] kauditd_thread+0x660/0x940 [ 379.333147] kthread+0x33c/0x400 [ 379.333148] ret_from_fork+0x3a/0x50 [ 379.333149] [ 379.333149] -> #0 ((console_sem).lock){..-.}: [ 379.333154] lock_acquire+0x1d5/0x580 [ 379.333155] _raw_spin_lock_irqsave+0x96/0xc0 [ 379.333156] down_trylock+0x13/0x70 [ 379.333158] __down_trylock_console_sem+0xa2/0x1e0 [ 379.333159] console_trylock+0x15/0x70 [ 379.333160] vprintk_emit+0x5b5/0xb90 [ 379.333162] vprintk_default+0x28/0x30 [ 379.333163] vprintk_func+0x57/0xc0 [ 379.333164] printk+0xaa/0xca [ 379.333165] __warn_printk+0x90/0xf0 [ 379.333167] debug_print_object+0x166/0x220 [ 379.333168] debug_check_no_obj_freed+0x662/0xf1f [ 379.333169] kfree+0xc7/0x260 [ 379.333171] process_one_req+0x2e7/0x6c0 [ 379.333172] process_one_work+0xc47/0x1bb0 [ 379.333174] worker_thread+0x223/0x1990 [ 379.333175] kthread+0x33c/0x400 [ 379.333176] ret_from_fork+0x3a/0x50 [ 379.333177] [ 379.333178] other info that might help us debug this: [ 379.333179] [ 379.333180] Chain exists of: [ 379.333180] (console_sem).lock --> &rq->lock --> &obj_hash[i].lock [ 379.333186] [ 379.333187] Possible unsafe locking scenario: [ 379.333188] [ 379.333189] CPU0 CPU1 [ 379.333190] ---- ---- [ 379.333191] lock(&obj_hash[i].lock); [ 379.333194] lock(&rq->lock); [ 379.333197] lock(&obj_hash[i].lock); [ 379.333199] lock((console_sem).lock); [ 379.333202] [ 379.333203] *** DEADLOCK *** [ 379.333204] [ 379.333205] 3 locks held by kworker/u4:1/21: [ 379.333205] #0: ((wq_completion)"ib_addr"){+.+.}, at: [<0000000069209d9d>] process_one_work+0xb12/0x1bb0 [ 379.333210] #1: ((work_completion)(&(&req->work)->work)){+.+.}, at: [<00000000e8ead21f>] process_one_work+0xb89/0x1bb0 [ 379.333216] #2: (&obj_hash[i].lock){-.-.}, at: [<0000000084546e22>] debug_check_no_obj_freed+0x1e9/0xf1f [ 379.333220] [ 379.333221] stack backtrace: [ 379.333223] CPU: 0 PID: 21 Comm: kworker/u4:1 Not tainted 4.16.0-rc5+ #262 [ 379.333226] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 379.333227] Workqueue: ib_addr process_one_req [ 379.333229] Call Trace: [ 379.333230] dump_stack+0x194/0x24d [ 379.333232] ? arch_local_irq_restore+0x53/0x53 [ 379.333233] print_circular_bug.isra.38+0x2cd/0x2dc [ 379.333235] ? save_trace+0xe0/0x2b0 [ 379.333236] __lock_acquire+0x30a8/0x3e00 [ 379.333237] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 379.333239] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 379.333240] ? __save_stack_trace+0x6e/0xd0 [ 379.333241] ? noop_count+0x40/0x40 [ 379.333243] ? check_usage+0x22f/0xb60 [ 379.333244] ? __bfs+0x387/0x830 [ 379.333245] ? trace_hardirqs_off+0x10/0x10 [ 379.333250] lock_acquire+0x1d5/0x580 [ 379.333251] ? lock_acquire+0x1d5/0x580 [ 379.333252] ? down_trylock+0x13/0x70 [ 379.333254] ? lock_release+0xa40/0xa40 [ 379.333255] ? vprintk_emit+0x43b/0xb90 [ 379.333256] ? lock_downgrade+0x980/0x980 [ 379.333258] ? kvm_sched_clock_read+0x25/0x40 [ 379.333259] ? sched_clock+0x31/0x40 [ 379.333260] ? sched_clock_cpu+0x1b/0x180 [ 379.333261] ? vprintk_emit+0x5b5/0xb90 [ 379.333263] _raw_spin_lock_irqsave+0x96/0xc0 [ 379.333264] ? down_trylock+0x13/0x70 [ 379.333265] down_trylock+0x13/0x70 [ 379.333266] ? vprintk_emit+0x5b5/0xb90 [ 379.333268] __down_trylock_console_sem+0xa2/0x1e0 [ 379.333269] console_trylock+0x15/0x70 [ 379.333270] vprintk_emit+0x5b5/0xb90 [ 379.333272] ? console_unlock+0xfb0/0xfb0 [ 379.333273] ? __might_sleep+0x95/0x190 [ 379.333274] ? addr_handler+0xa3/0x380 [ 379.333275] ? __mutex_lock+0x16f/0x1a80 [ 379.333277] ? addr_handler+0xa3/0x380 [ 379.333278] ? trace_hardirqs_off+0x10/0x10 [ 379.333279] ? rcu_note_context_switch+0x710/0x710 [ 379.333281] ? mutex_lock_io_nested+0x1900/0x1900 [ 379.333282] ? __usermodehelper_disable+0x2f0/0x2f0 [ 379.333284] vprintk_default+0x28/0x30 [ 379.333285] vprintk_func+0x57/0xc0 [ 379.333286] printk+0xaa/0xca [ 379.333287] ? show_regs_print_info+0x18/0x18 [ 379.333288] ? __warn_printk+0x84/0xf0 [ 379.333290] ? addr_resolve+0xbc0/0xbc0 [ 379.333291] __warn_printk+0x90/0xf0 [ 379.333292] ? test_taint+0x20/0x20 [ 379.333293] ? lock_release+0xa40/0xa40 [ 379.333295] ? print_irqtrace_events+0x270/0x270 [ 379.333296] ? addr_resolve+0xbc0/0xbc0 [ 379.333297] debug_print_object+0x166/0x220 [ 379.333299] debug_check_no_obj_freed+0x662/0xf1f [ 379.333300] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 379.333301] ? free_obj_work+0x690/0x690 [ 379.333303] ? trace_hardirqs_on+0xd/0x10 [ 379.333304] ? cma_deref_id+0x2c/0x30 [ 379.333305] ? __lock_is_held+0xb6/0x140 [ 379.333307] ? debug_check_no_locks_freed+0x264/0x3c0 [ 379.333308] ? cma_work_handler+0x1d0/0x1d0 [ 379.333309] kfree+0xc7/0x260 [ 379.333310] process_one_req+0x2e7/0x6c0 [ 379.333312] ? addr_resolve+0xbc0/0xbc0 [ 379.333313] ? __lock_is_held+0xb6/0x140 [ 379.333314] process_one_work+0xc47/0x1bb0 [ 379.333316] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 379.333317] ? trace_hardirqs_on+0xd/0x10 [ 379.333318] ? pwq_dec_nr_in_flight+0x450/0x450 [ 379.333320] ? __schedule+0x903/0x1ec0 [ 379.333321] ? trace_hardirqs_off+0x10/0x10 [ 379.333322] ? lock_downgrade+0x980/0x980 [ 379.333324] ? do_wait_intr_irq+0x3e0/0x3e0 [ 379.333325] ? lock_acquire+0x1d5/0x580 [ 379.333326] ? lock_acquire+0x1d5/0x580 [ 379.333327] ? worker_thread+0x4a3/0x1990 [ 379.333329] ? lock_downgrade+0x980/0x980 [ 379.333330] ? lock_release+0xa40/0xa40 [ 379.333331] ? pr_cont_work+0x130/0x130 [ 379.333332] ? do_raw_spin_trylock+0x190/0x190 [ 379.333334] worker_thread+0x223/0x1990 [ 379.333335] ? finish_task_switch+0x1c1/0x7e0 [ 379.333336] ? process_one_work+0x1bb0/0x1bb0 [ 379.333338] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 379.333339] ? trace_hardirqs_on+0xd/0x10 [ 379.333341] ? _raw_spin_unlock_irq+0x27/0x70 [ 379.333342] ? finish_task_switch+0x1c1/0x7e0 [ 379.333343] ? finish_task_switch+0x182/0x7e0 [ 379.333345] ? copy_overflow+0x20/0x20 [ 379.333346] ? __schedule+0x903/0x1ec0 [ 379.333347] ? trace_hardirqs_off+0x10/0x10 [ 379.333349] ? find_held_lock+0x35/0x1d0 [ 379.333350] ? find_held_lock+0x35/0x1d0 [ 379.333351] ? complete+0x62/0x80 [ 379.333352] ? __schedule+0x1ec0/0x1ec0 [ 379.333354] ? do_wait_intr_irq+0x3e0/0x3e0 [ 379.333355] ? __lockdep_init_map+0xe4/0x650 [ 379.333357] ? do_raw_spin_trylock+0x190/0x190 [ 379.333358] ? lockdep_init_map+0x9/0x10 [ 379.333359] ? _raw_spin_unlock_irqrestore+0x31/0xc0 [ 379.333361] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 379.333363] ? trace_hardirqs_on+0xd/0x10 [ 379.333364] ? __kthread_parkme+0x176/0x240 [ 379.333365] kthread+0x33c/0x400 [ 379.333367] ? process_one_work+0x1bb0/0x1bb0 [ 379.333368] ? kthread_stop+0x7a0/0x7a0 [ 379.333369] ret_from_fork+0x3a/0x50 [ 379.333787] Dumping ftrace buffer: [ 380.241003] (ftrace buffer empty) [ 380.244683] Kernel Offset: disabled [ 380.248299] Rebooting in 86400 seconds..