qemu polling KVM_IRQ_LINE_STATUS when stopped
One issue I see for some time is that even when I stop a Linux KVM guest using libvirt it still sometimes uses a lot of CPU time.
According to strace it loops polling on KVM_IRQ_LINE_STATUS
I see it with various qemu versions, both FC25, FC26, OpenSUSE Leap 42.1/2
IIRC old enough KVM didn't have this problem, at least I didn't notice it.
My workaround is to kill -STOP the qemu process too, but is there a better fix?
-Andi
strace of a stopped qemu using ~18% CPU time of a core.
write(7, "\1\0\0\0\0\0\0\0", 8) = 8clock_gettime(CLOCK_MONOTONIC, {tv_sec=1118693, tv_nsec=583125997}) = 0 gettimeofday({tv_sec=1508275611, tv_usec=558425}, NULL) = 0 clock_gettime(CLOCK_MONOTONIC, {tv_sec=1118693, tv_nsec=583171115}) = 0 ppoll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=24, events=POLLIN}], 7, {tv_sec=0, tv_nsec=0}, NULL,
8) = 1 ([{fd=7, revents=POLLIN}], left {tv_sec=0, tv_nsec=0}) clock_gettime(CLOCK_MONOTONIC, {tv_sec=1118693, tv_nsec=583227127}) = 0 gettimeofday({tv_sec=1508275611, tv_usec=558526}, NULL) = 0 ioctl(12, KVM_IRQ_LINE_STATUS, 0x7ffc15ce8f30) = 0 gettimeofday({tv_sec=1508275611, tv_usec=558569}, NULL) = 0 clock_gettime(CLOCK_MONOTONIC, {tv_sec=1118693, tv_nsec=583313870}) = 0 gettimeofday({tv_sec=1508275611, tv_usec=558612}, NULL) = 0 clock_gettime(CLOCK_MONOTONIC, {tv_sec=1118693, tv_nsec=583357101}) = 0 ppoll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=24, events=POLLIN}], 7, {tv_sec=0, tv_nsec=0}, NULL,
8) = 1 ([{fd=7, revents=POLLIN}], left {tv_sec=0, tv_nsec=0})read(7, "\3\0\0\0\0\0\0\0", 512) = 8clock_gettime(CLOCK_MONOTONIC, {tv_sec=1118693, tv_nsec=583433228}) = 0 clock_gettime(CLOCK_MONOTONIC, {tv_sec=1118693, tv_nsec=583455717}) = 0
Paolo Bonzini
maintainerQuoted 16 lines · Andi Kleen
One issue I see for some time is that even when I stop a Linux KVM guest using libvirt it still sometimes uses a lot of CPU time.
According to strace it loops polling on
KVM_IRQ_LINE_STATUSI see it with various qemu versions, both FC25, FC26, OpenSUSE Leap 42.1/2
IIRC old enough KVM didn't have this problem, at least I didn't notice it.
My workaround is to kill -STOP the qemu process too, but is there a better fix?
-Andi
strace of a stopped qemu using ~18% CPU time of a core.
Quoted 8 lines
write(7, "\1\0\0\0\0\0\0\0", 8)= 8clock_gettime(CLOCK_MONOTONIC, {tv_sec=1118693, tv_nsec=583125997})= 0gettimeofday({tv_sec=1508275611, tv_usec=558425}, NULL)= 0clock_gettime(CLOCK_MONOTONIC, {tv_sec=1118693, tv_nsec=583171115})= 0 ppoll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=24, events=POLLIN}], 7, {tv_sec=0, tv_nsec=0}, NULL,
8) = 1 ([{fd=7, revents=POLLIN}], left {tv_sec=0, tv_nsec=0})
Because the polling time is zero here, and fd=7 has POLLIN, it seems that QEMU is continuously scheduling a callback (a timer with a deadline in the past, or a bottom half). Can you perhaps attach gdb and see what callback it is?
Paolo
Quoted 4 lines
Because the polling time is zero here, and fd=7 has POLLIN, it seems that QEMU is continuously scheduling a callback (a timer with a deadline in the past, or a bottom half). Can you perhaps attach gdb and see what callback it is?
There seem to be multiple.
The ioctl appears to be the PIC timer
- 6.36% __GI___ioctl ▒
kvm_vm_ioctl ▒
kvm_set_irq ▒
kvm_pic_set_irq
It does something with glib (windows are all closed BTW)
- 2.83% libglib-2.0.so.0.5200.3 [.] g_main_context_check ▒
- 2.81% g_main_context_check ▒
- 2.60% main_loop_wait ▒
main ▒
__libc_start_main ▒ _start
And some AIO is going on, not sure what triggers that.
1.96% aio_ctx_check ▒
-Andi
Paolo Bonzini
maintainerQuoted 7 lines · Andi Kleen
The ioctl appears to be the PIC timer
- 6.36%
__GI___ioctl▒
kvm_vm_ioctl▒
kvm_set_irq▒
kvm_pic_set_irq
PIC is the interrupt controller, why do you say the timer? What is the QEMU side of the call stack?
Quoted 10 lines
- 2.83% libglib-2.0.so.0.5200.3 [.] g_main_context_check ▒ - 2.81% g_main_context_check ▒ - 2.60% main_loop_wait ▒ main ▒ __libc_start_main ▒
_startAnd some AIO is going on, not sure what triggers that.
1.96%
aio_ctx_check▒
"check" is just "do I have something to do?" so it runs on every iteration.
Paolo
Quoted 11 lines · Paolo Bonzini
Quoted 7 lines · Andi Kleen
The ioctl appears to be the PIC timer
- 6.36%
__GI___ioctl▒
kvm_vm_ioctl▒
kvm_set_irq▒
kvm_pic_set_irqPIC is the interrupt controller, why do you say the timer? What is the QEMU side of the call stack?
I did some more sampling in gdb this time.
All the timer call backs I caught are rtc_period_timer.
Perhaps that needs to be stopped when the guest is stopped?
It also calls the ioctl:
#0 0x00007f73d97175e0 in ioctl () from target:/lib64/libc.so.6
#1 0x000055ed03c7ec82 in kvm_vm_ioctl (s=s@entry=0x55ed06ba2000, type=<optimized out>) at /usr/src/debug/qemu-2.9.1/kvm-all.c:2136
#2 0x000055ed03c7fb15 in kvm_set_irq (s=0x55ed06ba2000, irq=<optimized out>, level=<optimized out>) at /usr/src/debug/qemu-2.9.1/kvm-all.c:1001
#3 0x000055ed03cef2c0 in kvm_pic_set_irq (opaque=<optimized out>, irq=<optimized out>, level=<optimized out>)
at /usr/src/debug/qemu-2.9.1/hw/i386/kvm/i8259.c:114
#4 0x000055ed03cba196 in qemu_irq_raise (irq=<optimized out>) at /usr/src/debug/qemu-2.9.1/include/hw/irq.h:16
#5 rtc_periodic_timer (opaque=0x55ed06f88580) at /usr/src/debug/qemu-2.9.1/hw/timer/mc146818rtc.c:198
#6 0x000055ed03faf1f0 in timerlist_run_timers (timer_list=0x55ed06aafa40) at /usr/src/debug/qemu-2.9.1/util/qemu-timer.c:536
#7 0x000055ed03faf3f7 in qemu_clock_run_timers (type=QEMU_CLOCK_HOST) at /usr/src/debug/qemu-2.9.1/util/qemu-timer.c:547
#8 qemu_clock_run_all_timers () at /usr/src/debug/qemu-2.9.1/util/qemu-timer.c:662
#9 0x000055ed03faf8da in main_loop_wait (nonblocking=<optimized out>) at /usr/src/debug/qemu-2.9.1/util/main-loop.c:525#10 0x000055ed03c2f0e3 in main_loop () at /usr/src/debug/qemu-2.9.1/vl.c:1898
-Andi
Paolo Bonzini
maintainerQuoted 14 lines · Andi Kleen
Quoted 11 lines · Paolo Bonzini
Quoted 7 lines · Andi Kleen
The ioctl appears to be the PIC timer
- 6.36%
__GI___ioctl▒
kvm_vm_ioctl▒
kvm_set_irq▒
kvm_pic_set_irqPIC is the interrupt controller, why do you say the timer? What is the QEMU side of the call stack?
Quoted 5 lines
I did some more sampling in gdb this time.
All the timer call backs I caught are
rtc_period_timer.Perhaps that needs to be stopped when the guest is stopped?
Unfortunately that's not possible in general. Windows uses the periodic timer to track wall time (!), so if you do that your clock is going to be late when you resume the guest.
But yeah, we might have to figure out a way to do that for non-Windows guests. But why is the RTC periodic timer on at all in your setup?
Paolo
Quoted 3 lines
Unfortunately that's not possible in general. Windows uses the periodic timer to track wall time (!), so if you do that your clock is going to be late when you resume the guest.
But when the guest cannot execute instructions
it cannot see whatever the handler does.
So the handler could always catch up after stopping for longer, without making any difference.
Quoted 3 lines
But yeah, we might have to figure out a way to do that for non-Windows guests. But why is the RTC periodic timer on at all in your setup?
Sorry this one was actually a Windows guest.
I'll check the Linux guests too.
-Andi
Paolo Bonzini
maintainerQuoted 9 lines · Andi Kleen
Quoted 3 lines
Unfortunately that's not possible in general. Windows uses the periodic timer to track wall time (!), so if you do that your clock is going to be late when you resume the guest.
But when the guest cannot execute instructions
it cannot see whatever the handler does.So the handler could always catch up after stopping for longer, without making any difference.
You may be right... you should get the interrupt storm *after continuing* the guest, but not while it's stopped.
Paolo
Quoted 10 lines
Quoted 3 lines
But yeah, we might have to figure out a way to do that for non-Windows guests. But why is the RTC periodic timer on at all in your setup?
Sorry this one was actually a Windows guest.
I'll check the Linux guests too.
-Andi
Quoted 5 lines · Paolo Bonzini
Quoted 4 lines · Andi Kleen
Quoted 3 lines
Unfortunately that's not possible in general. Windows uses the periodic timer to track wall time (!), so if you do that your clock is going to be late when you resume the guest.
Quoted 8 lines
Quoted 5 lines
But when the guest cannot execute instructions
it cannot see whatever the handler does.So the handler could always catch up after stopping for longer, without making any difference.
You may be right... you should get the interrupt storm *after continuing* the guest, but not while it's stopped.
Maybe be find to not have a storm, but only one. I belive real hardware cannot have a storm because only one interrupt can be pending at a time. The RTC driver should be able to figure it out from the actual time, and it already needs to handle it because this can happen for other reasons (e.g. a JTAG debugger)
-Andi
Paolo Bonzini
maintainer----- Original Message -----
Quoted 15 lines
From: "Andi Kleen" <[email protected]>
To: "Paolo Bonzini" <[email protected]>
Cc: [email protected]
Sent: Friday, October 20, 2017 10:50:26 PM
Subject: Re: qemu pollingKVM_IRQ_LINE_STATUSwhen stoppedQuoted 8 lines · Paolo Bonzini
Quoted 7 lines · Andi Kleen
Quoted 3 lines
Unfortunately that's not possible in general. Windows uses the periodic timer to track wall time (!), so if you do that your clock is going to be late when you resume the guest.
But when the guest cannot execute instructions
it cannot see whatever the handler does.
Quoted 8 lines
Quoted 5 lines
Quoted 2 lines
So the handler could always catch up after stopping for longer, without making any difference.
You may be right... you should get the interrupt storm *after continuing* the guest, but not while it's stopped.
Maybe be find to not have a storm, but only one. I belive real hardware cannot have a storm because only one interrupt can be pending at a time.
Real hardware also doesn't pause for an extended period of time, with exceptions such as JTAG that aren't as prominent as pausing a virtual machine. This is just how Windows works: unless it's S3/S4, it updates the time from RTC periodic timer ticks, and the frequency sometimes goes up as much as 1024 or 2048 Hz (default being 64 Hz IIRC).
In fact, we have a lot of cruft in KVM just to track periodic timer ticks that couldn't be delivered and retry again a little later. Without that, the smallest load on the host is enough for time to drift in Windows guests.
Paolo
Quoted 6 lines
The RTC driver should be able to figure it out from the actual time, and it already needs to handle it because this can happen for other reasons (e.g. a JTAG debugger)
-Andi
Hi Paolo et al.,
I recently noticed ~30% CPU usage on a paused Windows 10 VM, as reported in https://bugs.launchpad.net/bugs/1851062 and
https://bugzilla.redhat.com/1638289 which, with the help of Christian Ehrhardt, led to your previous discussion of the issue with Andi Kleen at https://lore.kernel.org/kvm/[email protected]/ quoted below:
Quoted 25 lines · Paolo Bonzini
Quoted 9 lines · Andi Kleen
Quoted 8 lines · Paolo Bonzini
Quoted 7 lines · Andi Kleen
Quoted 3 lines
Unfortunately that's not possible in general. Windows uses the periodic timer to track wall time (!), so if you do that your clock is going to be late when you resume the guest.
But when the guest cannot execute instructions
it cannot see whatever the handler does.Quoted 8 lines
Quoted 5 lines
Quoted 2 lines
So the handler could always catch up after stopping for longer, without making any difference.
You may be right... you should get the interrupt storm *after continuing* the guest, but not while it's stopped.
Maybe be find to not have a storm, but only one. I belive real hardware cannot have a storm because only one interrupt can be pending at a time.
Real hardware also doesn't pause for an extended period of time, with exceptions such as JTAG that aren't as prominent as pausing a virtual machine. This is just how Windows works: unless it's S3/S4, it updates the time from RTC periodic timer ticks, and the frequency sometimes goes up as much as 1024 or 2048 Hz (default being 64 Hz IIRC).
Quoted 4 lines
In fact, we have a lot of cruft in KVM just to track periodic timer ticks that couldn't be delivered and retry again a little later. Without that, the smallest load on the host is enough for time to drift in Windows guests.
I'm trying to understand the cause and what options might exist for addressing it. Several questions:
1. Do I understand correctly that the CPU usage is due to counting RTC periodic timer ticks for replay when the guest is resumed?
2. If so, would it be possible to calculate the number of ticks required from the time delta at resume, rather than polling each tick while paused?
3. Presumably when restoring from a snapshot, Windows time must jump forward from the time the snapshot was taken. How does this differ from resuming from a paused state?
4. How is this handled if the host is suspended (S3) when the VM is paused (or not paused) and ticks aren't counted on the host?
5. I have not observed high CPU usage for paused VMs in VirtualBox. Would it be worth investigating how they handle this?
From the discussion in https://bugs.launchpad.net/bugs/1851062 it appears that the issue does not occur for all Windows 10 VMs. Does that fit the theory it is caused by RTC periodic timer ticks? In my VM, clockres reports
Maximum timer interval: 15.625 ms
Minimum timer interval: 0.500 ms
Current timer interval: 15.625 ms
immediately before and after pausing, suggesting that high periodic tick frequency is not necessary to cause the issue.
Thanks,
Kevin
Quoted 4 lines
From the discussion in https://bugs.launchpad.net/bugs/1851062 it appears that the issue does not occur for all Windows 10 VMs. Does that fit the theory it is caused by RTC periodic timer ticks? In my VM, clockres reports
These days I just kill -STOP/-CONT the qemu of the VMs when pausing/resuming to work around this.
I also haven't noticed any clock drift in the Windows VM (which is Windows 8, so quite old for Windows standards)
So whatever the Windows drift problem was it's likely long fixed, and we're just burning CPU time for no good reason on modern Windows.
-Andi
Paolo Bonzini
maintainerQuoted 5 lines · Kevin Locke
I'm trying to understand the cause and what options might exist for addressing it. Several questions:
1. Do I understand correctly that the CPU usage is due to counting RTC periodic timer ticks for replay when the guest is resumed?
Yes.
Quoted 3 lines
2. If so, would it be possible to calculate the number of ticks required from the time delta at resume, rather than polling each tick while paused?
Note that high CPU usage while the guest is paused is a bug. Only high CPU usage as soon as the guest resumes is the unavoidable part.
That's because Windows (at least older version) counts up by one for every tick and so we have to inject thousands of ticks for it to catch up.
Quoted 3 lines
3. Presumably when restoring from a snapshot, Windows time must jump forward from the time the snapshot was taken. How does this differ from resuming from a paused state?
It doesn't, and it sucks equally bad because you get high CPU usage as soon as the snapshot is restored (in order to catch up with possibly days of lost ticks!).
Quoted 2 lines
4. How is this handled if the host is suspended (S3) when the VM is paused (or not paused) and ticks aren't counted on the host?
During S3, the VM is paused in a reset state (so all timers are off, which might explain different/non-buggy behavior). After wakeup, Windows refreshes the clock from the RTC time of day.
Quoted 6 lines
5. I have not observed high CPU usage for paused VMs in VirtualBox. Would it be worth investigating how they handle this?
From the discussion in https://bugs.launchpad.net/bugs/1851062 it appears that the issue does not occur for all Windows 10 VMs. Does that fit the theory it is caused by RTC periodic timer ticks?
Windows 10 can use the Hyper-V synthetic timer instead of the RTC, which shouldn't have the problem.
Paolo
Thanks for the info Paolo and Andi!
Quoted 12 lines · Paolo Bonzini
Quoted 2 lines · Kevin Locke
1. Do I understand correctly that the CPU usage is due to counting RTC periodic timer ticks for replay when the guest is resumed?
Yes.
Quoted 3 lines
2. If so, would it be possible to calculate the number of ticks required from the time delta at resume, rather than polling each tick while paused?
Note that high CPU usage while the guest is paused is a bug. Only high CPU usage as soon as the guest resumes is the unavoidable part.
[...]
Quoted 9 lines
Quoted 6 lines
5. I have not observed high CPU usage for paused VMs in VirtualBox. Would it be worth investigating how they handle this?
From the discussion in https://bugs.launchpad.net/bugs/1851062 it appears that the issue does not occur for all Windows 10 VMs. Does that fit the theory it is caused by RTC periodic timer ticks?
Windows 10 can use the Hyper-V synthetic timer instead of the RTC, which shouldn't have the problem.
That's great news! Since I'm able to reproduce the issue on a recently installed Windows 10 2004 VM on Linux 5.7 with QEMU 5.0, is there anything I can do to help isolate the bug, or is it a known issue?
Thanks again,
Kevin
Paolo Bonzini
maintainerQuoted 7 lines · Kevin Locke
Quoted 2 lines
Windows 10 can use the Hyper-V synthetic timer instead of the RTC, which shouldn't have the problem.
That's great news! Since I'm able to reproduce the issue on a recently installed Windows 10 2004 VM on Linux 5.7 with QEMU 5.0, is there anything I can do to help isolate the bug, or is it a known issue?
You need to enable Hyper-V enlightenments, with something like
-cpu host,hv_vpindex,hv_runtime,hv_synic,hv_stimer,hv_reset,hv_time,hv_relaxed
on the QEMU command line.
Thanks,
Paolo
Quoted 9 lines · Paolo Bonzini
Quoted 7 lines · Kevin Locke
Quoted 2 lines
Windows 10 can use the Hyper-V synthetic timer instead of the RTC, which shouldn't have the problem.
That's great news! Since I'm able to reproduce the issue on a recently installed Windows 10 2004 VM on Linux 5.7 with QEMU 5.0, is there anything I can do to help isolate the bug, or is it a known issue?
Quoted 5 lines
You need to enable Hyper-V enlightenments, with something like
-cpu host,hv_vpindex,hv_runtime,hv_synic,hv_stimer,hv_reset,hv_time,hv_relaxed
on the QEMU command line.
Bingo! I was using the defaults from virt-manager:[1]
-cpu $host,hv-time,hv-relaxed,hv-vapic,hv-spinlocks=0x1fff
Using to the enlightenments you suggested solves the high CPU when paused issue for me. After a bit of testing, it appears that hv_stimer is the key. High CPU when paused does not occur when that enlightenment is enabled, regardless of which others are enabled/disabled.
Is there any reason not to add it to the virt-manager defaults for Windows 10? Any other suggestions about which enlightenments to enable or disable by default?
Thanks again,
Kevin
[1]: https://github.com/virt-manager/virt-manager/blob/v2.2.1/virtinst/domain/features.py#L74-L83
Quoted 4 lines · Paolo Bonzini
Quoted 2 lines · Kevin Locke
1. Do I understand correctly that the CPU usage is due to counting RTC periodic timer ticks for replay when the guest is resumed?
Quoted 8 lines
Yes.
Quoted 3 lines
2. If so, would it be possible to calculate the number of ticks required from the time delta at resume, rather than polling each tick while paused?
Note that high CPU usage while the guest is paused is a bug. Only high CPU usage as soon as the guest resumes is the unavoidable part.
Although enabling the hv_stimer Hyper-V enlightenment avoids the issue, I assume high CPU usage while the guest is paused when hv_stimer is not enabled is still a bug. It's not important for my current use cases, but if there is interest in fixing the issue for others, I was able to find a more minimal reproduction:
Using the Windows 10 May 2020 English 64-bit ISO from
https://www.microsoft.com/en-us/software-download/windows10ISO
If I run
qemu-system-x86_64 \ -no-user-config \ -machine pc-q35-5.0,accel=kvm \ -m 1024 \ -blockdev driver=file,node-name=win10iso,filename=Win10_2004_English_x64.iso \ -device ide-cd,drive=win10iso \ -no-hpet \ -rtc driftfix=slew
then pause the VM after the "Windows Setup" window appears, qemu-system-x86_64 uses ~40% CPU indefinitely. Without -rtc driftfix=slew, ~10%. Without -no-hpet, ~1%.
For reference, both of these options are added by virt-manager by default for Windows 10.
If there's anything else I can do to help, let me know. Thanks again for all of the help tracking this down.
Best,
Kevin