[?25l[?1c7[1G[[32m ok [39;49m8[?25h[?0c.
[....] Starting periodic command scheduler: cron[?25l[?1c7[1G[[32m ok [39;49m8[?25h[?0c.
Starting mcstransd:
[....] Starting file context maintaining daemon: restorecond[?25l[?1c7[1G[[32m ok [39;49m8[?25h[?0c.
[....] Starting OpenBSD Secure Shell server: sshd[?25l[?1c7[1G[[32m ok [39;49m8[?25h[?0c.
[ 17.650768] audit: type=1400 audit(1520766747.861:6): avc: denied { map } for pid=4143 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
Debian GNU/Linux 7 syzkaller ttyS0
Warning: Permanently added '10.128.0.61' (ECDSA) to the list of known hosts.
executing program
syzkaller login: [ 23.967586] audit: type=1400 audit(1520766754.178:7): avc: denied { map } for pid=4157 comm="syzkaller698278" path="/root/syzkaller698278051" 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
[ 24.002569] ------------[ cut here ]------------
[ 24.008109] ODEBUG: free active (active state 0) object type: work_struct hint: process_one_req+0x0/0x6c0
[ 24.017876] WARNING: CPU: 1 PID: 21 at lib/debugobjects.c:291 debug_print_object+0x166/0x220
[ 24.026420] Kernel panic - not syncing: panic_on_warn set ...
[ 24.026420]
[ 24.033755] CPU: 1 PID: 21 Comm: kworker/u4:1 Not tainted 4.16.0-rc4+ #349
[ 24.040734] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
[ 24.050064] Workqueue: ib_addr process_one_req
[ 24.054616] Call Trace:
[ 24.057175] dump_stack+0x194/0x24d
[ 24.060780] ? arch_local_irq_restore+0x53/0x53
[ 24.065425] ? vsnprintf+0x1ed/0x1900
[ 24.069201] panic+0x1e4/0x41c
[ 24.072368] ? refcount_error_report+0x214/0x214
[ 24.077096] ? show_regs_print_info+0x18/0x18
[ 24.081570] ? __warn+0x1c1/0x200
[ 24.084997] ? debug_print_object+0x166/0x220
[ 24.089462] __warn+0x1dc/0x200
[ 24.092721] ? debug_print_object+0x166/0x220
[ 24.097187] report_bug+0x1f4/0x2b0
[ 24.100792] fixup_bug.part.11+0x37/0x80
[ 24.104827] do_error_trap+0x2d7/0x3e0
[ 24.108687] ? vprintk_default+0x28/0x30
[ 24.112722] ? math_error+0x400/0x400
[ 24.116494] ? printk+0xaa/0xca
[ 24.119745] ? show_regs_print_info+0x18/0x18
[ 24.124221] ? __usermodehelper_disable+0x2f0/0x2f0
[ 24.129214] ? trace_hardirqs_off_thunk+0x1a/0x1c
[ 24.134033] do_invalid_op+0x1b/0x20
[ 24.137719] invalid_op+0x1b/0x40
[ 24.141145] RIP: 0010:debug_print_object+0x166/0x220
[ 24.146216] RSP: 0018:ffff8801d9447210 EFLAGS: 00010086
[ 24.151550] RAX: dffffc0000000008 RBX: 0000000000000003 RCX: ffffffff815abbee
[ 24.158799] RDX: 0000000000000000 RSI: 1ffff1003b288df2 RDI: 1ffff1003b288dc7
[ 24.166039] RBP: ffff8801d9447250 R08: 0000000000000000 R09: 1ffff1003b288d99
[ 24.173281] R10: ffffed003b288e71 R11: ffffffff86f398b8 R12: 0000000000000001
[ 24.180522] R13: ffffffff86f15180 R14: ffffffff86408500 R15: ffffffff8147aed0
[ 24.187771] ? __usermodehelper_disable+0x2f0/0x2f0
[ 24.192765] ? vprintk_func+0x5e/0xc0
[ 24.196551] debug_check_no_obj_freed+0x662/0xf1f
[ 24.201364] ? debug_check_no_locks_freed+0x3c0/0x3c0
[ 24.206539] ? free_obj_work+0x690/0x690
[ 24.210575] ? trace_hardirqs_on+0xd/0x10
[ 24.214705] ? cma_deref_id+0x2c/0x30
[ 24.218479] ? __lock_is_held+0xb6/0x140
[ 24.222516] ? debug_check_no_locks_freed+0x264/0x3c0
[ 24.227685] ? cma_work_handler+0x1d0/0x1d0
[ 24.231977] kfree+0xc7/0x260
[ 24.235058] process_one_req+0x2e7/0x6c0
[ 24.239093] ? addr_resolve+0xbc0/0xbc0
[ 24.243039] ? __lock_is_held+0xb6/0x140
[ 24.247084] process_one_work+0xc47/0x1bb0
[ 24.251292] ? debug_check_no_locks_freed+0x3c0/0x3c0
[ 24.256455] ? trace_hardirqs_on+0xd/0x10
[ 24.260584] ? pwq_dec_nr_in_flight+0x450/0x450
[ 24.265243] ? perf_trace_lock_acquire+0xe3/0x980
[ 24.270057] ? __schedule+0x903/0x1ec0
[ 24.273922] ? perf_trace_lock+0x900/0x900
[ 24.278135] ? trace_hardirqs_off+0x10/0x10
[ 24.282426] ? lock_downgrade+0x980/0x980
[ 24.286585] ? lock_acquire+0x1d5/0x580
[ 24.290529] ? lock_acquire+0x1d5/0x580
[ 24.294475] ? worker_thread+0x4a3/0x1990
[ 24.298602] ? lock_release+0xa40/0xa40
[ 24.302551] ? pr_cont_work+0x130/0x130
[ 24.306506] ? do_raw_spin_trylock+0x190/0x190
[ 24.311079] worker_thread+0x223/0x1990
[ 24.315028] ? finish_task_switch+0x1c1/0x7e0
[ 24.319515] ? process_one_work+0x1bb0/0x1bb0
[ 24.324072] ? trace_hardirqs_on_caller+0x421/0x5c0
[ 24.329070] ? trace_hardirqs_on+0xd/0x10
[ 24.333188] ? _raw_spin_unlock_irq+0x27/0x70
[ 24.337657] ? finish_task_switch+0x1c1/0x7e0
[ 24.342126] ? finish_task_switch+0x182/0x7e0
[ 24.346601] ? copy_overflow+0x20/0x20
[ 24.350479] ? __schedule+0x903/0x1ec0
[ 24.354350] ? trace_hardirqs_off+0x10/0x10
[ 24.358650] ? find_held_lock+0x35/0x1d0
[ 24.362689] ? find_held_lock+0x35/0x1d0
[ 24.366730] ? complete+0x62/0x80
[ 24.370166] ? __schedule+0x1ec0/0x1ec0
[ 24.374109] ? do_wait_intr_irq+0x3e0/0x3e0
[ 24.378402] ? __lockdep_init_map+0xe4/0x650
[ 24.382785] ? do_raw_spin_trylock+0x190/0x190
[ 24.387347] ? lockdep_init_map+0x9/0x10
[ 24.391379] ? _raw_spin_unlock_irqrestore+0x31/0xc0
[ 24.396457] ? trace_hardirqs_on_caller+0x421/0x5c0
[ 24.401447] ? trace_hardirqs_on+0xd/0x10
[ 24.405566] ? __kthread_parkme+0x176/0x240
[ 24.409865] kthread+0x33c/0x400
[ 24.413203] ? process_one_work+0x1bb0/0x1bb0
[ 24.417667] ? kthread_stop+0x7a0/0x7a0
[ 24.421615] ret_from_fork+0x3a/0x50
[ 24.425316]
[ 24.425319] ======================================================
[ 24.425321] WARNING: possible circular locking dependency detected
[ 24.425323] 4.16.0-rc4+ #349 Not tainted
[ 24.425325] ------------------------------------------------------
[ 24.425327] kworker/u4:1/21 is trying to acquire lock:
[ 24.425328] ((console_sem).lock){..-.}, at: [<000000007e2fd468>] down_trylock+0x13/0x70
[ 24.425335]
[ 24.425336] but task is already holding lock:
[ 24.425337] (&obj_hash[i].lock){-.-.}, at: [<00000000969ee97a>] debug_check_no_obj_freed+0x1e9/0xf1f
[ 24.425343]
[ 24.425345] which lock already depends on the new lock.
[ 24.425346]
[ 24.425347]
[ 24.425350] the existing dependency chain (in reverse order) is:
[ 24.425350]
[ 24.425351] -> #3 (&obj_hash[i].lock){-.-.}:
[ 24.425358] _raw_spin_lock_irqsave+0x96/0xc0
[ 24.425360] __debug_object_init+0x109/0x1040
[ 24.425361] debug_object_init+0x17/0x20
[ 24.425363] hrtimer_init+0x8c/0x410
[ 24.425365] init_dl_task_timer+0x1b/0x50
[ 24.425367] __sched_fork+0x2bb/0xb60
[ 24.425368] init_idle+0x75/0x820
[ 24.425370] sched_init+0xb19/0xc43
[ 24.425371] start_kernel+0x452/0x819
[ 24.425373] x86_64_start_reservations+0x2a/0x2c
[ 24.425375] x86_64_start_kernel+0x77/0x7a
[ 24.425377] secondary_startup_64+0xa5/0xb0
[ 24.425378]
[ 24.425379] -> #2 (&rq->lock){-.-.}:
[ 24.425385] _raw_spin_lock+0x2a/0x40
[ 24.425386] task_fork_fair+0x7a/0x690
[ 24.425388] sched_fork+0x450/0xc10
[ 24.425390] copy_process.part.38+0x1758/0x4b60
[ 24.425392] _do_fork+0x1f7/0xf70
[ 24.425393] kernel_thread+0x34/0x40
[ 24.425395] rest_init+0x22/0xf0
[ 24.425397] start_kernel+0x7f1/0x819
[ 24.425399] x86_64_start_reservations+0x2a/0x2c
[ 24.425400] x86_64_start_kernel+0x77/0x7a
[ 24.425403] secondary_startup_64+0xa5/0xb0
[ 24.425404]
[ 24.425405] -> #1 (&p->pi_lock){-.-.}:
[ 24.425411] _raw_spin_lock_irqsave+0x96/0xc0
[ 24.425412] try_to_wake_up+0xbc/0x15f0
[ 24.425414] wake_up_process+0x10/0x20
[ 24.425416] __up.isra.0+0x1cc/0x2c0
[ 24.425417] up+0x13b/0x1d0
[ 24.425419] __up_console_sem+0xb2/0x1a0
[ 24.425421] console_unlock+0x5af/0xfb0
[ 24.425423] vprintk_emit+0x5c3/0xb90
[ 24.425424] vprintk_default+0x28/0x30
[ 24.425426] vprintk_func+0x57/0xc0
[ 24.425427] printk+0xaa/0xca
[ 24.425429] kauditd_hold_skb+0x163/0x180
[ 24.425431] kauditd_send_queue+0xfa/0x140
[ 24.425433] kauditd_thread+0x660/0x940
[ 24.425434] kthread+0x33c/0x400
[ 24.425436] ret_from_fork+0x3a/0x50
[ 24.425437]
[ 24.425438] -> #0 ((console_sem).lock){..-.}:
[ 24.425444] lock_acquire+0x1d5/0x580
[ 24.425446] _raw_spin_lock_irqsave+0x96/0xc0
[ 24.425447] down_trylock+0x13/0x70
[ 24.425449] __down_trylock_console_sem+0xa2/0x1e0
[ 24.425451] console_trylock+0x15/0x70
[ 24.425453] vprintk_emit+0x5b5/0xb90
[ 24.425454] vprintk_default+0x28/0x30
[ 24.425456] vprintk_func+0x57/0xc0
[ 24.425458] printk+0xaa/0xca
[ 24.425459] __warn_printk+0x90/0xf0
[ 24.425461] debug_print_object+0x166/0x220
[ 24.425463] debug_check_no_obj_freed+0x662/0xf1f
[ 24.425465] kfree+0xc7/0x260
[ 24.425466] process_one_req+0x2e7/0x6c0
[ 24.425468] process_one_work+0xc47/0x1bb0
[ 24.425470] worker_thread+0x223/0x1990
[ 24.425472] kthread+0x33c/0x400
[ 24.425473] ret_from_fork+0x3a/0x50
[ 24.425474]
[ 24.425476] other info that might help us debug this:
[ 24.425477]
[ 24.425478] Chain exists of:
[ 24.425479] (console_sem).lock --> &rq->lock --> &obj_hash[i].lock
[ 24.425487]
[ 24.425489] Possible unsafe locking scenario:
[ 24.425490]
[ 24.425491] CPU0 CPU1
[ 24.425493] ---- ----
[ 24.425494] lock(&obj_hash[i].lock);
[ 24.425498] lock(&rq->lock);
[ 24.425505] lock(&obj_hash[i].lock);
[ 24.425509] lock((console_sem).lock);
[ 24.425512]
[ 24.425513] *** DEADLOCK ***
[ 24.425514]
[ 24.425516] 3 locks held by kworker/u4:1/21:
[ 24.425517] #0: ((wq_completion)"ib_addr"){+.+.}, at: [<00000000226671fe>] process_one_work+0xb12/0x1bb0
[ 24.425524] #1: ((work_completion)(&(&req->work)->work)){+.+.}, at: [<00000000a2dca1c8>] process_one_work+0xb89/0x1bb0
[ 24.425531] #2: (&obj_hash[i].lock){-.-.}, at: [<00000000969ee97a>] debug_check_no_obj_freed+0x1e9/0xf1f
[ 24.425537]
[ 24.425539] stack backtrace:
[ 24.425541] CPU: 1 PID: 21 Comm: kworker/u4:1 Not tainted 4.16.0-rc4+ #349
[ 24.425545] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
[ 24.425546] Workqueue: ib_addr process_one_req
[ 24.425549] Call Trace:
[ 24.425550] dump_stack+0x194/0x24d
[ 24.425552] ? arch_local_irq_restore+0x53/0x53
[ 24.425554] print_circular_bug.isra.38+0x2cd/0x2dc
[ 24.425556] ? save_trace+0xe0/0x2b0
[ 24.425557] __lock_acquire+0x30a8/0x3e00
[ 24.425559] ? debug_check_no_locks_freed+0x3c0/0x3c0
[ 24.425561] ? debug_check_no_locks_freed+0x3c0/0x3c0
[ 24.425563] ? __save_stack_trace+0x6e/0xd0
[ 24.425565] ? perf_trace_lock_acquire+0xe3/0x980
[ 24.425567] ? check_usage+0x22f/0xb60
[ 24.425569] ? perf_trace_lock+0x900/0x900
[ 24.425571] ? perf_trace_lock_acquire+0xe3/0x980
[ 24.425572] ? perf_trace_lock+0x900/0x900
[ 24.425574] lock_acquire+0x1d5/0x580
[ 24.425576] ? lock_acquire+0x1d5/0x580
[ 24.425577] ? down_trylock+0x13/0x70
[ 24.425579] ? lock_release+0xa40/0xa40
[ 24.425580] ? vprintk_emit+0x43b/0xb90
[ 24.425582] ? lock_downgrade+0x980/0x980
[ 24.425584] ? kvm_sched_clock_read+0x25/0x40
[ 24.425586] ? sched_clock+0x31/0x40
[ 24.425587] ? sched_clock_cpu+0x1b/0x180
[ 24.425589] ? vprintk_emit+0x5b5/0xb90
[ 24.425591] _raw_spin_lock_irqsave+0x96/0xc0
[ 24.425592] ? down_trylock+0x13/0x70
[ 24.425594] down_trylock+0x13/0x70
[ 24.425596] ? vprintk_emit+0x5b5/0xb90
[ 24.425598] __down_trylock_console_sem+0xa2/0x1e0
[ 24.425599] console_trylock+0x15/0x70
[ 24.425601] vprintk_emit+0x5b5/0xb90
[ 24.425603] ? console_unlock+0xfb0/0xfb0
[ 24.425605] ? perf_trace_lock_acquire+0xe3/0x980
[ 24.425606] ? __might_sleep+0x95/0x190
[ 24.425608] ? addr_handler+0xa3/0x380
[ 24.425610] ? perf_trace_lock+0x900/0x900
[ 24.425611] ? trace_hardirqs_off+0x10/0x10
[ 24.425613] ? __usermodehelper_disable+0x2f0/0x2f0
[ 24.425615] vprintk_default+0x28/0x30
[ 24.425617] vprintk_func+0x57/0xc0
[ 24.425618] printk+0xaa/0xca
[ 24.425620] ? show_regs_print_info+0x18/0x18
[ 24.425621] ? __warn_printk+0x84/0xf0
[ 24.425623] ? addr_resolve+0xbc0/0xbc0
[ 24.425625] __warn_printk+0x90/0xf0
[ 24.425626] ? test_taint+0x20/0x20
[ 24.425628] ? lock_release+0xa40/0xa40
[ 24.425630] ? print_irqtrace_events+0x270/0x270
[ 24.425631] ? addr_resolve+0xbc0/0xbc0
[ 24.425633] debug_print_object+0x166/0x220
[ 24.425635] debug_check_no_obj_freed+0x662/0xf1f
[ 24.425637] ? debug_check_no_locks_freed+0x3c0/0x3c0
[ 24.425639] ? free_obj_work+0x690/0x690
[ 24.425641] ? trace_hardirqs_on+0xd/0x10
[ 24.425642] ? cma_deref_id+0x2c/0x30
[ 24.425644] ? __lock_is_held+0xb6/0x140
[ 24.425646] ? debug_check_no_locks_freed+0x264/0x3c0
[ 24.425648] ? cma_work_handler+0x1d0/0x1d0
[ 24.425649] kfree+0xc7/0x260
[ 24.425651] process_one_req+0x2e7/0x6c0
[ 24.425652] ? addr_resolve+0xbc0/0xbc0
[ 24.425654] ? __lock_is_held+0xb6/0x140
[ 24.425656] process_one_work+0xc47/0x1bb0
[ 24.425658] ? debug_check_no_locks_freed+0x3c0/0x3c0
[ 24.425660] ? trace_hardirqs_on+0xd/0x10
[ 24.425661] ? pwq_dec_nr_in_flight+0x450/0x450
[ 24.425663] ? perf_trace_lock_acquire+0xe3/0x980
[ 24.425665] ? __schedule+0x903/0x1ec0
[ 24.425667] ? perf_trace_lock+0x900/0x900
[ 24.425669] ? trace_hardirqs_off+0x10/0x10
[ 24.425670] ? lock_downgrade+0x980/0x980
[ 24.425672] ? lock_acquire+0x1d5/0x580
[ 24.425674] ? lock_acquire+0x1d5/0x580
[ 24.425675] ? worker_thread+0x4a3/0x1990
[ 24.425677] ? lock_release+0xa40/0xa40
[ 24.425679] ? pr_cont_work+0x130/0x130
[ 24.425680] ? do_raw_spin_trylock+0x190/0x190
[ 24.425682] worker_thread+0x223/0x1990
[ 24.425684] ? finish_task_switch+0x1c1/0x7e0
[ 24.425686] ? process_one_work+0x1bb0/0x1bb0
[ 24.425688] ? trace_hardirqs_on_caller+0x421/0x5c0
[ 24.425689] ? trace_hardirqs_on+0xd/0x10
[ 24.425691] ? _raw_spin_unlock_irq+0x27/0x70
[ 24.425693] ? finish_task_switch+0x1c1/0x7e0
[ 24.425695] ? finish_task_switch+0x182/0x7e0
[ 24.425697] ? copy_overflow+0x20/0x20
[ 24.425698] ? __schedule+0x903/0x1ec0
[ 24.425700] ? trace_hardirqs_off+0x10/0x10
[ 24.425702] ? find_held_lock+0x35/0x1d0
[ 24.425703] ? find_held_lock+0x35/0x1d0
[ 24.425705] ? complete+0x62/0x80
[ 24.425707] ? __schedule+0x1ec0/0x1ec0
[ 24.425708] ? do_wait_intr_irq+0x3e0/0x3e0
[ 24.425710] ? __lockdep_init_map+0xe4/0x650
[ 24.425712] ? do_raw_spin_trylock+0x190/0x190
[ 24.425714] ? lockdep_init_map+0x9/0x10
[ 24.425716] ? _raw_spin_unlock_irqrestore+0x31/0xc0
[ 24.425718] ? trace_hardirqs_on_caller+0x421/0x5c0
[ 24.425719] ? trace_hardirqs_on+0xd/0x10
[ 24.425721] ? __kthread_parkme+0x176/0x240
[ 24.425723] kthread+0x33c/0x400
[ 24.425724] ? process_one_work+0x1bb0/0x1bb0
[ 24.425726] ? kthread_stop+0x7a0/0x7a0
[ 24.425728] ret_from_fork+0x3a/0x50
[ 25.481834] Shutting down cpus with NMI
[ 26.384507] Dumping ftrace buffer:
[ 26.388021] (ftrace buffer empty)
[ 26.391701] Kernel Offset: disabled
[ 26.395301] Rebooting in 86400 seconds..