kvm 4.10 merge grumbles wrt suspicious RCU usage , might_sleep() and sched: do not call blocking ops when !TASK_RUNNING

From: Mike Galbraith
Date: Wed Dec 14 2016 - 22:36:20 EST


Grumpy master.today, w. tune for maximum bloat PREEMPT config.

[ 101.898909] ===============================
[ 101.898910] [ INFO: suspicious RCU usage. ]
[ 101.898912] 4.10.0-preempt #1 Tainted: G E
[ 101.898913] -------------------------------
[ 101.898914] ./include/linux/kvm_host.h:541 suspicious rcu_dereference_check() usage!
[ 101.898914] other info that might help us debug this:
[ 101.898916] rcu_scheduler_active = 1, debug_locks = 0
[ 101.898917] 2 locks held by qemu-system-x86/4265:
[ 101.898918] #0: (&vcpu->mutex){+.+.+.}, at: [<ffffffffa08d289c>] vcpu_load+0x1c/0x80 [kvm]
[ 101.898941] #1: (&rq->lock){-.-.-.}, at: [<ffffffff8172fcc0>] __schedule+0xb0/0xaa0
[ 101.898945] stack backtrace:
[ 101.898946] CPU: 2 PID: 4265 Comm: qemu-system-x86 Tainted: G E 4.10.0-preempt #1
[ 101.898947] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
[ 101.898948] Call Trace:
[ 101.898952] dump_stack+0x85/0xc9
[ 101.898954] lockdep_rcu_suspicious+0xe7/0x120
[ 101.898960] kvm_write_guest_offset_cached+0x145/0x180 [kvm]
[ 101.898969] kvm_arch_vcpu_put+0x3e/0x70 [kvm]
[ 101.898974] kvm_sched_out+0x2e/0x30 [kvm]
[ 101.898976] __schedule+0x398/0xaa0
[ 101.898977] preempt_schedule_common+0x34/0x47
[ 101.898978] preempt_schedule+0x26/0x30
[ 101.898980] ___preempt_schedule+0x16/0x18
[ 101.898988] vcpu_enter_guest+0x1598/0x1690 [kvm]
[ 101.898995] ? vcpu_enter_guest+0xaed/0x1690 [kvm]
[ 101.899003] ? kvm_arch_vcpu_ioctl_run+0xb8/0x500 [kvm]
[ 101.899010] ? kvm_arch_can_inject_async_page_present+0x43/0x50 [kvm]
[ 101.899017] ? kvm_check_async_pf_completion+0x30/0x110 [kvm]
[ 101.899024] kvm_arch_vcpu_ioctl_run+0xfe/0x500 [kvm]
[ 101.899030] ? kvm_arch_vcpu_ioctl_run+0xb8/0x500 [kvm]
[ 101.899036] kvm_vcpu_ioctl+0x370/0x760 [kvm]
[ 101.899038] ? __fget+0xf8/0x210
[ 101.899039] ? __lock_is_held+0x49/0x70
[ 101.899041] do_vfs_ioctl+0x96/0x710
[ 101.899042] ? __fget+0x115/0x210
[ 101.899044] ? __fget+0x5/0x210
[ 101.899045] SyS_ioctl+0x79/0x90
[ 101.899047] entry_SYSCALL_64_fastpath+0x23/0xc6
[ 101.899048] RIP: 0033:0x7fd3680efbc7
[ 101.899049] RSP: 002b:00007fd352ca69b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 101.899051] RAX: ffffffffffffffda RBX: 000055b9fd0c2450 RCX: 00007fd3680efbc7
[ 101.899051] RDX: 0000000000000000 RSI: 000000000000ae80 RDI: 0000000000000011
[ 101.899052] RBP: 00007fd36eb5f000 R08: 0000000000000000 R09: 000000000000ffff
[ 101.899053] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
[ 101.899054] R13: 0000000000000004 R14: 0000000000000001 R15: 000055b9fbbf42a0
[ 101.899056] BUG: sleeping function called from invalid context at ./arch/x86/include/asm/uaccess_64.h:181
[ 101.899057] in_atomic(): 1, irqs_disabled(): 1, pid: 4265, name: qemu-system-x86
[ 101.899057] INFO: lockdep is turned off.
[ 101.899058] irq event stamp: 7522870
[ 101.899065] hardirqs last enabled at (7522869): [<ffffffffa08eccd7>] vcpu_enter_guest+0xa97/0x1690 [kvm]
[ 101.899067] hardirqs last disabled at (7522870): [<ffffffff8172fcac>] __schedule+0x9c/0xaa0
[ 101.899069] softirqs last enabled at (7522868): [<ffffffff8173c17a>] __do_softirq+0x1ea/0x4c6
[ 101.899071] softirqs last disabled at (7522857): [<ffffffff81084245>] irq_exit+0xd5/0xe0
[ 101.899071] Preemption disabled at:
[ 101.899072] [<ffffffff81730963>] preempt_schedule_common+0x2a/0x47
[ 101.899074] CPU: 2 PID: 4265 Comm: qemu-system-x86 Tainted: G E 4.10.0-preempt #1
[ 101.899075] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
[ 101.899075] Call Trace:
[ 101.899077] dump_stack+0x85/0xc9
[ 101.899078] ___might_sleep+0x17b/0x270
[ 101.899080] __might_sleep+0x4a/0x90
[ 101.899082] __might_fault+0x39/0xa0
[ 101.899088] kvm_write_guest_offset_cached+0xa6/0x180 [kvm]
[ 101.899095] kvm_arch_vcpu_put+0x3e/0x70 [kvm]
[ 101.899101] kvm_sched_out+0x2e/0x30 [kvm]
[ 101.899102] __schedule+0x398/0xaa0
[ 101.899103] preempt_schedule_common+0x34/0x47
[ 101.899104] preempt_schedule+0x26/0x30
[ 101.899106] ___preempt_schedule+0x16/0x18
[ 101.899112] vcpu_enter_guest+0x1598/0x1690 [kvm]
[ 101.899119] ? vcpu_enter_guest+0xaed/0x1690 [kvm]
[ 101.899125] ? kvm_arch_vcpu_ioctl_run+0xb8/0x500 [kvm]
[ 101.899132] ? kvm_arch_can_inject_async_page_present+0x43/0x50 [kvm]
[ 101.899139] ? kvm_check_async_pf_completion+0x30/0x110 [kvm]
[ 101.899145] kvm_arch_vcpu_ioctl_run+0xfe/0x500 [kvm]
[ 101.899151] ? kvm_arch_vcpu_ioctl_run+0xb8/0x500 [kvm]
[ 101.899157] kvm_vcpu_ioctl+0x370/0x760 [kvm]
[ 101.899159] ? __fget+0xf8/0x210
[ 101.899160] ? __lock_is_held+0x49/0x70
[ 101.899161] do_vfs_ioctl+0x96/0x710
[ 101.899163] ? __fget+0x115/0x210
[ 101.899164] ? __fget+0x5/0x210
[ 101.899165] SyS_ioctl+0x79/0x90
[ 101.899167] entry_SYSCALL_64_fastpath+0x23/0xc6
[ 101.899168] RIP: 0033:0x7fd3680efbc7
[ 101.899169] RSP: 002b:00007fd352ca69b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 101.899170] RAX: ffffffffffffffda RBX: 000055b9fd0c2450 RCX: 00007fd3680efbc7
[ 101.899171] RDX: 0000000000000000 RSI: 000000000000ae80 RDI: 0000000000000011
[ 101.899172] RBP: 00007fd36eb5f000 R08: 0000000000000000 R09: 000000000000ffff
[ 101.899172] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
[ 101.899173] R13: 0000000000000004 R14: 0000000000000001 R15: 000055b9fbbf42a0
[ 101.959132] ------------[ cut here ]------------
[ 101.959140] WARNING: CPU: 2 PID: 4265 at kernel/sched/core.c:7840 __might_sleep+0x80/0x90
[ 101.959144] do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffff810d0ed0>] prepare_to_swait+0x40/0xd0
[ 101.959146] Modules linked in: tun(E) ebtable_filter(E) ebtables(E) fuse(E) nf_log_ipv6(E) xt_pkttype(E) xt_physdev(E) br_netfilter(E) nf_log_ipv4(E) nf_log_common(E) xt_LOG(E) xt_limit(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) ip6t_REJECT(E) xt_tcpudp(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ip6table_raw(E) ipt_REJECT(E) iptable_raw(E) xt_CT(E) iptable_filter(E) ip6table_mangle(E) nf_conntrack_netbios_ns(E) nf_conntrack_broadcast(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E) ip_tables(E) xt_conntrack(E) nf_conntrack(E) ip6table_filter(E) ip6_tables(E) x_tables(E) intel_rapl(E) nls_iso8859_1(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) nls_cp437(E) coretemp(E) kvm_intel(E) nfsd(E) kvm(E) auth_rpcgss(E) nfs_acl(E) irqbypass(E) snd_hda_codec_realtek(E) lockd(E) grace(E) crct10dif_pclmul(E)
[ 101.959186] crc32_pclmul(E) crc32c_intel(E) ghash_clmulni_intel(E) pl2303(E) usbserial(E) snd_hda_codec_hdmi(E) snd_hda_codec_generic(E) sunrpc(E) pcbc(E) snd_hda_intel(E) snd_hda_codec(E) snd_hda_core(E) snd_hwdep(E) aesni_intel(E) aes_x86_64(E) snd_pcm(E) i2c_i801(E) crypto_simd(E) snd_timer(E) snd(E) usblp(E) glue_helper(E) joydev(E) iTCO_wdt(E) iTCO_vendor_support(E) mei_me(E) lpc_ich(E) mei(E) mfd_core(E) shpchp(E) i2c_smbus(E) cryptd(E) intel_smartconnect(E) serio_raw(E) soundcore(E) battery(E) thermal(E) pcspkr(E) tpm_infineon(E) fan(E) efivarfs(E) hid_logitech_hidpp(E) hid_logitech_dj(E) hid_generic(E) usbhid(E) ehci_pci(E) nouveau(E) ehci_hcd(E) mxm_wmi(E) wmi(E) i2c_algo_bit(E) drm_kms_helper(E) syscopyarea(E) sysfillrect(E) ahci(E) xhci_pci(E) sysimgblt(E) r8169(E) fb_sys_fops(E) mii(E)
[ 101.959230] libahci(E) xhci_hcd(E) ttm(E) libata(E) usbcore(E) drm(E) fjes(E) video(E) button(E) af_packet(E) sd_mod(E) vfat(E) fat(E) ext4(E) crc16(E) jbd2(E) mbcache(E) dm_mod(E) loop(E) sg(E) scsi_mod(E) autofs4(E)
[ 101.959248] CPU: 2 PID: 4265 Comm: qemu-system-x86 Tainted: G W E 4.10.0-preempt #1
[ 101.959249] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
[ 101.959251] Call Trace:
[ 101.959255] dump_stack+0x85/0xc9
[ 101.959258] __warn+0xd1/0xf0
[ 101.959261] warn_slowpath_fmt+0x4f/0x60
[ 101.959263] ? prepare_to_swait+0x40/0xd0
[ 101.959265] ? prepare_to_swait+0x40/0xd0
[ 101.959267] __might_sleep+0x80/0x90
[ 101.959269] __might_fault+0x39/0xa0
[ 101.959292] kvm_write_guest_offset_cached+0xa6/0x180 [kvm]
[ 101.959304] kvm_arch_vcpu_put+0x3e/0x70 [kvm]
[ 101.959312] kvm_sched_out+0x2e/0x30 [kvm]
[ 101.959315] __schedule+0x398/0xaa0
[ 101.959327] ? kvm_apic_has_interrupt+0x23/0xc0 [kvm]
[ 101.959329] schedule+0x40/0x90
[ 101.959338] kvm_vcpu_block+0x7b/0x520 [kvm]
[ 101.959349] kvm_arch_vcpu_ioctl_run+0x1d0/0x500 [kvm]
[ 101.959359] ? kvm_arch_vcpu_ioctl_run+0xb8/0x500 [kvm]
[ 101.959368] kvm_vcpu_ioctl+0x370/0x760 [kvm]
[ 101.959370] ? __fget+0x5/0x210
[ 101.959373] do_vfs_ioctl+0x96/0x710
[ 101.959375] ? __fget+0x115/0x210
[ 101.959376] ? __fget+0x5/0x210
[ 101.959379] SyS_ioctl+0x79/0x90
[ 101.959381] entry_SYSCALL_64_fastpath+0x23/0xc6
[ 101.959383] RIP: 0033:0x7fd3680efbc7
[ 101.959384] RSP: 002b:00007fd352ca69b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 101.959386] RAX: ffffffffffffffda RBX: 000055b9fd0c2450 RCX: 00007fd3680efbc7
[ 101.959388] RDX: 0000000000000000 RSI: 000000000000ae80 RDI: 0000000000000011
[ 101.959389] RBP: 00007fd36eb5f000 R08: 0000000000000000 R09: 00000000000000ff
[ 101.959390] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
[ 101.959392] R13: 0000000000000001 R14: 0000000000000001 R15: 000055b9fbbf42a0
[ 101.959394] ---[ end trace 2152da2d0234c6fc ]---
...