Starting mcstransd: [....] Starting periodic command scheduler: cron[?25l[?1c7[ ok 8[?25h[?0c. [....] Starting OpenBSD Secure Shell server: sshd[?25l[?1c7[ ok 8[?25h[?0c. [....] Starting file context maintaining daemon: restorecond[?25l[?1c7[ ok 8[?25h[?0c. [ 37.252750] audit: type=1800 audit(1567213706.472:33): pid=7345 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="startpar" name="rc.local" dev="sda1" ino=2465 res=0 [ 37.292315] audit: type=1800 audit(1567213706.482:34): pid=7345 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="startpar" name="rmnologin" dev="sda1" ino=2456 res=0 Debian GNU/Linux 7 syzkaller ttyS0 syzkaller login: [ 42.557702] audit: type=1400 audit(1567213711.782:35): avc: denied { map } for pid=7522 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.173' (ECDSA) to the list of known hosts. executing program [ 49.025105] audit: type=1400 audit(1567213718.252:36): avc: denied { map } for pid=7534 comm="syz-executor159" path="/root/syz-executor159236536" dev="sda1" ino=16484 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1 [ 49.063986] [ 49.065640] ======================================================== [ 49.072118] WARNING: possible irq lock inversion dependency detected [ 49.078594] 4.19.69 #43 Not tainted [ 49.082199] -------------------------------------------------------- [ 49.088667] swapper/1/0 just changed the state of lock: [ 49.094004] 00000000cf3bf942 (&(&ctx->ctx_lock)->rlock){..-.}, at: free_ioctx_users+0x2d/0x490 [ 49.102923] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 49.109736] (&fiq->waitq){+.+.} [ 49.109744] [ 49.109744] [ 49.109744] and interrupts could create inverse lock ordering between them. [ 49.109744] [ 49.124776] [ 49.124776] other info that might help us debug this: [ 49.131423] Possible interrupt unsafe locking scenario: [ 49.131423] [ 49.138325] CPU0 CPU1 [ 49.142963] ---- ---- [ 49.147605] lock(&fiq->waitq); [ 49.150948] local_irq_disable(); [ 49.156979] lock(&(&ctx->ctx_lock)->rlock); [ 49.163969] lock(&fiq->waitq); [ 49.169826] [ 49.172554] lock(&(&ctx->ctx_lock)->rlock); [ 49.177475] [ 49.177475] *** DEADLOCK *** [ 49.177475] [ 49.183582] 2 locks held by swapper/1/0: [ 49.187707] #0: 000000002f61a914 (rcu_callback){....}, at: rcu_process_callbacks+0xc79/0x1a30 [ 49.196457] #1: 00000000f352b490 (rcu_read_lock_sched){....}, at: percpu_ref_switch_to_atomic_rcu+0x1ca/0x540 [ 49.206592] [ 49.206592] the shortest dependencies between 2nd lock and 1st lock: [ 49.214545] -> (&fiq->waitq){+.+.} ops: 4 { [ 49.218939] HARDIRQ-ON-W at: [ 49.222300] lock_acquire+0x16f/0x3f0 [ 49.227907] _raw_spin_lock+0x2f/0x40 [ 49.233515] flush_bg_queue+0x1f3/0x3d0 [ 49.239857] fuse_request_send_background_locked+0x26d/0x4e0 [ 49.247460] fuse_request_send_background+0x12b/0x180 [ 49.254453] cuse_channel_open+0x5ba/0x830 [ 49.260500] misc_open+0x395/0x4c0 [ 49.265846] chrdev_open+0x245/0x6b0 [ 49.271381] do_dentry_open+0x4c3/0x1210 [ 49.277253] vfs_open+0xa0/0xd0 [ 49.282349] path_openat+0x10d7/0x45e0 [ 49.288574] do_filp_open+0x1a1/0x280 [ 49.294259] do_sys_open+0x3fe/0x550 [ 49.299781] __x64_sys_openat+0x9d/0x100 [ 49.305653] do_syscall_64+0xfd/0x620 [ 49.311259] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 49.318255] SOFTIRQ-ON-W at: [ 49.321677] lock_acquire+0x16f/0x3f0 [ 49.327284] _raw_spin_lock+0x2f/0x40 [ 49.332886] flush_bg_queue+0x1f3/0x3d0 [ 49.338739] fuse_request_send_background_locked+0x26d/0x4e0 [ 49.346357] fuse_request_send_background+0x12b/0x180 [ 49.353518] cuse_channel_open+0x5ba/0x830 [ 49.359561] misc_open+0x395/0x4c0 [ 49.365043] chrdev_open+0x245/0x6b0 [ 49.370560] do_dentry_open+0x4c3/0x1210 [ 49.376420] vfs_open+0xa0/0xd0 [ 49.381506] path_openat+0x10d7/0x45e0 [ 49.387195] do_filp_open+0x1a1/0x280 [ 49.392801] do_sys_open+0x3fe/0x550 [ 49.398324] __x64_sys_openat+0x9d/0x100 [ 49.404199] do_syscall_64+0xfd/0x620 [ 49.409857] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 49.416856] INITIAL USE at: [ 49.420184] lock_acquire+0x16f/0x3f0 [ 49.425876] _raw_spin_lock+0x2f/0x40 [ 49.431394] flush_bg_queue+0x1f3/0x3d0 [ 49.437082] fuse_request_send_background_locked+0x26d/0x4e0 [ 49.444668] fuse_request_send_background+0x12b/0x180 [ 49.451578] cuse_channel_open+0x5ba/0x830 [ 49.457533] misc_open+0x395/0x4c0 [ 49.462787] chrdev_open+0x245/0x6b0 [ 49.468219] do_dentry_open+0x4c3/0x1210 [ 49.474005] vfs_open+0xa0/0xd0 [ 49.479023] path_openat+0x10d7/0x45e0 [ 49.484635] do_filp_open+0x1a1/0x280 [ 49.490150] do_sys_open+0x3fe/0x550 [ 49.495580] __x64_sys_openat+0x9d/0x100 [ 49.501358] do_syscall_64+0xfd/0x620 [ 49.506879] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 49.513784] } [ 49.515664] ... key at: [] __key.42211+0x0/0x40 [ 49.522613] ... acquired at: [ 49.525790] _raw_spin_lock+0x2f/0x40 [ 49.529745] io_submit_one+0xef2/0x2eb0 [ 49.533884] __x64_sys_io_submit+0x1aa/0x520 [ 49.538452] do_syscall_64+0xfd/0x620 [ 49.542402] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 49.547735] [ 49.549340] -> (&(&ctx->ctx_lock)->rlock){..-.} ops: 2 { [ 49.554774] IN-SOFTIRQ-W at: [ 49.558047] lock_acquire+0x16f/0x3f0 [ 49.563477] _raw_spin_lock_irq+0x60/0x80 [ 49.569262] free_ioctx_users+0x2d/0x490 [ 49.574954] percpu_ref_switch_to_atomic_rcu+0x407/0x540 [ 49.582045] rcu_process_callbacks+0xba0/0x1a30 [ 49.588341] __do_softirq+0x25c/0x921 [ 49.594056] irq_exit+0x180/0x1d0 [ 49.599154] smp_apic_timer_interrupt+0x13b/0x550 [ 49.605628] apic_timer_interrupt+0xf/0x20 [ 49.611496] native_safe_halt+0xe/0x10 [ 49.617021] arch_cpu_idle+0xa/0x10 [ 49.622284] default_idle_call+0x36/0x90 [ 49.627981] do_idle+0x377/0x560 [ 49.632977] cpu_startup_entry+0xc8/0xe0 [ 49.638671] start_secondary+0x3e8/0x5b0 [ 49.644458] secondary_startup_64+0xa4/0xb0 [ 49.650401] INITIAL USE at: [ 49.653572] lock_acquire+0x16f/0x3f0 [ 49.658911] _raw_spin_lock_irq+0x60/0x80 [ 49.664602] io_submit_one+0xead/0x2eb0 [ 49.670120] __x64_sys_io_submit+0x1aa/0x520 [ 49.676087] do_syscall_64+0xfd/0x620 [ 49.681433] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 49.688685] } [ 49.690478] ... key at: [] __key.50211+0x0/0x40 [ 49.697208] ... acquired at: [ 49.700299] mark_lock+0x420/0x1370 [ 49.704077] __lock_acquire+0xc62/0x49c0 [ 49.708285] lock_acquire+0x16f/0x3f0 [ 49.712239] _raw_spin_lock_irq+0x60/0x80 [ 49.716542] free_ioctx_users+0x2d/0x490 [ 49.720760] percpu_ref_switch_to_atomic_rcu+0x407/0x540 [ 49.726362] rcu_process_callbacks+0xba0/0x1a30 [ 49.731187] __do_softirq+0x25c/0x921 [ 49.735145] irq_exit+0x180/0x1d0 [ 49.738754] smp_apic_timer_interrupt+0x13b/0x550 [ 49.743746] apic_timer_interrupt+0xf/0x20 [ 49.748129] native_safe_halt+0xe/0x10 [ 49.752166] arch_cpu_idle+0xa/0x10 [ 49.755942] default_idle_call+0x36/0x90 [ 49.760152] do_idle+0x377/0x560 [ 49.763666] cpu_startup_entry+0xc8/0xe0 [ 49.767878] start_secondary+0x3e8/0x5b0 [ 49.772089] secondary_startup_64+0xa4/0xb0 [ 49.776554] [ 49.778155] [ 49.778155] stack backtrace: [ 49.782688] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.19.69 #43 [ 49.788914] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 49.798246] Call Trace: [ 49.800817] [ 49.802953] dump_stack+0x172/0x1f0 [ 49.806647] print_irq_inversion_bug.part.0+0x2c0/0x2cd [ 49.812002] check_usage_forwards.cold+0x20/0x29 [ 49.816744] ? check_usage_backwards+0x340/0x340 [ 49.821484] ? save_stack_trace+0x1a/0x20 [ 49.825628] ? save_trace+0xe0/0x290 [ 49.829330] mark_lock+0x420/0x1370 [ 49.832947] ? check_usage_backwards+0x340/0x340 [ 49.837690] __lock_acquire+0xc62/0x49c0 [ 49.841732] ? mark_held_locks+0x100/0x100 [ 49.845950] ? mark_held_locks+0x100/0x100 [ 49.850164] ? __wake_up_common_lock+0xfe/0x190 [ 49.854815] ? mark_held_locks+0x100/0x100 [ 49.859037] ? __wake_up_common_lock+0xfe/0x190 [ 49.863829] ? _raw_spin_unlock_irqrestore+0x6b/0xe0 [ 49.868933] ? lockdep_hardirqs_on+0x19b/0x5d0 [ 49.873501] ? trace_hardirqs_on+0x67/0x220 [ 49.877852] ? kasan_check_read+0x11/0x20 [ 49.882006] lock_acquire+0x16f/0x3f0 [ 49.885790] ? free_ioctx_users+0x2d/0x490 [ 49.890014] _raw_spin_lock_irq+0x60/0x80 [ 49.894156] ? free_ioctx_users+0x2d/0x490 [ 49.898379] free_ioctx_users+0x2d/0x490 [ 49.902420] ? rcu_dynticks_curr_cpu_in_eqs+0x51/0xb0 [ 49.907595] percpu_ref_switch_to_atomic_rcu+0x407/0x540 [ 49.913026] ? percpu_ref_exit+0xd0/0xd0 [ 49.917069] rcu_process_callbacks+0xba0/0x1a30 [ 49.921732] ? __rcu_read_unlock+0x170/0x170 [ 49.926348] __do_softirq+0x25c/0x921 [ 49.930139] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 49.935659] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 49.941343] irq_exit+0x180/0x1d0 [ 49.944782] smp_apic_timer_interrupt+0x13b/0x550 [ 49.949604] apic_timer_interrupt+0xf/0x20 [ 49.953818] [ 49.956042] RIP: 0010:native_safe_halt+0xe/0x10 [ 49.960693] Code: ff ff 48 89 df e8 02 2c ae fa eb 82 e9 07 00 00 00 0f 00 2d 84 1e 54 00 f4 c3 66 90 e9 07 00 00 00 0f 00 2d 74 1e 54 00 fb f4 90 55 48 89 e5 41 57 41 56 41 55 41 54 53 e8 4e 0e 66 fa e8 09 [ 49.979585] RSP: 0018:ffff8880aa27fd00 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff13 [ 49.987405] RAX: 1ffffffff10e48c4 RBX: ffff8880aa2703c0 RCX: 0000000000000000 [ 49.994705] RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffff8880aa270c3c [ 50.001960] RBP: ffff8880aa27fd30 R08: ffff8880aa2703c0 R09: 0000000000000000 [ 50.009208] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001 [ 50.016610] R13: ffffffff88724610 R14: 0000000000000001 R15: 0000000000000000 [ 50.023879] ? default_idle+0x4e/0x320 [ 50.027749] arch_cpu