Bug 1039469

Summary: [whql][vioser]win2k12 guest stuck at reboot stage when running "Multiple processor group device test" job
Product: Red Hat Enterprise Linux 7 Reporter: Mike Cao <bcao>
Component: qemu-kvmAssignee: Yvugenfi <yvugenfi>
Status: CLOSED CANTFIX QA Contact: Virtualization Bugs <virt-bugs>
Severity: high Docs Contact:
Priority: high    
Version: 7.0CC: ailan, dfleytma, hhuang, huding, jkurik, juzhang, knoel, lijin, michen, pbonzini, rbalakri, tdosek, virt-bugs, virt-maint, yvugenfi
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-04-18 08:07:09 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Mike Cao 2013-12-09 08:22:43 UTC 
Description of problem:


Version-Release number of selected component (if applicable):
virtio-win-prewhql74
2.6.32-420.el6.x86_64
qemu-kvm-rhev-0.12.1.2-2.405.el6.x86_64
seabios-0.6.1.2-28.el6

How reproducible:
5/6

Steps to Reproduce:
1.Start VM with virtio-serial
CLI:/usr/libexec/qemu-kvm -M rhel6.5.0 -m 6G -smp 4 -cpu cpu64-rhel6,+x2apic -drive file=win2012-build74-vioserial.raw,format=raw,if=none,id=drive-ide0-0-0,werror=stop,rerror=stop,cache=none -device ide-drive,drive=drive-ide0-0-0,id=ide0-0-0,bootindex=1 -netdev tap,id=hostnet0,script=/etc/qemu-ifup -device e1000,netdev=hostnet0,mac=00:52:22:15:72:18,id=net0 -uuid ea3de0e6-8e06-4cbc-a639-1e334c6249aa -rtc-td-hack -no-kvm-pit-reinjection -chardev socket,id=111a,path=/tmp/monitor-win2k12-serialcc,server,nowait -mon chardev=111a,mode=readline -name win2k12-serial -vnc :11 -vga cirrus -device virtio-serial-pci,id=virtio-serial0,bus=pci.0 -chardev pty,id=channel0 -device virtserialport,chardev=channel0,name=org.linux-kvm.port.0,bus=virtio-serial0.0 -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0 -monitor stdio
2.running job1865-Multiple processor group device test job


Actual results:
Guest stuck at reboot stage in "reboot" sub-job stage

Expected results:
guest should start successfully

