[info] Using makefile-style concurrent boot in runlevel 2. [ 25.746287] audit: type=1800 audit(1542817010.630:21): pid=5811 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="bootlogs" dev="sda1" ino=2419 res=0 [ 25.779430] audit: type=1800 audit(1542817010.640:22): pid=5811 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="motd" dev="sda1" ino=2447 res=0 [....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [....] Starting periodic command scheduler: cron[?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: [ 36.474823] cron (5961) used greatest stack depth: 15632 bytes left Warning: Permanently added '10.128.0.59' (ECDSA) to the list of known hosts. net.ipv6.conf.syz_tun.accept_dad = 0 net.ipv6.conf.syz_tun.router_solicitations = 0 [ 40.847768] IPVS: ftp: loaded support on port[0] = 21 [ 41.077743] bridge0: port 1(bridge_slave_0) entered blocking state [ 41.084602] bridge0: port 1(bridge_slave_0) entered disabled state [ 41.091944] device bridge_slave_0 entered promiscuous mode [ 41.109270] bridge0: port 2(bridge_slave_1) entered blocking state [ 41.115769] bridge0: port 2(bridge_slave_1) entered disabled state [ 41.123217] device bridge_slave_1 entered promiscuous mode [ 41.139860] IPv6: ADDRCONF(NETDEV_UP): veth0_to_bridge: link is not ready [ 41.157763] IPv6: ADDRCONF(NETDEV_UP): veth1_to_bridge: link is not ready [ 41.205799] bond0: Enslaving bond_slave_0 as an active interface with an up link [ 41.225430] bond0: Enslaving bond_slave_1 as an active interface with an up link [ 41.300118] IPv6: ADDRCONF(NETDEV_UP): team_slave_0: link is not ready [ 41.307440] team0: Port device team_slave_0 added [ 41.324329] IPv6: ADDRCONF(NETDEV_UP): team_slave_1: link is not ready [ 41.331736] team0: Port device team_slave_1 added [ 41.348314] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready [ 41.369875] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready [ 41.390390] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bridge: link becomes ready [ 41.410198] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bridge: link becomes ready RTNETLINK answers: Operation not supported RTNETLINK answers: No buffer space available RTNETLINK answers: Operation not supported [ 41.553986] bridge0: port 2(bridge_slave_1) entered blocking state [ 41.560595] bridge0: port 2(bridge_slave_1) entered forwarding state [ 41.567542] bridge0: port 1(bridge_slave_0) entered blocking state [ 41.573920] bridge0: port 1(bridge_slave_0) entered forwarding state RTNETLINK answers: Operation not supported RTNETLINK answers: Operation not supported RTNETLINK answers: Operation not supported RTNETLINK answers: Invalid argument RTNETLINK answers: Invalid argument RTNETLINK answers: Invalid argument [ 42.078160] 8021q: adding VLAN 0 to HW filter on device bond0 [ 42.132338] IPv6: ADDRCONF(NETDEV_UP): veth0: link is not ready [ 42.185939] IPv6: ADDRCONF(NETDEV_UP): veth1: link is not ready [ 42.192380] IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready [ 42.199724] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 42.248116] 8021q: adding VLAN 0 to HW filter on device team0 executing program [ 42.559890] [ 42.561648] ====================================================== [ 42.567965] WARNING: possible circular locking dependency detected [ 42.574419] 4.20.0-rc1-next-20181109+ #110 Not tainted [ 42.579781] ------------------------------------------------------ [ 42.586229] syz-executor599/5968 is trying to acquire lock: [ 42.592025] 00000000e42cbf00 (sb_writers#3){.+.+}, at: mnt_want_write+0x3f/0xc0 [ 42.599753] [ 42.599753] but task is already holding lock: [ 42.605730] 00000000166f985a (&iint->mutex){+.+.}, at: process_measurement+0x438/0x1bf0 [ 42.614064] [ 42.614064] which lock already depends on the new lock. [ 42.614064] [ 42.622643] [ 42.622643] the existing dependency chain (in reverse order) is: [ 42.630256] [ 42.630256] -> #1 (&iint->mutex){+.+.}: [ 42.635713] __mutex_lock+0x166/0x16f0 [ 42.640223] mutex_lock_nested+0x16/0x20 [ 42.644804] process_measurement+0x438/0x1bf0 [ 42.649805] ima_file_check+0xe5/0x130 [ 42.654209] path_openat+0x134a/0x5150 [ 42.658663] do_filp_open+0x255/0x380 [ 42.662969] do_sys_open+0x568/0x700 [ 42.667191] __x64_sys_open+0x7e/0xc0 [ 42.671623] do_syscall_64+0x1b9/0x820 [ 42.676043] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 42.681736] [ 42.681736] -> #0 (sb_writers#3){.+.+}: [ 42.687189] lock_acquire+0x1ed/0x520 [ 42.691507] __sb_start_write+0x214/0x370 [ 42.696166] mnt_want_write+0x3f/0xc0 [ 42.700588] ovl_want_write+0x76/0xa0 [ 42.704919] ovl_open_maybe_copy_up+0x12c/0x190 [ 42.710205] ovl_open+0xb3/0x260 [ 42.714090] do_dentry_open+0x499/0x1250 [ 42.718767] dentry_open+0x143/0x1d0 [ 42.722989] ima_calc_file_hash+0x324/0x570 [ 42.727818] ima_collect_measurement+0x619/0x730 [ 42.733191] process_measurement+0x11fd/0x1bf0 [ 42.738275] ima_file_check+0xe5/0x130 [ 42.742665] path_openat+0x134a/0x5150 [ 42.747050] do_filp_open+0x255/0x380 [ 42.751433] do_sys_open+0x568/0x700 [ 42.755830] __x64_sys_open+0x7e/0xc0 [ 42.760147] do_syscall_64+0x1b9/0x820 [ 42.764660] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 42.770390] [ 42.770390] other info that might help us debug this: [ 42.770390] [ 42.778526] Possible unsafe locking scenario: [ 42.778526] [ 42.784569] CPU0 CPU1 [ 42.789221] ---- ---- [ 42.794041] lock(&iint->mutex); [ 42.797485] lock(sb_writers#3); [ 42.803537] lock(&iint->mutex); [ 42.809506] lock(sb_writers#3); [ 42.813184] [ 42.813184] *** DEADLOCK *** [ 42.813184] [ 42.819230] 1 lock held by syz-executor599/5968: [ 42.823962] #0: 00000000166f985a (&iint->mutex){+.+.}, at: process_measurement+0x438/0x1bf0 [ 42.832648] [ 42.832648] stack backtrace: [ 42.837148] CPU: 0 PID: 5968 Comm: syz-executor599 Not tainted 4.20.0-rc1-next-20181109+ #110 [ 42.845796] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 42.855141] Call Trace: [ 42.857741] dump_stack+0x244/0x39d [ 42.861353] ? dump_stack_print_info.cold.1+0x20/0x20 [ 42.866752] ? vprintk_func+0x85/0x181 [ 42.870629] print_circular_bug.isra.35.cold.56+0x1bd/0x27d [ 42.876450] ? save_trace+0xe0/0x290 [ 42.880336] __lock_acquire+0x3399/0x4c20 [ 42.884487] ? kasan_check_write+0x14/0x20 [ 42.888715] ? mark_held_locks+0x130/0x130 [ 42.892944] ? kmem_cache_alloc_trace+0x152/0x750 [ 42.897771] ? apparmor_file_alloc_security+0x17b/0xac0 [ 42.903147] ? security_file_alloc+0x4c/0xa0 [ 42.907583] ? __alloc_file+0x12a/0x470 [ 42.911749] ? alloc_empty_file+0x72/0x170 [ 42.916031] ? dentry_open+0x71/0x1d0 [ 42.919935] ? ima_file_check+0xe5/0x130 [ 42.923981] ? path_openat+0x134a/0x5150 [ 42.928024] ? do_filp_open+0x255/0x380 [ 42.932089] ? do_sys_open+0x568/0x700 [ 42.935961] ? __x64_sys_open+0x7e/0xc0 [ 42.939916] ? do_syscall_64+0x1b9/0x820 [ 42.944088] ? entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 42.949466] ? graph_lock+0x270/0x270 [ 42.953266] ? graph_lock+0x270/0x270 [ 42.957399] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 42.962925] ? check_preemption_disabled+0x48/0x280 [ 42.967935] lock_acquire+0x1ed/0x520 [ 42.971727] ? mnt_want_write+0x3f/0xc0 [ 42.975698] ? lock_release+0xa10/0xa10 [ 42.979667] ? perf_trace_sched_process_exec+0x860/0x860 [ 42.985167] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 42.990781] ? fsnotify+0x50e/0xef0 [ 42.994403] __sb_start_write+0x214/0x370 [ 42.998538] ? mnt_want_write+0x3f/0xc0 [ 43.002499] mnt_want_write+0x3f/0xc0 [ 43.006290] ovl_want_write+0x76/0xa0 [ 43.010077] ovl_open_maybe_copy_up+0x12c/0x190 [ 43.014770] ovl_open+0xb3/0x260 [ 43.018131] do_dentry_open+0x499/0x1250 [ 43.022183] ? ovl_llseek+0x110/0x110 [ 43.025978] ? chown_common+0x730/0x730 [ 43.029952] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 43.035479] ? percpu_counter_add_batch+0x141/0x190 [ 43.040537] dentry_open+0x143/0x1d0 [ 43.044248] ima_calc_file_hash+0x324/0x570 [ 43.048560] ima_collect_measurement+0x619/0x730 [ 43.053300] ? ima_get_action+0xa0/0xa0 [ 43.057261] process_measurement+0x11fd/0x1bf0 [ 43.061829] ? ima_add_template_entry.cold.4+0x3c/0x3c [ 43.067091] ? find_held_lock+0x36/0x1c0 [ 43.071149] ? lock_downgrade+0x900/0x900 [ 43.075281] ? check_preemption_disabled+0x48/0x280 [ 43.080290] ? kasan_check_read+0x11/0x20 [ 43.084425] ? rcu_dynticks_curr_cpu_in_eqs+0xa2/0x170 [ 43.089696] ? rcu_read_unlock_special+0x370/0x370 [ 43.094618] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 43.100159] ? refcount_sub_and_test_checked+0x203/0x310 [ 43.105599] ? refcount_dec_if_one+0x180/0x180 [ 43.110177] ? aa_capable+0xe30/0xe30 [ 43.114028] ? __sanitizer_cov_trace_const_cmp8+0x18/0x20 [ 43.119587] ? ovl_open+0xc9/0x260 [ 43.123114] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 43.128641] ? do_dentry_open+0x945/0x1250 [ 43.132878] ? __sanitizer_cov_trace_const_cmp1+0x1a/0x20 [ 43.138403] ? apparmor_task_getsecid+0x96/0xd0 [ 43.143054] ima_file_check+0xe5/0x130 [ 43.146925] ? process_measurement+0x1bf0/0x1bf0 [ 43.151672] ? __sanitizer_cov_trace_switch+0x53/0x90 [ 43.156845] path_openat+0x134a/0x5150 [ 43.160717] ? rcu_softirq_qs+0x20/0x20 [ 43.164676] ? unwind_dump+0x190/0x190 [ 43.168548] ? path_lookupat.isra.43+0xc00/0xc00 [ 43.173288] ? unwind_get_return_address+0x61/0xa0 [ 43.178203] ? __sanitizer_cov_trace_cmp4+0x16/0x20 [ 43.183204] ? expand_files.part.8+0x571/0x9a0 [ 43.187771] ? find_held_lock+0x36/0x1c0 [ 43.191816] ? __alloc_fd+0x347/0x6e0 [ 43.195601] ? lock_downgrade+0x900/0x900 [ 43.199729] ? getname+0x19/0x20 [ 43.203082] ? kasan_check_read+0x11/0x20 [ 43.207212] ? do_raw_spin_unlock+0xa7/0x330 [ 43.211601] ? do_raw_spin_trylock+0x270/0x270 [ 43.216374] ? __lock_is_held+0xb5/0x140 [ 43.220429] ? __check_object_size+0xb1/0x782 [ 43.225050] ? _raw_spin_unlock+0x2c/0x50 [ 43.229243] ? __alloc_fd+0x347/0x6e0 [ 43.233041] do_filp_open+0x255/0x380 [ 43.236833] ? may_open_dev+0x100/0x100 [ 43.240801] ? get_unused_fd_flags+0x122/0x1a0 [ 43.245372] ? __alloc_fd+0x6e0/0x6e0 [ 43.249176] do_sys_open+0x568/0x700 [ 43.252877] ? filp_open+0x80/0x80 [ 43.256459] ? trace_hardirqs_off_caller+0x300/0x300 [ 43.261557] __x64_sys_open+0x7e/0xc0 [ 43.265347] do_syscall_64+0x1b9/0x820 [ 43.269341] ? entry_SYSCALL_64_after_hwframe+0x3e/0xbe [ 43.274718] ? syscall_return_slowpath+0x5e0/0x5e0 [ 43.279660] ? trace_hardirqs_off_thunk+0x1a/0x1c [ 43.284493] ? trace_hardirqs_on_caller+0x310/0x310 [ 43.289504] ? prepare_exit_to_usermode+0x3b0/0x3b0 [ 43.294509] ? prepare_exit_to_usermode+0x291/0x3b0 [ 43.299513] ? trace_hardirqs_off_thunk+0x1a/0x1c [ 43.304345] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 43.309519] RIP: 0033:0x441af9 [ 43.312701] Code: 23 02 00 85 c0 b8 00 00 00 00 48 0f 44 c3 5b c3 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 cb 08 fc ff c3 66 2e 0f 1f 84 00 00 00 00 [ 43.331598] RSP: 002b:00007ffce8c93d48 EFLAGS: 00000246 ORIG_RAX: 0000000000000002 [ 43.339316] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 0000000000441af9 [ 43.346587] RDX: 0000000000000000 RSI: 0000000000000003 RDI: 0000000020000040 [ 43.354000] RBP: 0000000000000000 R08: 0000000000402850 R09: 0000000000402850 [ 43.361264] R10: 0000000000402850 R11: 0000000000000246 R12: 0000000000402850 [ 43.368526] R13: 00000000004028e0 R14: 0000000000000000 R15: 0000000000000000 [ 43.491585] kobject: 'rx-0' (000000008bf42b56): kobject_cleanup, parent 00000000f75c8bd3 [ 43.499901] kobject: 'rx-0' (000000008bf42b56): auto cleanup 'remove' event [ 43.507004] kobject: 'rx-0' (000000008bf42b56): kobject_uevent_env [ 43.513415] kobject: 'rx-0' (000000008bf42b56): fill_kobj_path: path = '/devices/virtual/net/syz_tun/queues/rx-0' [ 43.523948] kobject: 'rx-0' (000000008bf42b56): auto cleanup kobject_del [ 43.530876] kobject: 'rx-0' (000000008bf42b56): calling ktype release [ 43.537474] kobject: 'rx-0': free name [ 43.541481] kobject: 'tx-0' (00000000bbdcdbed): kobject_cleanup, parent 00000000f75c8bd3 [ 43.549924] kobject: 'tx-0' (00000000bbdcdbed): auto cleanup 'remove' event [ 43.557036] kobject: 'tx-0' (00000000bbdcdbed): kobject_uevent_env [ 43.564426] kobject: 'tx-0' (00000000bbdcdbed): fill_kobj_path: path = '/devices/virtual/net/syz_tun/queues/tx-0' [ 43.574933] kobject: 'tx-0' (00000000bbdcdbed): auto cleanup kobject_del [ 43.582080] kobject: 'tx-0' (00000000bbdcdbed): calling ktype release [ 43.588697] kobject: 'tx-0': free name [ 43.592684] kobject: 'queues' (00000000f75c8bd3): kobject_cleanup, parent (null) [ 43.601152] kobject: 'queues' (00000000f75c8bd3): calling ktype release [ 43.607905] kobject: 'queues' (00000000f75c8bd3): kset_release [ 43.613980] kobject: 'queues': free name [ 43.618302] kobject: 'syz_tun' (00000000ad4d7dba): kobject_uevent_env [ 43.625018] kobject: 'syz_tun' (00000000ad4d7dba): fill_kobj_path: path = '/devices/virtual/net/syz_tun' [ 43.669488] kobject: 'syz_tun' (00000000ad4d7dba): kobject_cleanup, parent (null) [ 43.678008] kobject: 'syz_tun' (00000000ad4d7dba): calling ktype release [ 43.684967] kobject: 'syz_tun': free name [ 43.741907] kobject: 'rx-0' (0000000017c19f65): kobject_cleanup, parent 000000003ca64aec [ 43.750356] kobject: 'rx-0' (0000000017c19f65): auto cleanup 'remove' event [ 43.758654] kobject: 'rx-0' (0000000017c19f65): kobject_uevent_env [ 43.765058] kobject: 'rx-0' (0000000017c19f65): kobject_uevent_env: uevent_suppress caused the event to drop! [ 43.775550] kobject: 'rx-0' (0000000017c19f65): auto cleanup kobject_del [ 43.782453] kobject: 'rx-0' (0000000017c19f65): calling ktype release [ 43.789027] kobject: 'rx-0': free name [ 43.793020] kobject: 'tx-0' (000000003e77b572): kobject_cleanup, parent 000000003ca64aec [ 43.801280] kobject: 'tx-0' (000000003e77b572): auto cleanup 'remove' event [ 43.808365] kobject: 'tx-0' (000000003e77b572): kobject_uevent_env [ 43.814780] kobject: 'tx-0' (000000003e77b572): kobject_uevent_env: uevent_suppress caused the event to drop! [ 43.824867] kobject: 'tx-0' (000000003e77b572): auto cleanup kobject_del [ 43.831822] kobject: 'tx-0' (000000003e77b572): calling ktype release [ 43.838397] kobject: 'tx-0': free name [