Re: 4.13-rc7: WARNING at arch/x86/kvm/mmu.c:717 (and a crash thereafter)

From: Adam Borowski
Date: Mon Aug 28 2017 - 09:06:14 EST


On Mon, Aug 28, 2017 at 02:26:06PM +0200, Takashi Iwai wrote:
> I seem to get a kernel warning when running KVM on Dell desktop with
> IvyBridge like below. As you can see, a bad page BUG is triggered
> after that, too. The problem is not triggered always, but it happens
> occasionally.

See the thread starting with 20170820231302.s732zclznrqxwr46@xxxxxxxxxx

> I haven't seen this on 4.13-rc4 at all, and IIRC, it started happening
> since rc5. So this might be a regression at rc5. But, as it doesn't
> happen always, I can't be 100% sure about it, and it's quite difficult
> to bisect (the test case isn't reliable), unfortunately.

Same here -- it sometimes takes a few hours of trying to reproduce, which
makes proving the negative greatly unpleasant.

And all I've been able to tell so far is that the problem is between
4.13-rc4 and 4.13-rc5, just like you say.

> ===
>
> WARNING: CPU: 2 PID: 7188 at arch/x86/kvm/mmu.c:717 mmu_spte_clear_track_bits+0xe7/0x100 [kvm]
> CPU: 2 PID: 7188 Comm: qemu-system-x86 Not tainted 4.13.0-rc7-test+ #26
> Hardware name: Dell Inc. OptiPlex 9010/0M9KCM, BIOS A12 01/10/2013
> task: ffff997fdc1320c0 task.stack: ffffb9394cf70000
> RIP: 0010:mmu_spte_clear_track_bits+0xe7/0x100 [kvm]
> RSP: 0018:ffffb9394cf73ab8 EFLAGS: 00010246
> RAX: 0000000000000000 RBX: 400000010552cc77 RCX: dead0000000000ff
> RDX: 0000000000000000 RSI: ffff997f53659108 RDI: ffffe7c684154b00
> RBP: ffffb9394cf73ad0 R08: 0000000000000100 R09: 000000000000000c
> R10: ffff997fc2ba0008 R11: ffff997fc2ba0000 R12: 000000000010552c
> R13: ffff997edd0f0000 R14: ffff997f69c44348 R15: 0000000000000000
> FS: 0000000000000000(0000) GS:ffff9980de280000(0000) knlGS:0000000000000000
> CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 00007ffd57a77ff8 CR3: 0000000105704000 CR4: 00000000001426e0
> Call Trace:
> drop_spte+0x1a/0xb0 [kvm]
> mmu_page_zap_pte+0x9d/0xe0 [kvm]
> kvm_mmu_prepare_zap_page+0x56/0x300 [kvm]
> kvm_mmu_invalidate_zap_all_pages+0x10d/0x160 [kvm]
> kvm_arch_flush_shadow_all+0xe/0x10 [kvm]
> kvm_mmu_notifier_release+0x2c/0x40 [kvm]
> __mmu_notifier_release+0x44/0xc0
> exit_mmap+0x11e/0x130
> ? __switch_to+0x216/0x3f0
> ? __khugepaged_exit+0x114/0x120
> mmput+0x46/0x120
> do_exit+0x277/0xb10
> ? preempt_schedule_common+0x1f/0x30
> ? preempt_schedule+0x27/0x30
> ? ___preempt_schedule+0x16/0x18
> do_group_exit+0x43/0xb0
> get_signal+0x260/0x600
> ? get_futex_key+0x294/0x350
> do_signal+0x28/0x710
> ? recalc_sigpending+0x1b/0x50
> exit_to_usermode_loop+0x6e/0xc0
> syscall_return_slowpath+0x59/0x60
> entry_SYSCALL_64_fastpath+0xa7/0xa9
> RIP: 0033:0x7f95aab8f8ec
> RSP: 002b:00007f959c36c7e8 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
> RAX: fffffffffffffe00 RBX: 000056156743b010 RCX: 00007f95aab8f8ec
> RDX: 0000000000000002 RSI: 0000000000000080 RDI: 000056156626c080
> RBP: 0000000000000000 R08: 000056156626c080 R09: 000056156626c000
> R10: 0000000000000000 R11: 0000000000000246 R12: 000000000000000f
> R13: 000056156626c080 R14: 0000000000000000 R15: 000056156743b03c
> Code: 4f 04 00 48 85 c0 75 1c 4c 89 e7 e8 54 4d fe ff 48 8b 05 9d 4f 04 00 48 85 c0 74 c1 48 85 c3 0f 95 c3 eb bf 48 85 c3 74 e7 eb dd <0f> ff eb 9e 4c 89 e7 e8 2d 4d fe ff eb a4 90 66 2e 0f 1f 84 00
> ---[ end trace dd04b99ed8787467 ]---

The first WARN is always the above. But the rest seems to be totally random
-- a nasty case of fandango on core whose results range from harmless
through crash to massive data loss (just guess what would happen if some
idiot picked balancing the disk as a test load -- no one would be that
stupid, right? At least an incomplete idiot has checksums and backups).

> BUG: Bad page state in process python pfn:10552c
> page:ffffe7c684154b00 count:0 mapcount:0 mapping: (null) index:0x1
> flags: 0x2ffff800000014(referenced|dirty)
> raw: 002ffff800000014 0000000000000000 0000000000000001 00000000ffffffff
> raw: dead000000000100 dead000000000200 0000000000000000 0000000000000000
> page dumped because: PAGE_FLAGS_CHECK_AT_PREP flag set
> bad because of flags: 0x14(referenced|dirty)
> CPU: 7 PID: 9171 Comm: python Tainted: G W 4.13.0-rc7-test+ #26
> Hardware name: Dell Inc. OptiPlex 9010/0M9KCM, BIOS A12 01/10/2013
> Call Trace:
> dump_stack+0x63/0x8d
> bad_page+0xcb/0x120
> check_new_page_bad+0x67/0x80
> get_page_from_freelist+0x9d1/0xb00
> __alloc_pages_nodemask+0xce/0x230
> alloc_pages_vma+0x88/0x1f0
> __handle_mm_fault+0x7c9/0x1000
> handle_mm_fault+0xde/0x1e0
> __do_page_fault+0x23b/0x4f0
> do_page_fault+0x22/0x30
> page_fault+0x28/0x30
> RIP: 0033:0x7f4a2761c2c3
> RSP: 002b:00007fffbe1b2988 EFLAGS: 00010206
> RAX: 0000557a87b725b0 RBX: 00000000000000e8 RCX: 0000557a87b75000
> RDX: 0000557a87b78a00 RSI: 00000000000000ba RDI: 0000557a87b725b0
> RBP: 00007f4a279362a8 R08: 0000000000000003 R09: 000000000000007c
> R10: 00000000000001c1 R11: 0000000000000077 R12: 00007f4a27935b38
> R13: 0000000000006460 R14: 0000557a87b725b0 R15: 00007f4a27935ae0
> Disabling lock debugging due to kernel taint
>

--
âââââââ
âââââââ Vat kind uf sufficiently advanced technology iz dis!?
âââââââ -- Genghis Ht'rok'din
âââââââ