Additional info:
1.I kept (qemu)system_reset for plenty of time ,at last the VM can boot up successfully then the job show pass
2.screenshot and nmi crash dump will be provided
Comment 5 Mike Cao 2014-02-11 03:26:35 UTC 
(In reply to Miki Mishael from comment #3)
> Hi Mike,
> 
> This looks like e1000 problem we saw before with Windows 8 guests.
> Please try to reproduce with realtek network adapter instead of e1000.
> 
> Thanks,
> Miki

Sorry for the late response 

I can reproduce this issue without e1000 nic attached 

CLI:
/usr/libexec/qemu-kvm -M rhel6.5.0 -m 2G -smp 4,cores=4 -cpu cpu64-rhel6,+x2apic -usb -device usb-tablet -drive file=/home/win2012-vioserial-74,if=none,id=drive-ide0-0-0,werror=stop,rerror=stop,cache=none -device ide-drive,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0 -netdev tap,sndbuf=0,id=hostnet2,script=/etc/qemu-ifup,downscript=no -device rtl8139,netdev=hostnet2,mac=00:52:15:23:42:32,bus=pci.0,addr=0x6 -uuid d3389d2a-1980-4daf-b19f-8af7ca66b6a6 -no-kvm-pit-reinjection -chardev socket,id=111a,path=/tmp/monitor-win8-32-vioserial,server,nowait -mon chardev=111a,mode=readline -vnc :1 -vga cirrus -name win2k8R2-balloon-74 -rtc base=localtime,clock=host,driftfix=slew -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0 -monitor stdio -device virtio-serial-pci,id=serial0 -chardev socket,path=/tmp/chardev0,server,nowait,id=chardev0 -cdrom /home/en_windows_server_2012_x64_dvd_915478.iso -device virtserialport,chardev=chardev0,bus=serial0.0
Comment 6 lijin 2014-03-03 08:28:18 UTC 
win2012 guest hit the same issue when run viostor whql job "Multiple processor gruop device test"

package info:
virtio-win-1.6.8-4.el7.noarch
kernel-3.10.0-84.el7.x86_64
qemu-kvm-rhev-1.5.3-45.el7.x86_64
seabios-1.7.2.2-11.el7.x86_64

qemu-kvm command:
/usr/libexec/qemu-kvm -M pc -m 4G -smp 8,sockets=2,cores=4,threads=1 -cpu Nehalem -usb -device usb-tablet -drive file=gluster://10.66.73.33:24007/gv0/win2012.raw,format=raw,if=none,id=drive-ide0-0-0,werror=stop,rerror=stop,cache=none -device virtio-blk-pci,drive=drive-ide0-0-0,id=ide0-0-0,bootindex=1 -netdev tap,id=hostnet0,script=/etc/qemu-ifup1 -device e1000,netdev=hostnet0,mac=00:52:4f:80:70:40,id=net0 -uuid 0bef6a62-4a4b-4a03-8a8f-5dde92cb5529 -rtc-td-hack -no-kvm-pit-reinjection -chardev socket,id=a111,path=/tmp/monitor-win2012-serial,server,nowait -mon chardev=a111,mode=readline -name win2012-blk-glusterfs -drive file=gluster://10.66.73.33:24007/gv0/win2012-data.raw,if=none,media=disk,format=raw,rerror=stop,werror=stop,cache=none,aio=native,id=blk-disk1,serial=win8.1-32-blk -device virtio-blk-pci,drive=blk-disk1,id=disk1 -vnc :2 -vga cirrus -monitor stdio -cdrom /usr/share/virtio-win/virtio-win.iso -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0
Comment 15 Ronen Hod 2014-11-27 16:51:54 UTC 
Too late. Deferring again.
Seems like it can be reproduced regardless of the use of virtio.
Yan, after you provide a Windows side analysis, then this bug can be assigned to a qemu person.
Comment 16 Dmitry Fleytman 2015-02-01 13:08:12 UTC 
Also easily reproducible by running from command line:

bcdedit /set groupaware on
bcdedit /set groupsize 2

and reboot.
Comment 17 Dmitry Fleytman 2015-02-09 09:11:22 UTC 
Call stacks on guest after stuck:

6: kd> !running -ti

System Processors:  (0000000000000003) (0000000000000003) (0000000000000003) (0000000000000003) (0000000000000003) (0000000000000003) (0000000000000003) (0000000000000003)
  Idle Processors:  (0000000000000000) (0000000000000003) (0000000000000003) (0000000000000002) (0000000000000003) (0000000000000003) (0000000000000000) (0000000000000003)

       Prcbs             Current         (pri) Next            (pri) Idle
  0    fffff8006cd15180  fffffa8000e7d040 (12)                       fffff8006cd6f880  ................

Child-SP          RetAddr           Call Site
fffff800`6be22c08 fffff800`6d1948de nt!KeBugCheckEx
fffff800`6be22c10 fffff800`6cb78c09 hal!HalBugCheckSystem+0x9a
fffff800`6be22c50 fffff800`6d195204 nt!WheaReportHwError+0x249
fffff800`6be22cb0 fffff800`6cbf37a7 hal!HalHandleNMI+0x150
fffff800`6be22ce0 fffff800`6ca96d02 nt! ?? ::FNODOBFM::`string'+0x13d6d
fffff800`6be22d30 fffff800`6ca96b73 nt!KxNmiInterrupt+0x82
fffff800`6be22e70 fffff800`6cacd0cb nt!KiNmiInterrupt+0x173
fffff880`035cc7c0 fffff800`6cb07e0c nt!KeFlushMultipleRangeTb+0x3c0
fffff880`035cc9c0 fffff800`6cba570c nt!MiFlushPteList+0x2c
fffff880`035cc9f0 fffff800`6cc8f7dd nt!MmFreeSpecialPool+0x2ec
fffff880`035ccb30 fffff880`01fe9079 nt!ExFreePool+0x6d8
fffff880`035ccc10 fffff800`6ca8545b tdx!TdxProviderReadyWorkItemRoutine+0x59
fffff880`035ccc50 fffff800`6cad2391 nt!IopProcessWorkItem+0x5f
fffff880`035cccc0 fffff800`6ca41521 nt!ExpWorkerThread+0x142
fffff880`035ccd50 fffff800`6ca7fdd6 nt!PspSystemThreadStartup+0x59
fffff880`035ccda0 00000000`00000000 nt!KiStartSystemThread+0x16

  1    fffff88002c15180  fffffa8000e79040 (12)                       fffff88002c21140  ................

Child-SP          RetAddr           Call Site
fffff880`03714d50 fffff800`6cb07e0c nt!KeFlushMultipleRangeTb+0x3c0
fffff880`03714f50 fffff800`6cba570c nt!MiFlushPteList+0x2c
fffff880`03714f80 fffff800`6cc8f7dd nt!MmFreeSpecialPool+0x2ec
fffff880`037150c0 fffff800`6d0658e4 nt!ExFreePool+0x6d8
fffff880`037151a0 fffff800`6d05cfac nt!VfIoFreeIrp+0x174
fffff880`03715250 fffff800`6cad132a nt!IovFreeIrpPrivate+0x5c
fffff880`03715290 fffff800`6d05cf20 nt!IopfCompleteRequest+0x61a
fffff880`03715370 fffff880`018cce3d nt!IovCompleteRequest+0x1b0
fffff880`03715440 fffff880`018cd45b Ntfs!NtfsCommonRead+0x1b6e
fffff880`03715600 fffff800`6d05cd26 Ntfs!NtfsFsdRead+0x1db
fffff880`03715840 fffff880`00ee50ee nt!IovCallDriver+0x3e6
fffff880`03715890 fffff800`6d05cd26 fltmgr!FltpDispatch+0xee
fffff880`037158f0 fffff800`6ca8c27a nt!IovCallDriver+0x3e6
fffff880`03715940 fffff800`6cdf6ba8 nt!IoPageRead+0x22a
fffff880`037159a0 fffff800`6ce881dc nt!MiCreateImageFileMap+0x444
fffff880`03715b70 fffff800`6ce84900 nt!MiCreateNewSection+0x10c
fffff880`03715c70 fffff800`6ce96f30 nt!MiCreateSection+0x88c
fffff880`03715e90 fffff800`6ca99053 nt!NtCreateSection+0x1af
fffff880`03715f20 fffff800`6ca9e230 nt!KiSystemServiceCopyEnd+0x13
fffff880`03716128 fffff800`6cea53d8 nt!KiServiceLinkage
fffff880`03716130 fffff800`6ceb10ca nt!MiCreateSectionForDriver+0xe0
fffff880`037161e0 fffff800`6ceb0a58 nt!MiObtainSectionForDriver+0x8e
fffff880`03716230 fffff800`6ceb143e nt!MmLoadSystemImage+0x120
fffff880`03716340 fffff800`6ceab79c nt!IopLoadDriver+0x2ca
fffff880`03716610 fffff800`6cea9fb6 nt!PipCallDriverAddDeviceQueryRoutine+0x22c
fffff880`03716730 fffff800`6cea7bc0 nt!PnpCallDriverQueryServiceHelper+0x13e
fffff880`037167b0 fffff800`6cea811e nt!PipCallDriverAddDevice+0x400
fffff880`03716940 fffff800`6cf1bc07 nt!PipProcessDevNodeTree+0x1ca
fffff880`03716bc0 fffff800`6cb2581f nt!PiProcessStartSystemDevices+0x87
fffff880`03716c10 fffff800`6cad2391 nt!PnpDeviceActionWorker+0x363
fffff880`03716cc0 fffff800`6ca41521 nt!ExpWorkerThread+0x142
fffff880`03716d50 fffff800`6ca7fdd6 nt!PspSystemThreadStartup+0x59
fffff880`03716da0 00000000`00000000 nt!KiStartSystemThread+0x16

  2    fffff88002c87180  fffff88002c93140 ( 0)                       fffff88002c93140  ................

Child-SP          RetAddr           Call Site
00000000`00000000 00000000`00000000 0x0

  3    fffff88002cf9180  fffff88002d05140 ( 0)                       fffff88002d05140  ................

Child-SP          RetAddr           Call Site
fffff880`02d22a08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`02d22a10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`02d22a40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`02d22c60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`02d22da0 00000000`00000000 nt!KiIdleLoop+0x2c

  4    fffff88002d6b180  fffff88002d77140 ( 0)                       fffff88002d77140  ................

Child-SP          RetAddr           Call Site
fffff880`02d94a08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`02d94a10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`02d94a40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`02d94c60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`02d94da0 00000000`00000000 nt!KiIdleLoop+0x2c

  5    fffff88002ddd180  fffff88002de9140 ( 0)                       fffff88002de9140  ................

Child-SP          RetAddr           Call Site
fffff880`02e06a08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`02e06a10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`02e06a40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`02e06c60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`02e06da0 00000000`00000000 nt!KiIdleLoop+0x2c

  6    fffff88002e4f180  fffffa8000e91b00 (17)                       fffff88002e5b140  ................

Child-SP          RetAddr           Call Site
fffff880`03b40700 fffff800`6cacd10f nt!KxFlushEntireTb+0xf0
fffff880`03b40750 fffff800`6cb07e0c nt!KeFlushMultipleRangeTb+0x401
fffff880`03b40950 fffff800`6cb20ae2 nt!MiFlushPteList+0x2c
fffff880`03b40980 fffff800`6cb20ec3 nt!MiReturnSystemVa+0x29e
fffff880`03b40a30 fffff800`6caff4da nt!MiReturnSystemPtes+0x93
fffff880`03b40b10 fffff800`6cacbb26 nt!MiReplenishBitMap+0x27e
fffff880`03b40c30 fffff800`6cacc3ae nt!MiEmptyPteBins+0xc6
fffff880`03b40c80 fffff800`6cacc9e5 nt!MiAdjustPteBins+0x12
fffff880`03b40cb0 fffff800`6cacc559 nt!MmWorkingSetManager+0x45
fffff880`03b40ce0 fffff800`6ca41521 nt!KeBalanceSetManager+0xd9
fffff880`03b40d50 fffff800`6ca7fdd6 nt!PspSystemThreadStartup+0x59
fffff880`03b40da0 00000000`00000000 nt!KiStartSystemThread+0x16

  7    fffff88002ec1180  fffff88002ecd140 ( 0)                       fffff88002ecd140  ................

Child-SP          RetAddr           Call Site
fffff880`02eeaa08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`02eeaa10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`02eeaa40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`02eeac60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`02eeada0 00000000`00000000 nt!KiIdleLoop+0x2c

  8    fffff88002f33180  fffff88002f3f140 ( 0)                       fffff88002f3f140  ................

Child-SP          RetAddr           Call Site
fffff880`02f5ca08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`02f5ca10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`02f5ca40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`02f5cc60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`02f5cda0 00000000`00000000 nt!KiIdleLoop+0x2c

  9    fffff88002fa5180  fffff88002fb1140 ( 0)                       fffff88002fb1140  ................

Child-SP          RetAddr           Call Site
fffff880`02fcea08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`02fcea10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`02fcea40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`02fcec60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`02fceda0 00000000`00000000 nt!KiIdleLoop+0x2c

 10    fffff88002fd7180  fffff88002fe3140 ( 0)                       fffff88002fe3140  ................

Child-SP          RetAddr           Call Site
fffff880`03046a08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`03046a10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`03046a40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`03046c60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`03046da0 00000000`00000000 nt!KiIdleLoop+0x2c

 11    fffff8800308f180  fffff8800309b140 ( 0)                       fffff8800309b140  ................

Child-SP          RetAddr           Call Site
fffff880`030b8a08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`030b8a10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`030b8a40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`030b8c60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`030b8da0 00000000`00000000 nt!KiIdleLoop+0x2c

 12    fffff88003101180  fffff8800310d140 ( 0) fffffa8000ec1b00 ( 8) fffff8800310d140  ................

Child-SP          RetAddr           Call Site
fffff880`0312ab00 fffff800`6d186e6d nt!KeGetNextTimerExpirationDueTime+0x27d
fffff880`0312ab50 fffff800`6cb712e2 hal!HalpTimerGetNextTickDuration+0x89
fffff880`0312ab90 fffff800`6cbb04a1 nt!PpmIdleEvaluateConstraints+0x152
fffff880`0312ac00 fffff800`6cac72e4 nt!PpmIdlePrepare+0x69
fffff880`0312ac60 fffff800`6cac554c nt!PoIdle+0x104
fffff880`0312ada0 00000000`00000000 nt!KiIdleLoop+0x2c

 13    fffff88003173180  fffffa8000e7eb00 ( 8)                       fffff8800317f140  ................

Child-SP          RetAddr           Call Site
fffff880`039e1760 fffff800`6cb07e0c nt!KeFlushMultipleRangeTb+0x3be
fffff880`039e1960 fffff800`6cb0846b nt!MiFlushPteList+0x2c
fffff880`039e1990 fffff800`6cb2f473 nt!MiFreeWsleList+0x4db
fffff880`039e1bb0 fffff800`6cb2f31b nt!MiEmptyWorkingSetHelper+0xe7
fffff880`039e1be0 fffff800`6cba2ac6 nt!MiEmptyWorkingSet+0xcb
fffff880`039e1c90 fffff800`6d05d0fa nt!MiTrimAllSystemPagableMemory+0x266
fffff880`039e1ce0 fffff800`6d06dc25 nt!MmVerifierTrimMemory+0xca
fffff880`039e1d10 fffff800`6ca41521 nt!ViKeTrimWorkerThreadRoutine+0x29
fffff880`039e1d50 fffff800`6ca7fdd6 nt!PspSystemThreadStartup+0x59
fffff880`039e1da0 00000000`00000000 nt!KiStartSystemThread+0x16

 14    fffff880031e5180  fffff880031f1140 ( 0)                       fffff880031f1140  ................

Child-SP          RetAddr           Call Site
fffff880`031f9a08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`031f9a10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`031f9a40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`031f9c60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`031f9da0 00000000`00000000 nt!KiIdleLoop+0x2c

 15    fffff8800325d180  fffff88003269140 ( 0)                       fffff88003269140  ................

Child-SP          RetAddr           Call Site
fffff880`03286a08 fffff800`6cb6012a hal!HalProcessorIdle+0xf
fffff880`03286a10 fffff800`6cac89a0 nt!PpmIdleDefaultExecute+0xa
fffff880`03286a40 fffff800`6cac73c0 nt!PpmIdleExecuteTransition+0x47f
fffff880`03286c60 fffff800`6cac554c nt!PoIdle+0x1e0
fffff880`03286da0 00000000`00000000 nt!KiIdleLoop+0x2c
Comment 18 Dmitry Fleytman 2015-02-09 10:01:27 UTC 
Threads that stuck execute KeFlushMultipleRangeTb/KxFlushEntireTb.

According to our investigation this function send All-But-Self IPIs and wait for all target processors to complete the request processing and this wait never completes.

According to KVM code base processing of All-But-Self IPI is not "atomic", i.e. KVM loops over all target CPUs, injects interrupts to each CPU's IRR and kicks CPUs one by one. Thus, some CPUs may start (and even complete) processing of IPI before other even got corresponding bit set in IRR.

From our understanding in case of real HW all-but-self IPI is broadcasted "atomically", i.e. at least all IRRs (and probably ISRs) for all CPUs got updated before first CPUs gets corresponding interrupt.

If this is the case there may be an IPI coalescing problem because KVM's APIC implementation fails to queue two similar interrupts as specified in

Intel® 64 and IA-32 Architectures Software Developer’s Manual, 10.8.4 Interrupt Acceptance for Fixed Interrupts:

"If more than one interrupt is generated with the same vector number, the local APIC can set the bit for the vector both in the IRR and the ISR. This means that for the Pentium 4 and Intel Xeon processors, the IRR and ISR can queue two interrupts for each interrupt vector: one in the IRR and one in the ISR. Any additional interrupts issued for the same interrupt vector are collapsed into the single bit in the IRR."


Let's consider following scenario:

There are N CPUs in the system.

1. CPU0 issues all-but-self IPI, KVM enters into CPU loop and broadcasts IPI to CPU1
2. CPU1 immediately processes the IPI and issues another all-but-self IPI with the same vector number.
3. At the same time KVM continues to broadcast first IPI to other CPUs and in parallel starts broadcasting second API.

In this case IPI on CPUs 2-N may get coalesced in contradiction to what should have happened on real HW.

Paolo, what do you think? Does this look sane to you?
Comment 19 Dmitry Fleytman 2015-02-19 13:52:01 UTC 
Patch to test theory from Comment #18 didn't help, so this is not the case.

I tried to play with Hyper-V enlightments and noticed that adding hv_spinlocks=0x1FFF to -cpu resolves the issue, however adding this flag effectively disables cpu grouping in Windows because PV windows kernels do not support those, so the fact Windows boots doesn't mean pause-loop-exiting is related to the problem we observe.