====================================================== WARNING: possible circular locking dependency detected 4.13.0-rc6-next-20170825+ #9 Not tainted ------------------------------------------------------ kworker/0:1/37 is trying to acquire lock: ((shepherd).work){+.+.}, at: [] process_one_work+0xb2c/0x1be0 kernel/workqueue.c:2094 but now in release context of a crosslock acquired at the following: ((complete)&rcu.completion){+.+.}, at: [] __synchronize_srcu+0x1b5/0x250 kernel/rcu/srcutree.c:898 which lock already depends on the new lock. the existing dependency chain (in reverse order) is: -> #2 ((complete)&rcu.completion){+.+.}: check_prevs_add kernel/locking/lockdep.c:2020 [inline] validate_chain kernel/locking/lockdep.c:2469 [inline] __lock_acquire+0x3286/0x4620 kernel/locking/lockdep.c:3498 lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002 complete_acquire include/linux/completion.h:39 [inline] __wait_for_common kernel/sched/completion.c:108 [inline] wait_for_common kernel/sched/completion.c:122 [inline] wait_for_completion+0xc8/0x770 kernel/sched/completion.c:143 __synchronize_srcu+0x1b5/0x250 kernel/rcu/srcutree.c:898 synchronize_srcu_expedited kernel/rcu/srcutree.c:923 [inline] synchronize_srcu+0x1a3/0x560 kernel/rcu/srcutree.c:974 quarantine_remove_cache+0xd7/0xf0 mm/kasan/quarantine.c:327 kasan_cache_shrink+0x9/0x10 mm/kasan/kasan.c:380 kmem_cache_shrink+0x15/0x30 mm/slab_common.c:857 acpi_os_purge_cache+0x15/0x20 drivers/acpi/osl.c:1560 acpi_purge_cached_objects+0x38/0xc9 drivers/acpi/acpica/utxface.c:271 acpi_initialize_objects+0xc5/0x112 drivers/acpi/acpica/utxfinit.c:302 acpi_bus_init drivers/acpi/bus.c:1131 [inline] acpi_init+0x23c/0x8e6 drivers/acpi/bus.c:1220 do_one_initcall+0x9e/0x330 init/main.c:826 do_initcall_level init/main.c:892 [inline] do_initcalls init/main.c:900 [inline] do_basic_setup init/main.c:918 [inline] kernel_init_freeable+0x469/0x521 init/main.c:1066 kernel_init+0x13/0x172 init/main.c:993 ret_from_fork+0x2a/0x40 arch/x86/entry/entry_64.S:431 -> #1 (cpu_hotplug_lock.rw_sem){++++}: check_prevs_add kernel/locking/lockdep.c:2020 [inline] validate_chain kernel/locking/lockdep.c:2469 [inline] __lock_acquire+0x3286/0x4620 kernel/locking/lockdep.c:3498 lock_acquire+0x1d5/0x580 kernel/locking/lockdep.c:4002 percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:35 [inline] percpu_down_read include/linux/percpu-rwsem.h:58 [inline] cpus_read_lock+0x42/0x90 kernel/cpu.c:218 get_online_cpus include/linux/cpu.h:126 [inline] vmstat_shepherd+0x3d/0x1b0 mm/vmstat.c:1707 process_one_work+0xbfd/0x1be0 kernel/workqueue.c:2098 worker_thread+0x223/0x1860 kernel/workqueue.c:2233 kthread+0x39c/0x470 kernel/kthread.c:231 ret_from_fork+0x2a/0x40 arch/x86/entry/entry_64.S:431 -> #0 ((shepherd).work){+.+.}: process_one_work+0xba5/0x1be0 kernel/workqueue.c:2095 worker_thread+0x223/0x1860 kernel/workqueue.c:2233 kthread+0x39c/0x470 kernel/kthread.c:231 ret_from_fork+0x2a/0x40 arch/x86/entry/entry_64.S:431 0xffffffffffffffff other info that might help us debug this: Chain exists of: (shepherd).work --> cpu_hotplug_lock.rw_sem --> (complete)&rcu.completion Possible unsafe locking scenario by crosslock: CPU0 CPU1 ---- ---- lock(cpu_hotplug_lock.rw_sem); lock((complete)&rcu.completion); lock((shepherd).work); unlock((complete)&rcu.completion); *** DEADLOCK *** 3 locks held by kworker/0:1/37: #0: ("events_power_efficient"){.+.+}, at: [] __write_once_size include/linux/compiler.h:305 [inline] #0: ("events_power_efficient"){.+.+}, at: [] atomic64_set arch/x86/include/asm/atomic64_64.h:33 [inline] #0: ("events_power_efficient"){.+.+}, at: [] atomic_long_set include/asm-generic/atomic-long.h:56 [inline] #0: ("events_power_efficient"){.+.+}, at: [] set_work_data kernel/workqueue.c:617 [inline] #0: ("events_power_efficient"){.+.+}, at: [] set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline] #0: ("events_power_efficient"){.+.+}, at: [] process_one_work+0xad4/0x1be0 kernel/workqueue.c:2090 #1: ((&(&sdp->work)->work)){+.+.}, at: [] process_one_work+0xb2c/0x1be0 kernel/workqueue.c:2094 #2: (&x->wait#5){....}, at: [] complete+0x18/0x80 kernel/sched/completion.c:34 stack backtrace: CPU: 0 PID: 37 Comm: kworker/0:1 Not tainted 4.13.0-rc6-next-20170825+ #9 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011 Workqueue: events_power_efficient srcu_invoke_callbacks Call Trace: __dump_stack lib/dump_stack.c:16 [inline] dump_stack+0x194/0x257 lib/dump_stack.c:52 print_circular_bug+0x503/0x710 kernel/locking/lockdep.c:1259 check_prev_add+0x865/0x1520 kernel/locking/lockdep.c:1894 commit_xhlock kernel/locking/lockdep.c:5002 [inline] commit_xhlocks kernel/locking/lockdep.c:5046 [inline] lock_commit_crosslock+0xe73/0x1d10 kernel/locking/lockdep.c:5085 complete_release_commit include/linux/completion.h:49 [inline] complete+0x24/0x80 kernel/sched/completion.c:39 wakeme_after_rcu+0xd/0x10 kernel/rcu/update.c:376 srcu_invoke_callbacks+0x280/0x4d0 kernel/rcu/srcutree.c:1161 process_one_work+0xbfd/0x1be0 kernel/workqueue.c:2098 worker_thread+0x223/0x1860 kernel/workqueue.c:2233 kthread+0x39c/0x470 kernel/kthread.c:231 ret_from_fork+0x2a/0x40 arch/x86/entry/entry_64.S:431 do_dccp_getsockopt: sockopt(PACKET_SIZE) is deprecated: fix your app SELinux: unrecognized netlink message: protocol=0 nlmsg_type=14516 sclass=netlink_route_socket pig=13920 comm=syz-executor7 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=14516 sclass=netlink_route_socket pig=13920 comm=syz-executor7 do_dccp_getsockopt: sockopt(PACKET_SIZE) is deprecated: fix your app audit: type=1326 audit(1503885448.758:53): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=13906 comm="syz-executor6" exe="/syz-executor6" sig=31 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0xffff0000 QAT: Invalid ioctl audit: type=1326 audit(1503885448.823:54): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=13906 comm="syz-executor6" exe="/syz-executor6" sig=31 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0xffff0000 QAT: Invalid ioctl SELinux: failure in selinux_parse_skb(), unable to parse packet SELinux: failure in selinux_parse_skb(), unable to parse packet SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=14153 comm=syz-executor6 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=14153 comm=syz-executor6 syz-executor2 (14185) used greatest stack depth: 14032 bytes left QAT: Invalid ioctl QAT: Invalid ioctl QAT: Invalid ioctl kvm [14284]: vcpu0, guest rIP: 0x9111 Hyper-V uhandled wrmsr: 0x40000020 data 0xf0047 sctp: [Deprecated]: syz-executor7 (pid 14315) Use of int in max_burst socket option. Use struct sctp_assoc_value instead sctp: [Deprecated]: syz-executor7 (pid 14330) Use of int in max_burst socket option. Use struct sctp_assoc_value instead selinux_nlmsg_perm: 4 callbacks suppressed SELinux: unrecognized netlink message: protocol=0 nlmsg_type=1636 sclass=netlink_route_socket pig=14348 comm=syz-executor2 IPv6: NLM_F_REPLACE set, but no existing node found! irq bypass consumer (token ffff88003d95f840) registration fails: -16 QAT: Invalid ioctl QAT: Invalid ioctl loop_reread_partitions: partition scan of loop0 (-\t@r9hxGQ:[il L*@R-Tr-x) failed (rc=-13) RDS: rds_bind could not find a transport for 63.255.128.0, load rds_tcp or rds_rdma? RDS: rds_bind could not find a transport for 63.255.128.0, load rds_tcp or rds_rdma? nla_parse: 18 callbacks suppressed netlink: 1 bytes leftover after parsing attributes in process `syz-executor5'. netlink: 1 bytes leftover after parsing attributes in process `syz-executor5'. kauditd_printk_skb: 2 callbacks suppressed audit: type=1326 audit(1503885451.772:57): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=14990 comm="syz-executor2" exe="/syz-executor2" sig=9 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0x0 audit: type=1326 audit(1503885451.853:58): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=14990 comm="syz-executor2" exe="/syz-executor2" sig=9 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0x0 netlink: 1 bytes leftover after parsing attributes in process `syz-executor1'. netlink: 1 bytes leftover after parsing attributes in process `syz-executor1'. netlink: 1 bytes leftover after parsing attributes in process `syz-executor1'. netlink: 1 bytes leftover after parsing attributes in process `syz-executor1'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor6'. netlink: 64 bytes leftover after parsing attributes in process `syz-executor7'. netlink: 3 bytes leftover after parsing attributes in process `syz-executor6'. ?: renamed from sit0 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=15157 comm=syz-executor7 sg_write: data in/out 524253/2 bytes for SCSI command 0x1-- guessing data in; program syz-executor1 not setting count and/or reply_len properly device  entered promiscuous mode device  left promiscuous mode 9pnet_virtio: no channels available for device ./file0 9pnet_virtio: no channels available for device ./file0 device syz5 entered promiscuous mode QAT: Invalid ioctl netlink: 1 bytes leftover after parsing attributes in process `syz-executor4'. QAT: Invalid ioctl kvm: pic: non byte read kvm: pic: non byte read kvm: pic: non byte read kvm: pic: non byte read kvm: pic: non byte read kvm: pic: non byte read kvm: pic: non byte read kvm: pic: non byte read kvm: pic: non byte read kvm: pic: non byte read kvm_hv_set_msr: 269 callbacks suppressed kvm [15386]: vcpu0, guest rIP: 0x9110 Hyper-V uhandled wrmsr: 0x4000008f data 0x4d1ba6600a9 kvm [15386]: vcpu0, guest rIP: 0x9110 Hyper-V uhandled wrmsr: 0x4000008e data 0x4d1ba6600a9 kvm [15386]: vcpu0, guest rIP: 0x9110 Hyper-V uhandled wrmsr: 0x4000008d data 0x4d1ba6600a9 kvm [15386]: vcpu0, guest rIP: 0x9110 Hyper-V uhandled wrmsr: 0x4000008c data 0x4d1ba6600a9 kvm [15386]: vcpu0, guest rIP: 0x9110 Hyper-V uhandled wrmsr: 0x4000008b data 0x4d1ba6600a9 kvm [15386]: vcpu0, guest rIP: 0x9110 Hyper-V uhandled wrmsr: 0x4000008a data 0x4d1ba6600a9 kvm [15386]: vcpu0, guest rIP: 0x9110 Hyper-V uhandled wrmsr: 0x40000089 data 0x4d1ba6600a9 kvm [15386]: vcpu0, guest rIP: 0x9110 Hyper-V uhandled wrmsr: 0x40000088 data 0x4d1ba6600a9 sg_write: data in/out 213971796/19 bytes for SCSI command 0x0-- guessing data in; program syz-executor7 not setting count and/or reply_len properly sg_write: data in/out 213971796/19 bytes for SCSI command 0x0-- guessing data in; program syz-executor7 not setting count and/or reply_len properly kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x4000008f kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x4000008e kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x4000008d kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x4000008c kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x4000008b kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x4000008a kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x40000089 kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x40000088 kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x40000087 kvm [15450]: vcpu0, guest rIP: 0x9135 Hyper-V unhandled rdmsr: 0x40000086 kvm [15450]: vcpu0, guest rIP: 0x9112 Hyper-V uhandled wrmsr: 0x40000023 data 0x66c900003b9a1043 kvm [15450]: vcpu0, guest rIP: 0x9112 Hyper-V uhandled wrmsr: 0x40000022 data 0x66c90000cb211043 sctp: [Deprecated]: syz-executor5 (pid 15533) Use of struct sctp_assoc_value in delayed_ack socket option. Use struct sctp_sack_info instead sctp: [Deprecated]: syz-executor5 (pid 15533) Use of struct sctp_assoc_value in delayed_ack socket option. Use struct sctp_sack_info instead audit: type=1326 audit(1503885454.228:59): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=15621 comm="syz-executor0" exe="/syz-executor0" sig=31 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0xffff0000 audit: type=1326 audit(1503885454.274:60): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=15621 comm="syz-executor0" exe="/syz-executor0" sig=31 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0xffff0000 audit: type=1326 audit(1503885454.294:61): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=15613 comm="syz-executor2" exe="/syz-executor2" sig=9 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0x0 audit: type=1326 audit(1503885454.345:62): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=15621 comm="syz-executor0" exe="/syz-executor0" sig=31 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0xffff0000 rpcbind: RPC call returned error 22 audit: type=1326 audit(1503885454.397:63): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=15613 comm="syz-executor2" exe="/syz-executor2" sig=9 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0x0 rfkill: input handler disabled rfkill: input handler enabled Can not set IPV6_FL_F_REFLECT if flowlabel_consistency sysctl is enable Can not set IPV6_FL_F_REFLECT if flowlabel_consistency sysctl is enable SELinux: unrecognized netlink message: protocol=0 nlmsg_type=1912 sclass=netlink_route_socket pig=16087 comm=syz-executor1 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=123 sclass=netlink_route_socket pig=16104 comm=syz-executor1 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=16104 comm=syz-executor1 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=123 sclass=netlink_route_socket pig=16104 comm=syz-executor1 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=16112 comm=syz-executor1 [drm:drm_mode_legacy_fb_format] *ERROR* bad bpp, assuming x8r8g8b8 pixel format [drm:drm_mode_legacy_fb_format] *ERROR* bad bpp, assuming x8r8g8b8 pixel format nla_parse: 24 callbacks suppressed netlink: 1 bytes leftover after parsing attributes in process `syz-executor1'. SELinux: unrecognized netlink message: protocol=0 nlmsg_type=1023 sclass=netlink_route_socket pig=16343 comm=syz-executor5 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=16357 comm=syz-executor6 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=16357 comm=syz-executor6 netlink: 3 bytes leftover after parsing attributes in process `syz-executor7'. netlink: 1 bytes leftover after parsing attributes in process `syz-executor7'. SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=16375 comm=syz-executor6 SELinux: unrecognized netlink message: protocol=0 nlmsg_type=0 sclass=netlink_route_socket pig=16381 comm=syz-executor6 netlink: 3 bytes leftover after parsing attributes in process `syz-executor7'. netlink: 1 bytes leftover after parsing attributes in process `syz-executor7'. IPv6: ADDRCONF(NETDEV_CHANGE): syz1: link becomes ready IPv6: ADDRCONF(NETDEV_CHANGE): syz1: link becomes ready audit: type=1326 audit(1503885457.477:64): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=16442 comm="syz-executor6" exe="/syz-executor6" sig=31 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0xffff0000 audit: type=1326 audit(1503885457.589:65): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=16442 comm="syz-executor6" exe="/syz-executor6" sig=31 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0xffff0000 device syz5 left promiscuous mode sock: sock_set_timeout: `syz-executor7' (pid 16525) tries to set negative timeout sock: sock_set_timeout: `syz-executor7' (pid 16529) tries to set negative timeout audit: type=1326 audit(1503885458.128:66): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=16555 comm="syz-executor2" exe="/syz-executor2" sig=9 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0x0 audit: type=1326 audit(1503885458.273:67): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=16555 comm="syz-executor2" exe="/syz-executor2" sig=9 arch=c000003e syscall=202 compat=0 ip=0x446749 code=0x0