[....] Starting enhanced syslogd: rsyslogd[ 17.104872] audit: type=1400 audit(1520676492.446:5): avc: denied { syslog } for pid=4110 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 mcstransd: [....] Starting periodic command scheduler: cron[?25l[?1c7[ ok 8[?25h[?0c. [....] 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: [ 23.219843] audit: type=1400 audit(1520676498.561:6): avc: denied { map } for pid=4249 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.10.3' (ECDSA) to the list of known hosts. executing program executing program [ 29.560576] audit: type=1400 audit(1520676504.902:7): avc: denied { map } for pid=4263 comm="syzkaller642663" path="/root/syzkaller642663051" 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 [ 29.589070] ------------[ cut here ]------------ [ 29.594486] ODEBUG: free active (active state 0) object type: work_struct hint: process_one_req+0x0/0x6c0 [ 29.604225] WARNING: CPU: 0 PID: 40 at lib/debugobjects.c:291 debug_print_object+0x166/0x220 [ 29.612766] Kernel panic - not syncing: panic_on_warn set ... [ 29.612766] [ 29.620098] CPU: 0 PID: 40 Comm: kworker/u4:2 Not tainted 4.16.0-rc4+ #348 [ 29.627075] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 29.636399] Workqueue: ib_addr process_one_req [ 29.640948] Call Trace: [ 29.643504] dump_stack+0x194/0x24d [ 29.647102] ? arch_local_irq_restore+0x53/0x53 [ 29.651740] ? vsnprintf+0x1ed/0x1900 [ 29.655512] panic+0x1e4/0x41c [ 29.658672] ? refcount_error_report+0x214/0x214 [ 29.663394] ? show_regs_print_info+0x18/0x18 [ 29.667861] ? __warn+0x1c1/0x200 [ 29.671283] ? debug_print_object+0x166/0x220 [ 29.675746] __warn+0x1dc/0x200 [ 29.679004] ? debug_print_object+0x166/0x220 [ 29.683473] report_bug+0x1f4/0x2b0 [ 29.687072] fixup_bug.part.11+0x37/0x80 [ 29.691100] do_error_trap+0x2d7/0x3e0 [ 29.694953] ? vprintk_default+0x28/0x30 [ 29.698982] ? math_error+0x400/0x400 [ 29.702749] ? printk+0xaa/0xca [ 29.705997] ? show_regs_print_info+0x18/0x18 [ 29.710469] ? __usermodehelper_disable+0x2f0/0x2f0 [ 29.715455] ? trace_hardirqs_off_thunk+0x1a/0x1c [ 29.720282] do_invalid_op+0x1b/0x20 [ 29.723968] invalid_op+0x1b/0x40 [ 29.727405] RIP: 0010:debug_print_object+0x166/0x220 [ 29.732472] RSP: 0018:ffff8801d959f210 EFLAGS: 00010086 [ 29.737804] RAX: dffffc0000000008 RBX: 0000000000000003 RCX: ffffffff815abbee [ 29.745048] RDX: 0000000000000000 RSI: 1ffff1003b2b3df2 RDI: 1ffff1003b2b3dc7 [ 29.752290] RBP: ffff8801d959f250 R08: 0000000000000000 R09: 1ffff1003b2b3d99 [ 29.759537] R10: ffffed003b2b3e71 R11: ffffffff86f398b8 R12: 0000000000000001 [ 29.766775] R13: ffffffff86f15180 R14: ffffffff86408500 R15: ffffffff8147aed0 [ 29.774021] ? __usermodehelper_disable+0x2f0/0x2f0 [ 29.779015] ? vprintk_func+0x5e/0xc0 [ 29.782802] debug_check_no_obj_freed+0x662/0xf1f [ 29.787613] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 29.792779] ? free_obj_work+0x690/0x690 [ 29.796806] ? trace_hardirqs_on+0xd/0x10 [ 29.800927] ? cma_deref_id+0x2c/0x30 [ 29.804697] ? __lock_is_held+0xb6/0x140 [ 29.808728] ? debug_check_no_locks_freed+0x264/0x3c0 [ 29.813886] ? cma_work_handler+0x1d0/0x1d0 [ 29.818184] kfree+0xc7/0x260 [ 29.821260] process_one_req+0x2e7/0x6c0 [ 29.825303] ? addr_resolve+0xc90/0xc90 [ 29.829273] ? __lock_is_held+0xb6/0x140 [ 29.833337] process_one_work+0xc47/0x1bb0 [ 29.837575] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 29.842760] ? trace_hardirqs_on+0xd/0x10 [ 29.846910] ? pwq_dec_nr_in_flight+0x450/0x450 [ 29.851581] ? __schedule+0x903/0x1ec0 [ 29.855467] ? __lock_acquire+0x664/0x3e00 [ 29.859701] ? __lock_is_held+0xb6/0x140 [ 29.863761] ? trace_hardirqs_off+0x10/0x10 [ 29.868087] ? trace_hardirqs_off+0x10/0x10 [ 29.872409] ? lock_acquire+0x1d5/0x580 [ 29.876374] ? lock_acquire+0x1d5/0x580 [ 29.880349] ? worker_thread+0x4a3/0x1990 [ 29.884489] ? lock_downgrade+0x980/0x980 [ 29.888631] ? lock_release+0xa40/0xa40 [ 29.892604] ? pr_cont_work+0x130/0x130 [ 29.896571] ? trace_hardirqs_off+0x10/0x10 [ 29.900899] ? do_raw_spin_trylock+0x190/0x190 [ 29.905474] worker_thread+0x223/0x1990 [ 29.909418] ? finish_task_switch+0x1c1/0x7e0 [ 29.913881] ? lock_downgrade+0x980/0x980 [ 29.918008] ? process_one_work+0x1bb0/0x1bb0 [ 29.922478] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 29.927468] ? trace_hardirqs_on+0xd/0x10 [ 29.931585] ? _raw_spin_unlock_irq+0x27/0x70 [ 29.936048] ? finish_task_switch+0x1c1/0x7e0 [ 29.940522] ? finish_task_switch+0x182/0x7e0 [ 29.944986] ? copy_overflow+0x20/0x20 [ 29.948850] ? __schedule+0x903/0x1ec0 [ 29.952714] ? trace_hardirqs_off+0x10/0x10 [ 29.957013] ? find_held_lock+0x35/0x1d0 [ 29.961052] ? find_held_lock+0x35/0x1d0 [ 29.965088] ? complete+0x62/0x80 [ 29.968517] ? __schedule+0x1ec0/0x1ec0 [ 29.972457] ? do_wait_intr_irq+0x3e0/0x3e0 [ 29.976748] ? __lockdep_init_map+0xe4/0x650 [ 29.981127] ? do_raw_spin_trylock+0x190/0x190 [ 29.985681] ? lockdep_init_map+0x9/0x10 [ 29.989710] ? _raw_spin_unlock_irqrestore+0x31/0xc0 [ 29.994782] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 29.999768] ? trace_hardirqs_on+0xd/0x10 [ 30.003884] ? __kthread_parkme+0x176/0x240 [ 30.008177] kthread+0x33c/0x400 [ 30.011514] ? process_one_work+0x1bb0/0x1bb0 [ 30.015978] ? kthread_stop+0x7a0/0x7a0 [ 30.019921] ret_from_fork+0x3a/0x50 [ 30.023611] [ 30.023613] ====================================================== [ 30.023615] WARNING: possible circular locking dependency detected [ 30.023616] 4.16.0-rc4+ #348 Not tainted [ 30.023618] ------------------------------------------------------ [ 30.023620] kworker/u4:2/40 is trying to acquire lock: [ 30.023620] ((console_sem).lock){..-.}, at: [<000000001da17500>] down_trylock+0x13/0x70 [ 30.023625] [ 30.023626] but task is already holding lock: [ 30.023627] (&obj_hash[i].lock){-.-.}, at: [<000000002515fa87>] debug_check_no_obj_freed+0x1e9/0xf1f [ 30.023631] [ 30.023632] which lock already depends on the new lock. [ 30.023633] [ 30.023634] [ 30.023635] the existing dependency chain (in reverse order) is: [ 30.023636] [ 30.023637] -> #3 (&obj_hash[i].lock){-.-.}: [ 30.023641] _raw_spin_lock_irqsave+0x96/0xc0 [ 30.023642] __debug_object_init+0x109/0x1040 [ 30.023643] debug_object_init+0x17/0x20 [ 30.023645] hrtimer_init+0x8c/0x410 [ 30.023646] init_dl_task_timer+0x1b/0x50 [ 30.023647] __sched_fork+0x2bb/0xb60 [ 30.023648] init_idle+0x75/0x820 [ 30.023649] sched_init+0xb19/0xc43 [ 30.023651] start_kernel+0x452/0x819 [ 30.023652] x86_64_start_reservations+0x2a/0x2c [ 30.023653] x86_64_start_kernel+0x77/0x7a [ 30.023655] secondary_startup_64+0xa5/0xb0 [ 30.023655] [ 30.023656] -> #2 (&rq->lock){-.-.}: [ 30.023660] _raw_spin_lock+0x2a/0x40 [ 30.023661] task_fork_fair+0x7a/0x690 [ 30.023662] sched_fork+0x450/0xc10 [ 30.023664] copy_process.part.38+0x1758/0x4b60 [ 30.023665] _do_fork+0x1f7/0xf70 [ 30.023666] kernel_thread+0x34/0x40 [ 30.023667] rest_init+0x22/0xf0 [ 30.023668] start_kernel+0x7f1/0x819 [ 30.023669] x86_64_start_reservations+0x2a/0x2c [ 30.023671] x86_64_start_kernel+0x77/0x7a [ 30.023672] secondary_startup_64+0xa5/0xb0 [ 30.023673] [ 30.023673] -> #1 (&p->pi_lock){-.-.}: [ 30.023677] _raw_spin_lock_irqsave+0x96/0xc0 [ 30.023679] try_to_wake_up+0xbc/0x15f0 [ 30.023680] wake_up_process+0x10/0x20 [ 30.023681] __up.isra.0+0x1cc/0x2c0 [ 30.023682] up+0x13b/0x1d0 [ 30.023683] __up_console_sem+0xb2/0x1a0 [ 30.023685] console_unlock+0x5af/0xfb0 [ 30.023686] vprintk_emit+0x5c3/0xb90 [ 30.023687] vprintk_default+0x28/0x30 [ 30.023688] vprintk_func+0x57/0xc0 [ 30.023689] printk+0xaa/0xca [ 30.023690] kauditd_hold_skb+0x163/0x180 [ 30.023692] kauditd_send_queue+0xfa/0x140 [ 30.023693] kauditd_thread+0x660/0x940 [ 30.023694] kthread+0x33c/0x400 [ 30.023695] ret_from_fork+0x3a/0x50 [ 30.023696] [ 30.023697] -> #0 ((console_sem).lock){..-.}: [ 30.023701] lock_acquire+0x1d5/0x580 [ 30.023702] _raw_spin_lock_irqsave+0x96/0xc0 [ 30.023703] down_trylock+0x13/0x70 [ 30.023705] __down_trylock_console_sem+0xa2/0x1e0 [ 30.023706] console_trylock+0x15/0x70 [ 30.023707] vprintk_emit+0x5b5/0xb90 [ 30.023708] vprintk_default+0x28/0x30 [ 30.023709] vprintk_func+0x57/0xc0 [ 30.023710] printk+0xaa/0xca [ 30.023712] __warn_printk+0x90/0xf0 [ 30.023713] debug_print_object+0x166/0x220 [ 30.023714] debug_check_no_obj_freed+0x662/0xf1f [ 30.023715] kfree+0xc7/0x260 [ 30.023716] process_one_req+0x2e7/0x6c0 [ 30.023718] process_one_work+0xc47/0x1bb0 [ 30.023719] worker_thread+0x223/0x1990 [ 30.023720] kthread+0x33c/0x400 [ 30.023721] ret_from_fork+0x3a/0x50 [ 30.023722] [ 30.023723] other info that might help us debug this: [ 30.023724] [ 30.023725] Chain exists of: [ 30.023725] (console_sem).lock --> &rq->lock --> &obj_hash[i].lock [ 30.023731] [ 30.023732] Possible unsafe locking scenario: [ 30.023732] [ 30.023734] CPU0 CPU1 [ 30.023735] ---- ---- [ 30.023736] lock(&obj_hash[i].lock); [ 30.023739] lock(&rq->lock); [ 30.023741] lock(&obj_hash[i].lock); [ 30.023744] lock((console_sem).lock); [ 30.023746] [ 30.023747] *** DEADLOCK *** [ 30.023747] [ 30.023749] 3 locks held by kworker/u4:2/40: [ 30.023749] #0: ((wq_completion)"ib_addr"){+.+.}, at: [<0000000084eccb28>] process_one_work+0xb12/0x1bb0 [ 30.023754] #1: ((work_completion)(&(&req->work)->work)){+.+.}, at: [<000000007d2c884e>] process_one_work+0xb89/0x1bb0 [ 30.023759] #2: (&obj_hash[i].lock){-.-.}, at: [<000000002515fa87>] debug_check_no_obj_freed+0x1e9/0xf1f [ 30.023764] [ 30.023765] stack backtrace: [ 30.023766] CPU: 0 PID: 40 Comm: kworker/u4:2 Not tainted 4.16.0-rc4+ #348 [ 30.023769] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 30.023770] Workqueue: ib_addr process_one_req [ 30.023772] Call Trace: [ 30.023773] dump_stack+0x194/0x24d [ 30.023774] ? arch_local_irq_restore+0x53/0x53 [ 30.023776] print_circular_bug.isra.38+0x2cd/0x2dc [ 30.023777] ? save_trace+0xe0/0x2b0 [ 30.023778] __lock_acquire+0x30a8/0x3e00 [ 30.023780] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 30.023781] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 30.023782] ? __lock_acquire+0x664/0x3e00 [ 30.023784] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 30.023785] ? trace_hardirqs_off+0x10/0x10 [ 30.023786] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 30.023788] ? __lock_acquire+0x664/0x3e00 [ 30.023789] ? trace_hardirqs_off+0x10/0x10 [ 30.023790] ? find_held_lock+0x35/0x1d0 [ 30.023792] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 30.023793] ? trace_hardirqs_off+0x10/0x10 [ 30.023794] ? print_irqtrace_events+0x270/0x270 [ 30.023795] lock_acquire+0x1d5/0x580 [ 30.023796] ? lock_acquire+0x1d5/0x580 [ 30.023798] ? down_trylock+0x13/0x70 [ 30.023799] ? lock_release+0xa40/0xa40 [ 30.023800] ? vprintk_emit+0x43b/0xb90 [ 30.023801] ? lock_downgrade+0x980/0x980 [ 30.023802] ? kvm_sched_clock_read+0x25/0x40 [ 30.023803] ? sched_clock+0x31/0x40 [ 30.023805] ? sched_clock_cpu+0x1b/0x180 [ 30.023806] ? vprintk_emit+0x5b5/0xb90 [ 30.023807] _raw_spin_lock_irqsave+0x96/0xc0 [ 30.023808] ? down_trylock+0x13/0x70 [ 30.023809] down_trylock+0x13/0x70 [ 30.023810] ? vprintk_emit+0x5b5/0xb90 [ 30.023812] __down_trylock_console_sem+0xa2/0x1e0 [ 30.023813] console_trylock+0x15/0x70 [ 30.023814] vprintk_emit+0x5b5/0xb90 [ 30.023815] ? console_unlock+0xfb0/0xfb0 [ 30.023816] ? __might_sleep+0x95/0x190 [ 30.023818] ? addr_handler+0xa3/0x380 [ 30.023819] ? __mutex_lock+0x16f/0x1a80 [ 30.023820] ? addr_handler+0xa3/0x380 [ 30.023821] ? trace_hardirqs_off+0x10/0x10 [ 30.023823] ? rcu_note_context_switch+0x710/0x710 [ 30.023824] ? mutex_lock_io_nested+0x1900/0x1900 [ 30.023825] ? __usermodehelper_disable+0x2f0/0x2f0 [ 30.023826] vprintk_default+0x28/0x30 [ 30.023827] vprintk_func+0x57/0xc0 [ 30.023828] printk+0xaa/0xca [ 30.023830] ? show_regs_print_info+0x18/0x18 [ 30.023831] ? __warn_printk+0x84/0xf0 [ 30.023832] ? addr_resolve+0xc90/0xc90 [ 30.023833] __warn_printk+0x90/0xf0 [ 30.023834] ? test_taint+0x20/0x20 [ 30.023835] ? lock_release+0xa40/0xa40 [ 30.023837] ? print_irqtrace_events+0x270/0x270 [ 30.023838] ? addr_resolve+0xc90/0xc90 [ 30.023839] debug_print_object+0x166/0x220 [ 30.023841] debug_check_no_obj_freed+0x662/0xf1f [ 30.023842] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 30.023843] ? free_obj_work+0x690/0x690 [ 30.023844] ? trace_hardirqs_on+0xd/0x10 [ 30.023846] ? cma_deref_id+0x2c/0x30 [ 30.023847] ? __lock_is_held+0xb6/0x140 [ 30.023848] ? debug_check_no_locks_freed+0x264/0x3c0 [ 30.023849] ? cma_work_handler+0x1d0/0x1d0 [ 30.023850] kfree+0xc7/0x260 [ 30.023852] process_one_req+0x2e7/0x6c0 [ 30.023853] ? addr_resolve+0xc90/0xc90 [ 30.023854] ? __lock_is_held+0xb6/0x140 [ 30.023855] process_one_work+0xc47/0x1bb0 [ 30.023857] ? debug_check_no_locks_freed+0x3c0/0x3c0 [ 30.023858] ? trace_hardirqs_on+0xd/0x10 [ 30.023859] ? pwq_dec_nr_in_flight+0x450/0x450 [ 30.023860] ? __schedule+0x903/0x1ec0 [ 30.023862] ? __lock_acquire+0x664/0x3e00 [ 30.023863] ? __lock_is_held+0xb6/0x140 [ 30.023864] ? trace_hardirqs_off+0x10/0x10 [ 30.023865] ? trace_hardirqs_off+0x10/0x10 [ 30.023866] ? lock_acquire+0x1d5/0x580 [ 30.023867] ? lock_acquire+0x1d5/0x580 [ 30.023869] ? worker_thread+0x4a3/0x1990 [ 30.023870] ? lock_downgrade+0x980/0x980 [ 30.023871] ? lock_release+0xa40/0xa40 [ 30.023872] ? pr_cont_work+0x130/0x130 [ 30.023873] ? trace_hardirqs_off+0x10/0x10 [ 30.023875] ? do_raw_spin_trylock+0x190/0x190 [ 30.023876] worker_thread+0x223/0x1990 [ 30.023877] ? finish_task_switch+0x1c1/0x7e0 [ 30.023878] ? lock_downgrade+0x980/0x980 [ 30.023880] ? process_one_work+0x1bb0/0x1bb0 [ 30.023881] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 30.023882] ? trace_hardirqs_on+0xd/0x10 [ 30.023884] ? _raw_spin_unlock_irq+0x27/0x70 [ 30.023885] ? finish_task_switch+0x1c1/0x7e0 [ 30.023886] ? finish_task_switch+0x182/0x7e0 [ 30.023887] ? copy_overflow+0x20/0x20 [ 30.023888] ? __schedule+0x903/0x1ec0 [ 30.023890] ? trace_hardirqs_off+0x10/0x10 [ 30.023891] ? find_held_lock+0x35/0x1d0 [ 30.023892] ? find_held_lock+0x35/0x1d0 [ 30.023893] ? complete+0x62/0x80 [ 30.023894] ? __schedule+0x1ec0/0x1ec0 [ 30.023896] ? do_wait_intr_irq+0x3e0/0x3e0 [ 30.023897] ? __lockdep_init_map+0xe4/0x650 [ 30.023898] ? do_raw_spin_trylock+0x190/0x190 [ 30.023899] ? lockdep_init_map+0x9/0x10 [ 30.023901] ? _raw_spin_unlock_irqrestore+0x31/0xc0 [ 30.023902] ? trace_hardirqs_on_caller+0x421/0x5c0 [ 30.023903] ? trace_hardirqs_on+0xd/0x10 [ 30.023905] ? __kthread_parkme+0x176/0x240 [ 30.023906] kthread+0x33c/0x400 [ 30.023907] ? process_one_work+0x1bb0/0x1bb0 [ 30.023908] ? kthread_stop+0x7a0/0x7a0 [ 30.023909] ret_from_fork+0x3a/0x50 [ 30.024336] Dumping ftrace buffer: [ 30.965380] (ftrace buffer empty) [ 30.969080] Kernel Offset: disabled [ 30.972702] Rebooting in 86400 seconds..