[....] Starting enhanced syslogd: rsyslogd[ 16.111360] audit: type=1400 audit(1520948368.673:5): avc: denied { syslog } for pid=3929 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 file context maintaining daemon: restorecond[?25l[?1c7[ ok 8[?25h[?0c. Starting mcstransd: [....] Starting OpenBSD Secure Shell server: sshd[?25l[?1c7[ ok 8[?25h[?0c. Debian GNU/Linux 7 syzkaller ttyS0 syzkaller login: [ 18.722426] audit: type=1400 audit(1520948371.284:6): avc: denied { map } for pid=4067 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.49' (ECDSA) to the list of known hosts. executing program executing program executing program [ 25.070308] audit: type=1400 audit(1520948377.632:7): avc: denied { map } for pid=4081 comm="syzkaller076954" path="/root/syzkaller076954431" 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.099568] ------------[ cut here ]------------ [ 25.105150] ODEBUG: free active (active state 0) object type: work_struct hint: process_one_req+0x0/0x6c0 [ 25.114914] WARNING: CPU: 0 PID: 42 at lib/debugobjects.c:291 debug_print_object+0x166/0x220 [ 25.123459] Kernel panic - not syncing: panic_on_warn set ... [ 25.123459] [ 25.130793] CPU: 0 PID: 42 Comm: kworker/u4:2 Not tainted 4.16.0-rc5+ #352 [ 25.137983] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 25.147320] Workqueue: ib_addr process_one_req [ 25.151875] Call Trace: [ 25.154437] dump_stack+0x194/0x24d [ 25.158038] ? arch_local_irq_restore+0x53/0x53 [ 25.162704] ? vsnprintf+0x1ed/0x1900 [ 25.166480] panic+0x1e4/0x41c [ 25.169645] ? refcount_error_report+0x214/0x214 [ 25.174374] ? show_regs_print_info+0x18/0x18 [ 25.178845] ? __warn+0x1c1/0x200 [ 25.182273] ? debug_print_object+0x166/0x220 [ 25.186740] __warn+0x1dc/0x200 [ 25.189995] ? debug_print_object+0x166/0x220 [ 25.194478] report_bug+0x1f4/0x2b0 [ 25.198082] fixup_bug.part.11+0x37/0x80 [ 25.202113] do_error_trap+0x2d7/0x3e0 [ 25.205974] ? vprintk_default+0x28/0x30 [ 25.210018] ? math_error+0x400/0x400 [ 25.213790] ? printk+0xaa/0xca [ 25.217042] ? show_regs_print_info+0x18/0x18 [ 25.223166] ? __usermodehelper_disable+0x2f0/0x2f0 [ 25.228159] ? trace_hardirqs_off_thunk+0x1a/0x1c [ 25.232978] do_invalid_op+0x1b/0x20 [ 25.236668] invalid_op+0x1b/0x40 [ 25.240099] RIP: 0010:debug_print_object+0x166/0x220 [ 25.245171] RSP: 0018:ffff8801d9547210 EFLAGS: 00010086 [ 25.250509] RAX: dffffc0000000008 RBX: 0000000000000003 RCX: ffffffff815acd3e [ 25.257751] RDX: 0000000000000000 RSI: 1ffff1003b2a8df2 RDI: 1ffff1003b2a8dc7 [ 25.264999] RBP: ffff8801d9547250 R08: 0000000000000000 R09: 1ffff1003b2a8d99 [ 25.272243] R10: ffffed003b2a8e71 R11: ffffffff86f39b78 R12: 0000000000000001 [ 25.279487] R13: ffffffff86f15440 R14: ffffffff86408680 R15: ffffffff8147c020 [ 25.286733] ? __usermodehelper_disable+0x2f0/0x2f0 [ 25.291727] ? vprintk_func+0x5e/0xc0 [ 25.295511] debug_check_no_obj_freed+0x662/0xf1f [ 25.300327] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.305499] ? free_obj_work+0x690/0x690 [ 25.309538] ? trace_hardirqs_on+0xd/0x10 [ 25.313668] ? cma_deref_id+0x2c/0x30 [ 25.317445] ? __lock_is_held+0xb6/0x140 [ 25.321485] ? debug_check_no_locks_freed+0x264/0x3c0 [ 25.326652] ? cma_work_handler+0x1d0/0x1d0 [ 25.330948] kfree+0xc7/0x260 [ 25.334032] process_one_req+0x2e7/0x6c0 [ 25.338184] ? addr_resolve+0xbc0/0xbc0 [ 25.342139] ? __lock_is_held+0xb6/0x140 [ 25.346180] process_one_work+0xc47/0x1bb0 [ 25.350385] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.355545] ? trace_hardirqs_on+0xd/0x10 [ 25.359666] ? pwq_dec_nr_in_flight+0x450/0x450 [ 25.364316] ? __schedule+0x903/0x1ec0 [ 25.368177] ? __lock_acquire+0x664/0x3e00 [ 25.372382] ? trace_hardirqs_off+0x10/0x10 [ 25.376671] ? trace_hardirqs_off+0x10/0x10 [ 25.380986] ? lock_acquire+0x1d5/0x580 [ 25.384927] ? lock_acquire+0x1d5/0x580 [ 25.388871] ? worker_thread+0x4a3/0x1990 [ 25.392991] ? lock_downgrade+0x980/0x980 [ 25.397107] ? lock_release+0xa40/0xa40 [ 25.401053] ? pr_cont_work+0x130/0x130 [ 25.404995] ? do_raw_spin_trylock+0x190/0x190 [ 25.409553] worker_thread+0x223/0x1990 [ 25.413497] ? finish_task_switch+0x1c1/0x7e0 [ 25.417960] ? lock_downgrade+0x980/0x980 [ 25.422082] ? process_one_work+0x1bb0/0x1bb0 [ 25.426547] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 25.431533] ? trace_hardirqs_on+0xd/0x10 [ 25.435650] ? _raw_spin_unlock_irq+0x27/0x70 [ 25.440114] ? finish_task_switch+0x1c1/0x7e0 [ 25.444576] ? finish_task_switch+0x182/0x7e0 [ 25.449041] ? copy_overflow+0x20/0x20 [ 25.452919] ? __schedule+0x903/0x1ec0 [ 25.456783] ? trace_hardirqs_off+0x10/0x10 [ 25.461081] ? find_held_lock+0x35/0x1d0 [ 25.465117] ? find_held_lock+0x35/0x1d0 [ 25.469151] ? complete+0x62/0x80 [ 25.472577] ? __schedule+0x1ec0/0x1ec0 [ 25.476521] ? do_wait_intr_irq+0x3e0/0x3e0 [ 25.480810] ? __lockdep_init_map+0xe4/0x650 [ 25.485201] ? do_raw_spin_trylock+0x190/0x190 [ 25.489753] ? lockdep_init_map+0x9/0x10 [ 25.493796] ? _raw_spin_unlock_irqrestore+0x31/0xc0 [ 25.498870] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 25.503856] ? trace_hardirqs_on+0xd/0x10 [ 25.507974] ? __kthread_parkme+0x176/0x240 [ 25.512267] kthread+0x33c/0x400 [ 25.515604] ? process_one_work+0x1bb0/0x1bb0 [ 25.520065] ? kthread_stop+0x7a0/0x7a0 [ 25.524009] ret_from_fork+0x3a/0x50 [ 25.527700] [ 25.527702] ====================================================== [ 25.527704] WARNING: possible circular locking dependency detected [ 25.527705] 4.16.0-rc5+ #352 Not tainted [ 25.527707] ------------------------------------------------------ [ 25.527709] kworker/u4:2/42 is trying to acquire lock: [ 25.527710] ((console_sem).lock){..-.}, at: [<00000000177924ad>] down_trylock+0x13/0x70 [ 25.527715] [ 25.527716] but task is already holding lock: [ 25.527717] (&obj_hash[i].lock){-.-.}, at: [<00000000b9c758ba>] debug_check_no_obj_freed+0x1e9/0xf1f [ 25.527721] [ 25.527723] which lock already depends on the new lock. [ 25.527724] [ 25.527724] [ 25.527726] the existing dependency chain (in reverse order) is: [ 25.527727] [ 25.527728] -> #3 (&obj_hash[i].lock){-.-.}: [ 25.527732] _raw_spin_lock_irqsave+0x96/0xc0 [ 25.527734] __debug_object_init+0x109/0x1040 [ 25.527735] debug_object_init+0x17/0x20 [ 25.527736] hrtimer_init+0x8c/0x410 [ 25.527737] init_dl_task_timer+0x1b/0x50 [ 25.527739] __sched_fork+0x2bb/0xb60 [ 25.527740] init_idle+0x75/0x820 [ 25.527741] sched_init+0xb19/0xc43 [ 25.527742] start_kernel+0x452/0x819 [ 25.527744] x86_64_start_reservations+0x2a/0x2c [ 25.527745] x86_64_start_kernel+0x77/0x7a [ 25.527747] secondary_startup_64+0xa5/0xb0 [ 25.527747] [ 25.527748] -> #2 (&rq->lock){-.-.}: [ 25.527752] _raw_spin_lock+0x2a/0x40 [ 25.527753] task_fork_fair+0x7a/0x690 [ 25.527755] sched_fork+0x450/0xc10 [ 25.527756] copy_process.part.38+0x1758/0x4b60 [ 25.527757] _do_fork+0x1f7/0xf70 [ 25.527758] kernel_thread+0x34/0x40 [ 25.527760] rest_init+0x22/0xf0 [ 25.527761] start_kernel+0x7f1/0x819 [ 25.527763] x86_64_start_reservations+0x2a/0x2c [ 25.527764] x86_64_start_kernel+0x77/0x7a [ 25.527765] secondary_startup_64+0xa5/0xb0 [ 25.527766] [ 25.527767] -> #1 (&p->pi_lock){-.-.}: [ 25.527771] _raw_spin_lock_irqsave+0x96/0xc0 [ 25.527772] try_to_wake_up+0xbc/0x15f0 [ 25.527774] wake_up_process+0x10/0x20 [ 25.527775] __up.isra.0+0x1cc/0x2c0 [ 25.527776] up+0x13b/0x1d0 [ 25.527777] __up_console_sem+0xb2/0x1a0 [ 25.527778] console_unlock+0x5af/0xfb0 [ 25.527780] do_con_write+0x106e/0x1f70 [ 25.527781] con_write+0x25/0xb0 [ 25.527782] n_tty_write+0x5ef/0xec0 [ 25.527783] tty_write+0x3fa/0x840 [ 25.527785] __vfs_write+0xef/0x970 [ 25.527786] vfs_write+0x189/0x510 [ 25.527787] SyS_write+0xef/0x220 [ 25.527788] do_syscall_64+0x281/0x940 [ 25.527790] entry_SYSCALL_64_after_hwframe+0x42/0xb7 [ 25.527790] [ 25.527791] -> #0 ((console_sem).lock){..-.}: [ 25.527795] lock_acquire+0x1d5/0x580 [ 25.527797] _raw_spin_lock_irqsave+0x96/0xc0 [ 25.527798] down_trylock+0x13/0x70 [ 25.527799] __down_trylock_console_sem+0xa2/0x1e0 [ 25.527801] console_trylock+0x15/0x70 [ 25.527802] vprintk_emit+0x5b5/0xb90 [ 25.527803] vprintk_default+0x28/0x30 [ 25.527805] vprintk_func+0x57/0xc0 [ 25.527806] printk+0xaa/0xca [ 25.527807] __warn_printk+0x90/0xf0 [ 25.527808] debug_print_object+0x166/0x220 [ 25.527810] debug_check_no_obj_freed+0x662/0xf1f [ 25.527811] kfree+0xc7/0x260 [ 25.527812] process_one_req+0x2e7/0x6c0 [ 25.527814] process_one_work+0xc47/0x1bb0 [ 25.527815] worker_thread+0x223/0x1990 [ 25.527816] kthread+0x33c/0x400 [ 25.527817] ret_from_fork+0x3a/0x50 [ 25.527818] [ 25.527819] other info that might help us debug this: [ 25.527820] [ 25.527821] Chain exists of: [ 25.527822] (console_sem).lock --> &rq->lock --> &obj_hash[i].lock [ 25.527827] [ 25.527829] Possible unsafe locking scenario: [ 25.527829] [ 25.527831] CPU0 CPU1 [ 25.527832] ---- ---- [ 25.527833] lock(&obj_hash[i].lock); [ 25.527836] lock(&rq->lock); [ 25.527838] lock(&obj_hash[i].lock); [ 25.527841] lock((console_sem).lock); [ 25.527843] [ 25.527844] *** DEADLOCK *** [ 25.527845] [ 25.527846] 3 locks held by kworker/u4:2/42: [ 25.527847] #0: ((wq_completion)"ib_addr"){+.+.}, at: [<0000000068b2864d>] process_one_work+0xb12/0x1bb0 [ 25.527852] #1: ((work_completion)(&(&req->work)->work)){+.+.}, at: [<0000000013c86e12>] process_one_work+0xb89/0x1bb0 [ 25.527857] #2: (&obj_hash[i].lock){-.-.}, at: [<00000000b9c758ba>] debug_check_no_obj_freed+0x1e9/0xf1f [ 25.527862] [ 25.527863] stack backtrace: [ 25.527866] CPU: 0 PID: 42 Comm: kworker/u4:2 Not tainted 4.16.0-rc5+ #352 [ 25.527869] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 25.527871] Workqueue: ib_addr process_one_req [ 25.527873] Call Trace: [ 25.527874] dump_stack+0x194/0x24d [ 25.527875] ? arch_local_irq_restore+0x53/0x53 [ 25.527877] print_circular_bug.isra.38+0x2cd/0x2dc [ 25.527878] ? save_trace+0xe0/0x2b0 [ 25.527879] __lock_acquire+0x30a8/0x3e00 [ 25.527881] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.527882] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.527883] ? __lock_acquire+0x664/0x3e00 [ 25.527885] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.527886] ? trace_hardirqs_off+0x10/0x10 [ 25.527888] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.527889] ? __lock_acquire+0x664/0x3e00 [ 25.527891] ? trace_hardirqs_off+0x10/0x10 [ 25.527892] ? find_held_lock+0x35/0x1d0 [ 25.527894] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.527895] ? trace_hardirqs_off+0x10/0x10 [ 25.527896] ? print_irqtrace_events+0x270/0x270 [ 25.527898] lock_acquire+0x1d5/0x580 [ 25.527899] ? lock_acquire+0x1d5/0x580 [ 25.527900] ? down_trylock+0x13/0x70 [ 25.527901] ? lock_release+0xa40/0xa40 [ 25.527902] ? vprintk_emit+0x43b/0xb90 [ 25.527904] ? lock_downgrade+0x980/0x980 [ 25.527905] ? kvm_sched_clock_read+0x25/0x40 [ 25.527906] ? sched_clock+0x31/0x40 [ 25.527908] ? sched_clock_cpu+0x1b/0x180 [ 25.527909] ? vprintk_emit+0x5b5/0xb90 [ 25.527910] _raw_spin_lock_irqsave+0x96/0xc0 [ 25.527911] ? down_trylock+0x13/0x70 [ 25.527912] down_trylock+0x13/0x70 [ 25.527914] ? vprintk_emit+0x5b5/0xb90 [ 25.527915] __down_trylock_console_sem+0xa2/0x1e0 [ 25.527916] console_trylock+0x15/0x70 [ 25.527918] vprintk_emit+0x5b5/0xb90 [ 25.527919] ? console_unlock+0xfb0/0xfb0 [ 25.527920] ? __might_sleep+0x95/0x190 [ 25.527921] ? addr_handler+0xa3/0x380 [ 25.527922] ? __mutex_lock+0x16f/0x1a80 [ 25.527924] ? addr_handler+0xa3/0x380 [ 25.527925] ? trace_hardirqs_off+0x10/0x10 [ 25.527927] ? rcu_note_context_switch+0x710/0x710 [ 25.527928] ? mutex_lock_io_nested+0x1900/0x1900 [ 25.527929] ? __usermodehelper_disable+0x2f0/0x2f0 [ 25.527931] vprintk_default+0x28/0x30 [ 25.527932] vprintk_func+0x57/0xc0 [ 25.527933] printk+0xaa/0xca [ 25.527935] ? show_regs_print_info+0x18/0x18 [ 25.527936] ? __warn_printk+0x84/0xf0 [ 25.527937] ? addr_resolve+0xbc0/0xbc0 [ 25.527938] __warn_printk+0x90/0xf0 [ 25.527939] ? test_taint+0x20/0x20 [ 25.527941] ? lock_release+0xa40/0xa40 [ 25.527942] ? print_irqtrace_events+0x270/0x270 [ 25.527943] ? addr_resolve+0xbc0/0xbc0 [ 25.527945] debug_print_object+0x166/0x220 [ 25.527946] debug_check_no_obj_freed+0x662/0xf1f [ 25.527948] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.527949] ? free_obj_work+0x690/0x690 [ 25.527950] ? trace_hardirqs_on+0xd/0x10 [ 25.527951] ? cma_deref_id+0x2c/0x30 [ 25.527953] ? __lock_is_held+0xb6/0x140 [ 25.527954] ? debug_check_no_locks_freed+0x264/0x3c0 [ 25.527955] ? cma_work_handler+0x1d0/0x1d0 [ 25.527956] kfree+0xc7/0x260 [ 25.527958] process_one_req+0x2e7/0x6c0 [ 25.527959] ? addr_resolve+0xbc0/0xbc0 [ 25.527960] ? __lock_is_held+0xb6/0x140 [ 25.527961] process_one_work+0xc47/0x1bb0 [ 25.527963] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 25.527964] ? trace_hardirqs_on+0xd/0x10 [ 25.527966] ? pwq_dec_nr_in_flight+0x450/0x450 [ 25.527967] ? __schedule+0x903/0x1ec0 [ 25.527968] ? __lock_acquire+0x664/0x3e00 [ 25.527969] ? trace_hardirqs_off+0x10/0x10 [ 25.527971] ? trace_hardirqs_off+0x10/0x10 [ 25.527972] ? lock_acquire+0x1d5/0x580 [ 25.527973] ? lock_acquire+0x1d5/0x580 [ 25.527974] ? worker_thread+0x4a3/0x1990 [ 25.527976] ? lock_downgrade+0x980/0x980 [ 25.527977] ? lock_release+0xa40/0xa40 [ 25.527978] ? pr_cont_work+0x130/0x130 [ 25.527979] ? do_raw_spin_trylock+0x190/0x190 [ 25.527981] worker_thread+0x223/0x1990 [ 25.527982] ? finish_task_switch+0x1c1/0x7e0 [ 25.527983] ? lock_downgrade+0x980/0x980 [ 25.527985] ? process_one_work+0x1bb0/0x1bb0 [ 25.527986] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 25.527987] ? trace_hardirqs_on+0xd/0x10 [ 25.527989] ? _raw_spin_unlock_irq+0x27/0x70 [ 25.527990] ? finish_task_switch+0x1c1/0x7e0 [ 25.527991] ? finish_task_switch+0x182/0x7e0 [ 25.527993] ? copy_overflow+0x20/0x20 [ 25.527994] ? __schedule+0x903/0x1ec0 [ 25.527995] ? trace_hardirqs_off+0x10/0x10 [ 25.527996] ? find_held_lock+0x35/0x1d0 [ 25.527998] ? find_held_lock+0x35/0x1d0 [ 25.527999] ? complete+0x62/0x80 [ 25.528000] ? __schedule+0x1ec0/0x1ec0 [ 25.528001] ? do_wait_intr_irq+0x3e0/0x3e0 [ 25.528003] ? __lockdep_init_map+0xe4/0x650 [ 25.528004] ? do_raw_spin_trylock+0x190/0x190 [ 25.528005] ? lockdep_init_map+0x9/0x10 [ 25.528007] ? _raw_spin_unlock_irqrestore+0x31/0xc0 [ 25.528008] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 25.528010] ? trace_hardirqs_on+0xd/0x10 [ 25.528011] ? __kthread_parkme+0x176/0x240 [ 25.528012] kthread+0x33c/0x400 [ 25.528013] ? process_one_work+0x1bb0/0x1bb0 [ 25.528015] ? kthread_stop+0x7a0/0x7a0 [ 25.528016] ret_from_fork+0x3a/0x50 [ 26.595724] Shutting down cpus with NMI [ 27.532484] Dumping ftrace buffer: [ 27.535996] (ftrace buffer empty) [ 27.539688] Kernel Offset: disabled [ 27.543288] Rebooting in 86400 seconds..