* TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-09 18:27 ` Michael Tokarev 0 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-09 18:27 UTC (permalink / raw) To: KVM list; +Cc: Avi Kivity, Gerd Hoffmann, qemu-devel As a follow-up to the patch "tsc: use kvmclock for calibration". There's another problem reported by several users. The sympthom is that grub does not show boot menu, it boots default entry right away without any pause. After quite some debugging it turned out to be TSC issue. Grub uses tsc for its timeout handling. When setting timeout to some very large value (10000), I can see the counter is ticking backwards at a very high speed, ticking from 10000 to 0 in about 5 seconds. Running kvm -cpu host,-tsc forces grub to use rtc clocksource, and the problem goes away. The most interesting thing is that this is a problem new for qemu-kvm 1.1 (and is still present in current git), 1.0 version had no such issue. And it only happens when in-kernel irqchip is enabled -- running with -no-kvm-irqchip also fixes the grub problem, so that tsc starts counting "correctly" for grub again. Gerd mentioned mis-calibration of bios timer when host is heavily loaded. I tested grub on my workstation today which was completely idle, no other processes running. It smells like a bug in kvm somewhere. And it happens when I explicitly pin kvm to a single core, so tsc should tick correctly even if its syncronization is broken between cores. Current qemu also has this issue (since 1.1), since it also has in-kernel irqchip support now. FWIW, here's the TSC calibration routine from grub: /* Calibrate the TSC based on the RTC. */ static void calibrate_tsc (void) { /* First calibrate the TSC rate (relative, not absolute time). */ grub_uint64_t start_tsc; grub_uint64_t end_tsc; start_tsc = grub_get_tsc (); grub_pit_wait (0xffff); end_tsc = grub_get_tsc (); tsc_ticks_per_ms = grub_divmod64 (end_tsc - start_tsc, 55, 0); } Thanks, /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-09 18:27 ` Michael Tokarev 0 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-09 18:27 UTC (permalink / raw) To: KVM list; +Cc: qemu-devel, Avi Kivity, Gerd Hoffmann As a follow-up to the patch "tsc: use kvmclock for calibration". There's another problem reported by several users. The sympthom is that grub does not show boot menu, it boots default entry right away without any pause. After quite some debugging it turned out to be TSC issue. Grub uses tsc for its timeout handling. When setting timeout to some very large value (10000), I can see the counter is ticking backwards at a very high speed, ticking from 10000 to 0 in about 5 seconds. Running kvm -cpu host,-tsc forces grub to use rtc clocksource, and the problem goes away. The most interesting thing is that this is a problem new for qemu-kvm 1.1 (and is still present in current git), 1.0 version had no such issue. And it only happens when in-kernel irqchip is enabled -- running with -no-kvm-irqchip also fixes the grub problem, so that tsc starts counting "correctly" for grub again. Gerd mentioned mis-calibration of bios timer when host is heavily loaded. I tested grub on my workstation today which was completely idle, no other processes running. It smells like a bug in kvm somewhere. And it happens when I explicitly pin kvm to a single core, so tsc should tick correctly even if its syncronization is broken between cores. Current qemu also has this issue (since 1.1), since it also has in-kernel irqchip support now. FWIW, here's the TSC calibration routine from grub: /* Calibrate the TSC based on the RTC. */ static void calibrate_tsc (void) { /* First calibrate the TSC rate (relative, not absolute time). */ grub_uint64_t start_tsc; grub_uint64_t end_tsc; start_tsc = grub_get_tsc (); grub_pit_wait (0xffff); end_tsc = grub_get_tsc (); tsc_ticks_per_ms = grub_divmod64 (end_tsc - start_tsc, 55, 0); } Thanks, /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip 2012-08-09 18:27 ` [Qemu-devel] " Michael Tokarev @ 2012-08-09 19:06 ` Marcelo Tosatti -1 siblings, 0 replies; 26+ messages in thread From: Marcelo Tosatti @ 2012-08-09 19:06 UTC (permalink / raw) To: Michael Tokarev, @amt.cnet Cc: qemu-devel, Avi Kivity, KVM list, Gerd Hoffmann On Thu, Aug 09, 2012 at 10:27:43PM +0400, Michael Tokarev wrote: > As a follow-up to the patch "tsc: use kvmclock for > calibration". > > There's another problem reported by several users. > The sympthom is that grub does not show boot menu, > it boots default entry right away without any pause. > > After quite some debugging it turned out to be > TSC issue. Grub uses tsc for its timeout handling. > When setting timeout to some very large value > (10000), I can see the counter is ticking backwards > at a very high speed, ticking from 10000 to 0 in > about 5 seconds. > > Running kvm -cpu host,-tsc forces grub to use > rtc clocksource, and the problem goes away. > > The most interesting thing is that this is a > problem new for qemu-kvm 1.1 (and is still > present in current git), 1.0 version had no > such issue. And it only happens when in-kernel > irqchip is enabled -- running with -no-kvm-irqchip > also fixes the grub problem, so that tsc starts > counting "correctly" for grub again. > > Gerd mentioned mis-calibration of bios timer > when host is heavily loaded. I tested grub on > my workstation today which was completely idle, > no other processes running. > > It smells like a bug in kvm somewhere. And it > happens when I explicitly pin kvm to a single > core, so tsc should tick correctly even if its > syncronization is broken between cores. > > Current qemu also has this issue (since 1.1), > since it also has in-kernel irqchip support now. > > FWIW, here's the TSC calibration routine from > grub: > > /* Calibrate the TSC based on the RTC. */ > static void > calibrate_tsc (void) > { > /* First calibrate the TSC rate (relative, not absolute time). */ > grub_uint64_t start_tsc; > grub_uint64_t end_tsc; > > start_tsc = grub_get_tsc (); > grub_pit_wait (0xffff); > end_tsc = grub_get_tsc (); > > tsc_ticks_per_ms = grub_divmod64 (end_tsc - start_tsc, 55, 0); > } Emulation of grub_pit_wait sequence by in-kernel PIT is probably broken. QEMU PIT emulation is also affected by miscalibration. Please provide steps to reproduce. ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-09 19:06 ` Marcelo Tosatti 0 siblings, 0 replies; 26+ messages in thread From: Marcelo Tosatti @ 2012-08-09 19:06 UTC (permalink / raw) To: Michael Tokarev, @amt.cnet Cc: qemu-devel, Avi Kivity, KVM list, Gerd Hoffmann On Thu, Aug 09, 2012 at 10:27:43PM +0400, Michael Tokarev wrote: > As a follow-up to the patch "tsc: use kvmclock for > calibration". > > There's another problem reported by several users. > The sympthom is that grub does not show boot menu, > it boots default entry right away without any pause. > > After quite some debugging it turned out to be > TSC issue. Grub uses tsc for its timeout handling. > When setting timeout to some very large value > (10000), I can see the counter is ticking backwards > at a very high speed, ticking from 10000 to 0 in > about 5 seconds. > > Running kvm -cpu host,-tsc forces grub to use > rtc clocksource, and the problem goes away. > > The most interesting thing is that this is a > problem new for qemu-kvm 1.1 (and is still > present in current git), 1.0 version had no > such issue. And it only happens when in-kernel > irqchip is enabled -- running with -no-kvm-irqchip > also fixes the grub problem, so that tsc starts > counting "correctly" for grub again. > > Gerd mentioned mis-calibration of bios timer > when host is heavily loaded. I tested grub on > my workstation today which was completely idle, > no other processes running. > > It smells like a bug in kvm somewhere. And it > happens when I explicitly pin kvm to a single > core, so tsc should tick correctly even if its > syncronization is broken between cores. > > Current qemu also has this issue (since 1.1), > since it also has in-kernel irqchip support now. > > FWIW, here's the TSC calibration routine from > grub: > > /* Calibrate the TSC based on the RTC. */ > static void > calibrate_tsc (void) > { > /* First calibrate the TSC rate (relative, not absolute time). */ > grub_uint64_t start_tsc; > grub_uint64_t end_tsc; > > start_tsc = grub_get_tsc (); > grub_pit_wait (0xffff); > end_tsc = grub_get_tsc (); > > tsc_ticks_per_ms = grub_divmod64 (end_tsc - start_tsc, 55, 0); > } Emulation of grub_pit_wait sequence by in-kernel PIT is probably broken. QEMU PIT emulation is also affected by miscalibration. Please provide steps to reproduce. ^ permalink raw reply [flat|nested] 26+ messages in thread
[parent not found: <20120809204748.GA32346@amt.cnet>]
* Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip [not found] ` <20120809204748.GA32346@amt.cnet> @ 2012-08-09 21:36 ` Michael Tokarev 0 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-09 21:36 UTC (permalink / raw) To: Marcelo Tosatti; +Cc: KVM list, Avi Kivity, Gerd Hoffmann, qemu-devel On 10.08.2012 00:47, Marcelo Tosatti wrote: [] >>> calibrate_tsc (void) >>> { >>> /* First calibrate the TSC rate (relative, not absolute time). */ >>> grub_uint64_t start_tsc; >>> grub_uint64_t end_tsc; >>> >>> start_tsc = grub_get_tsc (); >>> grub_pit_wait (0xffff); >>> end_tsc = grub_get_tsc (); >>> >>> tsc_ticks_per_ms = grub_divmod64 (end_tsc - start_tsc, 55, 0); >>> } >> >> Emulation of grub_pit_wait sequence by in-kernel PIT is probably broken. This is grub_pit_wait(): #define TIMER2_REG_CONTROL 0x42 #define TIMER_REG_COMMAND 0x43 #define TIMER2_REG_LATCH 0x61 #define TIMER2_SELECT 0x80 #define TIMER_ENABLE_LSB 0x20 #define TIMER_ENABLE_MSB 0x10 #define TIMER2_LATCH 0x20 #define TIMER2_SPEAKER 0x02 #define TIMER2_GATE 0x01 void grub_pit_wait (grub_uint16_t tics) { /* Disable timer2 gate and speaker. */ grub_outb (grub_inb (TIMER2_REG_LATCH) & ~ (TIMER2_SPEAKER | TIMER2_GATE), TIMER2_REG_LATCH); /* Set tics. */ grub_outb (TIMER2_SELECT | TIMER_ENABLE_LSB | TIMER_ENABLE_MSB, TIMER_REG_COMMAND); grub_outb (tics & 0xff, TIMER2_REG_CONTROL); grub_outb (tics >> 8, TIMER2_REG_CONTROL); /* Enable timer2 gate, keep speaker disabled. */ grub_outb ((grub_inb (TIMER2_REG_LATCH) & ~ TIMER2_SPEAKER) | TIMER2_GATE, TIMER2_REG_LATCH); /* Wait. */ while ((grub_inb (TIMER2_REG_LATCH) & TIMER2_LATCH) == 0x00); /* Disable timer2 gate and speaker. */ grub_outb (grub_inb (TIMER2_REG_LATCH) & ~ (TIMER2_SPEAKER | TIMER2_GATE), TIMER2_REG_LATCH); } >> QEMU PIT emulation is also affected by miscalibration. >> >> Please provide steps to reproduce. > > I mean verbose on the steps (does it happen always when setting timeout=10000, > how to set timeout=10000, etc). untested: mkdir /tmp/grub cd /tmp/grub mkdir boot boot/grub cat > boot/grub/grub.cfg <<EOF set timeout=10000 menuentry 'test' { echo "booted:"; read line } EOF grub-mkrescue -o ../grub.iso . kvm -cdrom ../grub.iso This should show a menu with single entry "test", and wait for 10000 seconds, with a countdown. 10000 is enough to actually see it -- with reasonable timeout it isn't easy to see that it displays the menu, instead it immediately goes to the booting, displaying the "booted:" line. kvm -cdrom ../grub.iso -cpu host,-tsc kvm -cdrom ../grub.iso -no-kvm-irqchip ... -- these works fine. Tried with grub from debian wheezy (1.99-22.1) and from ubuntu 12.04, but i guess it should be the same with various versions of grub. Thanks! /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-09 21:36 ` Michael Tokarev 0 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-09 21:36 UTC (permalink / raw) To: Marcelo Tosatti; +Cc: qemu-devel, Avi Kivity, KVM list, Gerd Hoffmann On 10.08.2012 00:47, Marcelo Tosatti wrote: [] >>> calibrate_tsc (void) >>> { >>> /* First calibrate the TSC rate (relative, not absolute time). */ >>> grub_uint64_t start_tsc; >>> grub_uint64_t end_tsc; >>> >>> start_tsc = grub_get_tsc (); >>> grub_pit_wait (0xffff); >>> end_tsc = grub_get_tsc (); >>> >>> tsc_ticks_per_ms = grub_divmod64 (end_tsc - start_tsc, 55, 0); >>> } >> >> Emulation of grub_pit_wait sequence by in-kernel PIT is probably broken. This is grub_pit_wait(): #define TIMER2_REG_CONTROL 0x42 #define TIMER_REG_COMMAND 0x43 #define TIMER2_REG_LATCH 0x61 #define TIMER2_SELECT 0x80 #define TIMER_ENABLE_LSB 0x20 #define TIMER_ENABLE_MSB 0x10 #define TIMER2_LATCH 0x20 #define TIMER2_SPEAKER 0x02 #define TIMER2_GATE 0x01 void grub_pit_wait (grub_uint16_t tics) { /* Disable timer2 gate and speaker. */ grub_outb (grub_inb (TIMER2_REG_LATCH) & ~ (TIMER2_SPEAKER | TIMER2_GATE), TIMER2_REG_LATCH); /* Set tics. */ grub_outb (TIMER2_SELECT | TIMER_ENABLE_LSB | TIMER_ENABLE_MSB, TIMER_REG_COMMAND); grub_outb (tics & 0xff, TIMER2_REG_CONTROL); grub_outb (tics >> 8, TIMER2_REG_CONTROL); /* Enable timer2 gate, keep speaker disabled. */ grub_outb ((grub_inb (TIMER2_REG_LATCH) & ~ TIMER2_SPEAKER) | TIMER2_GATE, TIMER2_REG_LATCH); /* Wait. */ while ((grub_inb (TIMER2_REG_LATCH) & TIMER2_LATCH) == 0x00); /* Disable timer2 gate and speaker. */ grub_outb (grub_inb (TIMER2_REG_LATCH) & ~ (TIMER2_SPEAKER | TIMER2_GATE), TIMER2_REG_LATCH); } >> QEMU PIT emulation is also affected by miscalibration. >> >> Please provide steps to reproduce. > > I mean verbose on the steps (does it happen always when setting timeout=10000, > how to set timeout=10000, etc). untested: mkdir /tmp/grub cd /tmp/grub mkdir boot boot/grub cat > boot/grub/grub.cfg <<EOF set timeout=10000 menuentry 'test' { echo "booted:"; read line } EOF grub-mkrescue -o ../grub.iso . kvm -cdrom ../grub.iso This should show a menu with single entry "test", and wait for 10000 seconds, with a countdown. 10000 is enough to actually see it -- with reasonable timeout it isn't easy to see that it displays the menu, instead it immediately goes to the booting, displaying the "booted:" line. kvm -cdrom ../grub.iso -cpu host,-tsc kvm -cdrom ../grub.iso -no-kvm-irqchip ... -- these works fine. Tried with grub from debian wheezy (1.99-22.1) and from ubuntu 12.04, but i guess it should be the same with various versions of grub. Thanks! /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip 2012-08-09 18:27 ` [Qemu-devel] " Michael Tokarev @ 2012-08-10 7:33 ` Gleb Natapov -1 siblings, 0 replies; 26+ messages in thread From: Gleb Natapov @ 2012-08-10 7:33 UTC (permalink / raw) To: Michael Tokarev; +Cc: KVM list, qemu-devel, Avi Kivity, Gerd Hoffmann On Thu, Aug 09, 2012 at 10:27:43PM +0400, Michael Tokarev wrote: > As a follow-up to the patch "tsc: use kvmclock for > calibration". > > There's another problem reported by several users. > The sympthom is that grub does not show boot menu, > it boots default entry right away without any pause. > > After quite some debugging it turned out to be > TSC issue. Grub uses tsc for its timeout handling. > When setting timeout to some very large value > (10000), I can see the counter is ticking backwards > at a very high speed, ticking from 10000 to 0 in > about 5 seconds. > > Running kvm -cpu host,-tsc forces grub to use > rtc clocksource, and the problem goes away. > Can you try -no-kvm-pit-reinjection please. > The most interesting thing is that this is a > problem new for qemu-kvm 1.1 (and is still > present in current git), 1.0 version had no > such issue. And it only happens when in-kernel > irqchip is enabled -- running with -no-kvm-irqchip > also fixes the grub problem, so that tsc starts > counting "correctly" for grub again. > 1.0 work on the same kernel 1.1 doesn't? > > FWIW, here's the TSC calibration routine from > grub: > > /* Calibrate the TSC based on the RTC. */ Comment claims RTC but code calls grub_pit_wait(). > static void > calibrate_tsc (void) > { > /* First calibrate the TSC rate (relative, not absolute time). */ > grub_uint64_t start_tsc; > grub_uint64_t end_tsc; > > start_tsc = grub_get_tsc (); > grub_pit_wait (0xffff); > end_tsc = grub_get_tsc (); > > tsc_ticks_per_ms = grub_divmod64 (end_tsc - start_tsc, 55, 0); > } > > Thanks, > > /mjt -- Gleb. ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-10 7:33 ` Gleb Natapov 0 siblings, 0 replies; 26+ messages in thread From: Gleb Natapov @ 2012-08-10 7:33 UTC (permalink / raw) To: Michael Tokarev; +Cc: Gerd Hoffmann, qemu-devel, KVM list, Avi Kivity On Thu, Aug 09, 2012 at 10:27:43PM +0400, Michael Tokarev wrote: > As a follow-up to the patch "tsc: use kvmclock for > calibration". > > There's another problem reported by several users. > The sympthom is that grub does not show boot menu, > it boots default entry right away without any pause. > > After quite some debugging it turned out to be > TSC issue. Grub uses tsc for its timeout handling. > When setting timeout to some very large value > (10000), I can see the counter is ticking backwards > at a very high speed, ticking from 10000 to 0 in > about 5 seconds. > > Running kvm -cpu host,-tsc forces grub to use > rtc clocksource, and the problem goes away. > Can you try -no-kvm-pit-reinjection please. > The most interesting thing is that this is a > problem new for qemu-kvm 1.1 (and is still > present in current git), 1.0 version had no > such issue. And it only happens when in-kernel > irqchip is enabled -- running with -no-kvm-irqchip > also fixes the grub problem, so that tsc starts > counting "correctly" for grub again. > 1.0 work on the same kernel 1.1 doesn't? > > FWIW, here's the TSC calibration routine from > grub: > > /* Calibrate the TSC based on the RTC. */ Comment claims RTC but code calls grub_pit_wait(). > static void > calibrate_tsc (void) > { > /* First calibrate the TSC rate (relative, not absolute time). */ > grub_uint64_t start_tsc; > grub_uint64_t end_tsc; > > start_tsc = grub_get_tsc (); > grub_pit_wait (0xffff); > end_tsc = grub_get_tsc (); > > tsc_ticks_per_ms = grub_divmod64 (end_tsc - start_tsc, 55, 0); > } > > Thanks, > > /mjt -- Gleb. ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip 2012-08-10 7:33 ` Gleb Natapov @ 2012-08-10 9:24 ` Michael Tokarev -1 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-10 9:24 UTC (permalink / raw) To: Gleb Natapov; +Cc: KVM list, qemu-devel, Avi Kivity, Gerd Hoffmann On 10.08.2012 11:33, Gleb Natapov wrote: > On Thu, Aug 09, 2012 at 10:27:43PM +0400, Michael Tokarev wrote: >> As a follow-up to the patch "tsc: use kvmclock for >> calibration". >> >> There's another problem reported by several users. >> The sympthom is that grub does not show boot menu, >> it boots default entry right away without any pause. >> >> After quite some debugging it turned out to be >> TSC issue. Grub uses tsc for its timeout handling. >> When setting timeout to some very large value >> (10000), I can see the counter is ticking backwards >> at a very high speed, ticking from 10000 to 0 in >> about 5 seconds. >> >> Running kvm -cpu host,-tsc forces grub to use >> rtc clocksource, and the problem goes away. >> > Can you try -no-kvm-pit-reinjection please. It does not help. With -no-kvm-pit-reinjection, the time in grub is ticking about 1000 times faster still, just like without. >> The most interesting thing is that this is a >> problem new for qemu-kvm 1.1 (and is still >> present in current git), 1.0 version had no >> such issue. And it only happens when in-kernel >> irqchip is enabled -- running with -no-kvm-irqchip >> also fixes the grub problem, so that tsc starts >> counting "correctly" for grub again. >> > 1.0 work on the same kernel 1.1 doesn't? Yes. This issue does not look like kernel-dependent - it happens the same way on 3.0, 3.2 and 3.5 kernels. Note that upstream qemu 1.1+ is also affected, when used with -machine pc,kernel_irqchip=on. /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-10 9:24 ` Michael Tokarev 0 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-10 9:24 UTC (permalink / raw) To: Gleb Natapov; +Cc: Gerd Hoffmann, qemu-devel, KVM list, Avi Kivity On 10.08.2012 11:33, Gleb Natapov wrote: > On Thu, Aug 09, 2012 at 10:27:43PM +0400, Michael Tokarev wrote: >> As a follow-up to the patch "tsc: use kvmclock for >> calibration". >> >> There's another problem reported by several users. >> The sympthom is that grub does not show boot menu, >> it boots default entry right away without any pause. >> >> After quite some debugging it turned out to be >> TSC issue. Grub uses tsc for its timeout handling. >> When setting timeout to some very large value >> (10000), I can see the counter is ticking backwards >> at a very high speed, ticking from 10000 to 0 in >> about 5 seconds. >> >> Running kvm -cpu host,-tsc forces grub to use >> rtc clocksource, and the problem goes away. >> > Can you try -no-kvm-pit-reinjection please. It does not help. With -no-kvm-pit-reinjection, the time in grub is ticking about 1000 times faster still, just like without. >> The most interesting thing is that this is a >> problem new for qemu-kvm 1.1 (and is still >> present in current git), 1.0 version had no >> such issue. And it only happens when in-kernel >> irqchip is enabled -- running with -no-kvm-irqchip >> also fixes the grub problem, so that tsc starts >> counting "correctly" for grub again. >> > 1.0 work on the same kernel 1.1 doesn't? Yes. This issue does not look like kernel-dependent - it happens the same way on 3.0, 3.2 and 3.5 kernels. Note that upstream qemu 1.1+ is also affected, when used with -machine pc,kernel_irqchip=on. /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip 2012-08-10 9:24 ` Michael Tokarev @ 2012-08-12 8:10 ` Gleb Natapov -1 siblings, 0 replies; 26+ messages in thread From: Gleb Natapov @ 2012-08-12 8:10 UTC (permalink / raw) To: Michael Tokarev; +Cc: Gerd Hoffmann, qemu-devel, KVM list, Avi Kivity On Fri, Aug 10, 2012 at 01:24:06PM +0400, Michael Tokarev wrote: > On 10.08.2012 11:33, Gleb Natapov wrote: > > On Thu, Aug 09, 2012 at 10:27:43PM +0400, Michael Tokarev wrote: > >> As a follow-up to the patch "tsc: use kvmclock for > >> calibration". > >> > >> There's another problem reported by several users. > >> The sympthom is that grub does not show boot menu, > >> it boots default entry right away without any pause. > >> > >> After quite some debugging it turned out to be > >> TSC issue. Grub uses tsc for its timeout handling. > >> When setting timeout to some very large value > >> (10000), I can see the counter is ticking backwards > >> at a very high speed, ticking from 10000 to 0 in > >> about 5 seconds. > >> > >> Running kvm -cpu host,-tsc forces grub to use > >> rtc clocksource, and the problem goes away. > >> > > Can you try -no-kvm-pit-reinjection please. > > It does not help. With -no-kvm-pit-reinjection, the > time in grub is ticking about 1000 times faster still, > just like without. > > >> The most interesting thing is that this is a > >> problem new for qemu-kvm 1.1 (and is still > >> present in current git), 1.0 version had no > >> such issue. And it only happens when in-kernel > >> irqchip is enabled -- running with -no-kvm-irqchip > >> also fixes the grub problem, so that tsc starts > >> counting "correctly" for grub again. > >> > > 1.0 work on the same kernel 1.1 doesn't? > > Yes. This issue does not look like kernel-dependent - > it happens the same way on 3.0, 3.2 and 3.5 kernels. > Note that upstream qemu 1.1+ is also affected, when > used with -machine pc,kernel_irqchip=on. > Any chance to bisect it? -- Gleb. ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-12 8:10 ` Gleb Natapov 0 siblings, 0 replies; 26+ messages in thread From: Gleb Natapov @ 2012-08-12 8:10 UTC (permalink / raw) To: Michael Tokarev; +Cc: Gerd Hoffmann, qemu-devel, KVM list, Avi Kivity On Fri, Aug 10, 2012 at 01:24:06PM +0400, Michael Tokarev wrote: > On 10.08.2012 11:33, Gleb Natapov wrote: > > On Thu, Aug 09, 2012 at 10:27:43PM +0400, Michael Tokarev wrote: > >> As a follow-up to the patch "tsc: use kvmclock for > >> calibration". > >> > >> There's another problem reported by several users. > >> The sympthom is that grub does not show boot menu, > >> it boots default entry right away without any pause. > >> > >> After quite some debugging it turned out to be > >> TSC issue. Grub uses tsc for its timeout handling. > >> When setting timeout to some very large value > >> (10000), I can see the counter is ticking backwards > >> at a very high speed, ticking from 10000 to 0 in > >> about 5 seconds. > >> > >> Running kvm -cpu host,-tsc forces grub to use > >> rtc clocksource, and the problem goes away. > >> > > Can you try -no-kvm-pit-reinjection please. > > It does not help. With -no-kvm-pit-reinjection, the > time in grub is ticking about 1000 times faster still, > just like without. > > >> The most interesting thing is that this is a > >> problem new for qemu-kvm 1.1 (and is still > >> present in current git), 1.0 version had no > >> such issue. And it only happens when in-kernel > >> irqchip is enabled -- running with -no-kvm-irqchip > >> also fixes the grub problem, so that tsc starts > >> counting "correctly" for grub again. > >> > > 1.0 work on the same kernel 1.1 doesn't? > > Yes. This issue does not look like kernel-dependent - > it happens the same way on 3.0, 3.2 and 3.5 kernels. > Note that upstream qemu 1.1+ is also affected, when > used with -machine pc,kernel_irqchip=on. > Any chance to bisect it? -- Gleb. ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip 2012-08-12 8:10 ` [Qemu-devel] " Gleb Natapov @ 2012-08-12 9:24 ` Michael Tokarev -1 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-12 9:24 UTC (permalink / raw) To: Gleb Natapov; +Cc: Jan Kiszka, Gerd Hoffmann, qemu-devel, KVM list, Avi Kivity On 12.08.2012 12:10, Gleb Natapov wrote: [] > Any chance to bisect it? The bisecion leads to this commit: commit 17ee47418e65b1593defb30edbab33ccd47fc1f8 Merge: 13b0496 5d17c0d Author: Jan Kiszka <jan.kiszka@siemens.com> Date: Tue Apr 10 16:26:23 2012 +0200 Merge commit '5d17c0d2df4998598e6002b27b8e47e792899a0f' into queues/qemu-merge Conflicts: hw/pc.c diff --cc Makefile.target index 33a7255,1bd25a8..32c8e42 --- a/Makefile.target +++ b/Makefile.target @@@ -245,13 -244,8 +245,13 @@@ obj-i386-y += pci-hotplug.o smbios.o wd obj-i386-y += debugcon.o multiboot.o obj-i386-y += pc_piix.o obj-i386-y += pc_sysfw.o - obj-i386-$(CONFIG_KVM) += kvm/clock.o kvm/apic.o kvm/i8259.o kvm/ioapic.o + obj-i386-$(CONFIG_KVM) += kvm/clock.o kvm/apic.o kvm/i8259.o kvm/ioapic.o kvm/i8254.o obj-i386-$(CONFIG_SPICE) += qxl.o qxl-logger.o qxl-render.o +obj-i386-y += testdev.o +obj-i386-y += acpi.o acpi_piix4.o + +obj-i386-y += i8254_common.o i8254.o +obj-i386-$(CONFIG_KVM_DEVICE_ASSIGNMENT) += device-assignment.o # shared objects obj-ppc-y = ppc.o ppc_booke.o diff --cc hw/pc.c index 74c19b9,bb9867b..feb6ef3 --- a/hw/pc.c +++ b/hw/pc.c @@@ -1116,8 -1118,12 +1122,12 @@@ void pc_basic_device_init(ISABus *isa_b qemu_register_boot_set(pc_boot_set, *rtc_state); - pit = pit_init(isa_bus, 0x40, pit_isa_irq, pit_alt_irq); + if (kvm_irqchip_in_kernel()) { + pit = kvm_pit_init(isa_bus, 0x40); + } else { + pit = pit_init(isa_bus, 0x40, pit_isa_irq, pit_alt_irq); + } - if (hpet) { + if (hpet && !(kvm_enabled() && kvm_irqchip_in_kernel())) { /* connect PIT to output control line of the HPET */ qdev_connect_gpio_out(hpet, 0, qdev_get_gpio_in(&pit->qdev, 0)); } Note this commit itself talks about pit and irqchip. But I don't know what does it mean. Cc'ing Jan for help. The short story: tsc timer calibration broke in 1.1+ with in-kernel irqchip (only) for several apps (seabios and grub are two examples), the time is ticking about 100 times faster. In grub the timer is calibrated using pit. The above commit is the result of bisection. Thanks, /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-12 9:24 ` Michael Tokarev 0 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-12 9:24 UTC (permalink / raw) To: Gleb Natapov; +Cc: Jan Kiszka, Gerd Hoffmann, qemu-devel, KVM list, Avi Kivity On 12.08.2012 12:10, Gleb Natapov wrote: [] > Any chance to bisect it? The bisecion leads to this commit: commit 17ee47418e65b1593defb30edbab33ccd47fc1f8 Merge: 13b0496 5d17c0d Author: Jan Kiszka <jan.kiszka@siemens.com> Date: Tue Apr 10 16:26:23 2012 +0200 Merge commit '5d17c0d2df4998598e6002b27b8e47e792899a0f' into queues/qemu-merge Conflicts: hw/pc.c diff --cc Makefile.target index 33a7255,1bd25a8..32c8e42 --- a/Makefile.target +++ b/Makefile.target @@@ -245,13 -244,8 +245,13 @@@ obj-i386-y += pci-hotplug.o smbios.o wd obj-i386-y += debugcon.o multiboot.o obj-i386-y += pc_piix.o obj-i386-y += pc_sysfw.o - obj-i386-$(CONFIG_KVM) += kvm/clock.o kvm/apic.o kvm/i8259.o kvm/ioapic.o + obj-i386-$(CONFIG_KVM) += kvm/clock.o kvm/apic.o kvm/i8259.o kvm/ioapic.o kvm/i8254.o obj-i386-$(CONFIG_SPICE) += qxl.o qxl-logger.o qxl-render.o +obj-i386-y += testdev.o +obj-i386-y += acpi.o acpi_piix4.o + +obj-i386-y += i8254_common.o i8254.o +obj-i386-$(CONFIG_KVM_DEVICE_ASSIGNMENT) += device-assignment.o # shared objects obj-ppc-y = ppc.o ppc_booke.o diff --cc hw/pc.c index 74c19b9,bb9867b..feb6ef3 --- a/hw/pc.c +++ b/hw/pc.c @@@ -1116,8 -1118,12 +1122,12 @@@ void pc_basic_device_init(ISABus *isa_b qemu_register_boot_set(pc_boot_set, *rtc_state); - pit = pit_init(isa_bus, 0x40, pit_isa_irq, pit_alt_irq); + if (kvm_irqchip_in_kernel()) { + pit = kvm_pit_init(isa_bus, 0x40); + } else { + pit = pit_init(isa_bus, 0x40, pit_isa_irq, pit_alt_irq); + } - if (hpet) { + if (hpet && !(kvm_enabled() && kvm_irqchip_in_kernel())) { /* connect PIT to output control line of the HPET */ qdev_connect_gpio_out(hpet, 0, qdev_get_gpio_in(&pit->qdev, 0)); } Note this commit itself talks about pit and irqchip. But I don't know what does it mean. Cc'ing Jan for help. The short story: tsc timer calibration broke in 1.1+ with in-kernel irqchip (only) for several apps (seabios and grub are two examples), the time is ticking about 100 times faster. In grub the timer is calibrated using pit. The above commit is the result of bisection. Thanks, /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip 2012-08-12 9:24 ` [Qemu-devel] " Michael Tokarev @ 2012-08-13 13:07 ` Jan Kiszka -1 siblings, 0 replies; 26+ messages in thread From: Jan Kiszka @ 2012-08-13 13:07 UTC (permalink / raw) To: Michael Tokarev Cc: Avi Kivity, Gerd Hoffmann, KVM list, Gleb Natapov, qemu-devel On 2012-08-12 11:24, Michael Tokarev wrote: > On 12.08.2012 12:10, Gleb Natapov wrote: > [] >> Any chance to bisect it? > > The bisecion leads to this commit: > > commit 17ee47418e65b1593defb30edbab33ccd47fc1f8 > Merge: 13b0496 5d17c0d > Author: Jan Kiszka <jan.kiszka@siemens.com> > Date: Tue Apr 10 16:26:23 2012 +0200 > > Merge commit '5d17c0d2df4998598e6002b27b8e47e792899a0f' into queues/qemu-merge > > Conflicts: > hw/pc.c > > diff --cc Makefile.target > index 33a7255,1bd25a8..32c8e42 > --- a/Makefile.target > +++ b/Makefile.target > @@@ -245,13 -244,8 +245,13 @@@ obj-i386-y += pci-hotplug.o smbios.o wd > obj-i386-y += debugcon.o multiboot.o > obj-i386-y += pc_piix.o > obj-i386-y += pc_sysfw.o > - obj-i386-$(CONFIG_KVM) += kvm/clock.o kvm/apic.o kvm/i8259.o kvm/ioapic.o > + obj-i386-$(CONFIG_KVM) += kvm/clock.o kvm/apic.o kvm/i8259.o kvm/ioapic.o kvm/i8254.o > obj-i386-$(CONFIG_SPICE) += qxl.o qxl-logger.o qxl-render.o > +obj-i386-y += testdev.o > +obj-i386-y += acpi.o acpi_piix4.o > + > +obj-i386-y += i8254_common.o i8254.o > +obj-i386-$(CONFIG_KVM_DEVICE_ASSIGNMENT) += device-assignment.o > > # shared objects > obj-ppc-y = ppc.o ppc_booke.o > diff --cc hw/pc.c > index 74c19b9,bb9867b..feb6ef3 > --- a/hw/pc.c > +++ b/hw/pc.c > @@@ -1116,8 -1118,12 +1122,12 @@@ void pc_basic_device_init(ISABus *isa_b > > qemu_register_boot_set(pc_boot_set, *rtc_state); > > - pit = pit_init(isa_bus, 0x40, pit_isa_irq, pit_alt_irq); > + if (kvm_irqchip_in_kernel()) { > + pit = kvm_pit_init(isa_bus, 0x40); > + } else { > + pit = pit_init(isa_bus, 0x40, pit_isa_irq, pit_alt_irq); > + } > - if (hpet) { > + if (hpet && !(kvm_enabled() && kvm_irqchip_in_kernel())) { > /* connect PIT to output control line of the HPET */ > qdev_connect_gpio_out(hpet, 0, qdev_get_gpio_in(&pit->qdev, 0)); > } > > > > Note this commit itself talks about pit and irqchip. > But I don't know what does it mean. > > Cc'ing Jan for help. The short story: tsc timer calibration > broke in 1.1+ with in-kernel irqchip (only) for several > apps (seabios and grub are two examples), the time is ticking > about 100 times faster. In grub the timer is calibrated > using pit. The above commit is the result of bisection. Did the versions you tested include the commit 0cdd3d1444 (kvm: i8254: Fix conversion of in-kernel to userspace state)? Jan -- Siemens AG, Corporate Technology, CT RTC ITP SDP-DE Corporate Competence Center Embedded Linux ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-13 13:07 ` Jan Kiszka 0 siblings, 0 replies; 26+ messages in thread From: Jan Kiszka @ 2012-08-13 13:07 UTC (permalink / raw) To: Michael Tokarev Cc: Avi Kivity, Gerd Hoffmann, KVM list, Gleb Natapov, qemu-devel On 2012-08-12 11:24, Michael Tokarev wrote: > On 12.08.2012 12:10, Gleb Natapov wrote: > [] >> Any chance to bisect it? > > The bisecion leads to this commit: > > commit 17ee47418e65b1593defb30edbab33ccd47fc1f8 > Merge: 13b0496 5d17c0d > Author: Jan Kiszka <jan.kiszka@siemens.com> > Date: Tue Apr 10 16:26:23 2012 +0200 > > Merge commit '5d17c0d2df4998598e6002b27b8e47e792899a0f' into queues/qemu-merge > > Conflicts: > hw/pc.c > > diff --cc Makefile.target > index 33a7255,1bd25a8..32c8e42 > --- a/Makefile.target > +++ b/Makefile.target > @@@ -245,13 -244,8 +245,13 @@@ obj-i386-y += pci-hotplug.o smbios.o wd > obj-i386-y += debugcon.o multiboot.o > obj-i386-y += pc_piix.o > obj-i386-y += pc_sysfw.o > - obj-i386-$(CONFIG_KVM) += kvm/clock.o kvm/apic.o kvm/i8259.o kvm/ioapic.o > + obj-i386-$(CONFIG_KVM) += kvm/clock.o kvm/apic.o kvm/i8259.o kvm/ioapic.o kvm/i8254.o > obj-i386-$(CONFIG_SPICE) += qxl.o qxl-logger.o qxl-render.o > +obj-i386-y += testdev.o > +obj-i386-y += acpi.o acpi_piix4.o > + > +obj-i386-y += i8254_common.o i8254.o > +obj-i386-$(CONFIG_KVM_DEVICE_ASSIGNMENT) += device-assignment.o > > # shared objects > obj-ppc-y = ppc.o ppc_booke.o > diff --cc hw/pc.c > index 74c19b9,bb9867b..feb6ef3 > --- a/hw/pc.c > +++ b/hw/pc.c > @@@ -1116,8 -1118,12 +1122,12 @@@ void pc_basic_device_init(ISABus *isa_b > > qemu_register_boot_set(pc_boot_set, *rtc_state); > > - pit = pit_init(isa_bus, 0x40, pit_isa_irq, pit_alt_irq); > + if (kvm_irqchip_in_kernel()) { > + pit = kvm_pit_init(isa_bus, 0x40); > + } else { > + pit = pit_init(isa_bus, 0x40, pit_isa_irq, pit_alt_irq); > + } > - if (hpet) { > + if (hpet && !(kvm_enabled() && kvm_irqchip_in_kernel())) { > /* connect PIT to output control line of the HPET */ > qdev_connect_gpio_out(hpet, 0, qdev_get_gpio_in(&pit->qdev, 0)); > } > > > > Note this commit itself talks about pit and irqchip. > But I don't know what does it mean. > > Cc'ing Jan for help. The short story: tsc timer calibration > broke in 1.1+ with in-kernel irqchip (only) for several > apps (seabios and grub are two examples), the time is ticking > about 100 times faster. In grub the timer is calibrated > using pit. The above commit is the result of bisection. Did the versions you tested include the commit 0cdd3d1444 (kvm: i8254: Fix conversion of in-kernel to userspace state)? Jan -- Siemens AG, Corporate Technology, CT RTC ITP SDP-DE Corporate Competence Center Embedded Linux ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip 2012-08-13 13:07 ` [Qemu-devel] " Jan Kiszka @ 2012-08-13 13:16 ` Michael Tokarev -1 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-13 13:16 UTC (permalink / raw) To: Jan Kiszka; +Cc: Avi Kivity, Gerd Hoffmann, KVM list, Gleb Natapov, qemu-devel On 13.08.2012 17:07, Jan Kiszka wrote: [] >> The bisecion leads to this commit: >> >> commit 17ee47418e65b1593defb30edbab33ccd47fc1f8 >> Merge: 13b0496 5d17c0d >> Author: Jan Kiszka <jan.kiszka@siemens.com> >> Date: Tue Apr 10 16:26:23 2012 +0200 >> >> Merge commit '5d17c0d2df4998598e6002b27b8e47e792899a0f' into queues/qemu-merge [] >> Cc'ing Jan for help. The short story: tsc timer calibration >> broke in 1.1+ with in-kernel irqchip (only) for several >> apps (seabios and grub are two examples), the time is ticking >> about 100 times faster. In grub the timer is calibrated >> using pit. The above commit is the result of bisection. > > Did the versions you tested include the commit 0cdd3d1444 (kvm: i8254: > Fix conversion of in-kernel to userspace state)? While bisecting I didn't have this commit applied, since it were applied past (qemu)-1.1. It is included into qemu-kvm 1.1.0 (as 960d355dc60d9), and that version behaves _exactly_ the same - the time in grub is ticking 100 times faster. I mentioned in this thread that the problem persists in current qemu (and qemu-kvm) git too. I can repeat the bisection with this commit applied after the above "bad" commit. Should I? Thanks, /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-13 13:16 ` Michael Tokarev 0 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-13 13:16 UTC (permalink / raw) To: Jan Kiszka; +Cc: qemu-devel, Gleb Natapov, Avi Kivity, KVM list, Gerd Hoffmann On 13.08.2012 17:07, Jan Kiszka wrote: [] >> The bisecion leads to this commit: >> >> commit 17ee47418e65b1593defb30edbab33ccd47fc1f8 >> Merge: 13b0496 5d17c0d >> Author: Jan Kiszka <jan.kiszka@siemens.com> >> Date: Tue Apr 10 16:26:23 2012 +0200 >> >> Merge commit '5d17c0d2df4998598e6002b27b8e47e792899a0f' into queues/qemu-merge [] >> Cc'ing Jan for help. The short story: tsc timer calibration >> broke in 1.1+ with in-kernel irqchip (only) for several >> apps (seabios and grub are two examples), the time is ticking >> about 100 times faster. In grub the timer is calibrated >> using pit. The above commit is the result of bisection. > > Did the versions you tested include the commit 0cdd3d1444 (kvm: i8254: > Fix conversion of in-kernel to userspace state)? While bisecting I didn't have this commit applied, since it were applied past (qemu)-1.1. It is included into qemu-kvm 1.1.0 (as 960d355dc60d9), and that version behaves _exactly_ the same - the time in grub is ticking 100 times faster. I mentioned in this thread that the problem persists in current qemu (and qemu-kvm) git too. I can repeat the bisection with this commit applied after the above "bad" commit. Should I? Thanks, /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip 2012-08-13 13:16 ` Michael Tokarev @ 2012-08-13 13:41 ` Jan Kiszka -1 siblings, 0 replies; 26+ messages in thread From: Jan Kiszka @ 2012-08-13 13:41 UTC (permalink / raw) To: Michael Tokarev Cc: Avi Kivity, Gerd Hoffmann, KVM list, Gleb Natapov, qemu-devel On 2012-08-13 15:16, Michael Tokarev wrote: > On 13.08.2012 17:07, Jan Kiszka wrote: > [] >>> The bisecion leads to this commit: >>> >>> commit 17ee47418e65b1593defb30edbab33ccd47fc1f8 >>> Merge: 13b0496 5d17c0d >>> Author: Jan Kiszka <jan.kiszka@siemens.com> >>> Date: Tue Apr 10 16:26:23 2012 +0200 >>> >>> Merge commit '5d17c0d2df4998598e6002b27b8e47e792899a0f' into queues/qemu-merge > [] >>> Cc'ing Jan for help. The short story: tsc timer calibration >>> broke in 1.1+ with in-kernel irqchip (only) for several >>> apps (seabios and grub are two examples), the time is ticking >>> about 100 times faster. In grub the timer is calibrated >>> using pit. The above commit is the result of bisection. >> >> Did the versions you tested include the commit 0cdd3d1444 (kvm: i8254: >> Fix conversion of in-kernel to userspace state)? > > While bisecting I didn't have this commit applied, since it were > applied past (qemu)-1.1. It is included into qemu-kvm 1.1.0 > (as 960d355dc60d9), and that version behaves _exactly_ the same - > the time in grub is ticking 100 times faster. I mentioned in this > thread that the problem persists in current qemu (and qemu-kvm) > git too. > > I can repeat the bisection with this commit applied after the > above "bad" commit. Should I? Don't think this will make a difference. There is some other issue. I reproduced the bug, will see if I can analyze it. Jan -- Siemens AG, Corporate Technology, CT RTC ITP SDP-DE Corporate Competence Center Embedded Linux ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip @ 2012-08-13 13:41 ` Jan Kiszka 0 siblings, 0 replies; 26+ messages in thread From: Jan Kiszka @ 2012-08-13 13:41 UTC (permalink / raw) To: Michael Tokarev Cc: qemu-devel, Gleb Natapov, Avi Kivity, KVM list, Gerd Hoffmann On 2012-08-13 15:16, Michael Tokarev wrote: > On 13.08.2012 17:07, Jan Kiszka wrote: > [] >>> The bisecion leads to this commit: >>> >>> commit 17ee47418e65b1593defb30edbab33ccd47fc1f8 >>> Merge: 13b0496 5d17c0d >>> Author: Jan Kiszka <jan.kiszka@siemens.com> >>> Date: Tue Apr 10 16:26:23 2012 +0200 >>> >>> Merge commit '5d17c0d2df4998598e6002b27b8e47e792899a0f' into queues/qemu-merge > [] >>> Cc'ing Jan for help. The short story: tsc timer calibration >>> broke in 1.1+ with in-kernel irqchip (only) for several >>> apps (seabios and grub are two examples), the time is ticking >>> about 100 times faster. In grub the timer is calibrated >>> using pit. The above commit is the result of bisection. >> >> Did the versions you tested include the commit 0cdd3d1444 (kvm: i8254: >> Fix conversion of in-kernel to userspace state)? > > While bisecting I didn't have this commit applied, since it were > applied past (qemu)-1.1. It is included into qemu-kvm 1.1.0 > (as 960d355dc60d9), and that version behaves _exactly_ the same - > the time in grub is ticking 100 times faster. I mentioned in this > thread that the problem persists in current qemu (and qemu-kvm) > git too. > > I can repeat the bisection with this commit applied after the > above "bad" commit. Should I? Don't think this will make a difference. There is some other issue. I reproduced the bug, will see if I can analyze it. Jan -- Siemens AG, Corporate Technology, CT RTC ITP SDP-DE Corporate Competence Center Embedded Linux ^ permalink raw reply [flat|nested] 26+ messages in thread
* [PATCH uq/master] kvm: i8254: Finish time conversion fix 2012-08-13 13:16 ` Michael Tokarev @ 2012-08-13 18:18 ` Jan Kiszka -1 siblings, 0 replies; 26+ messages in thread From: Jan Kiszka @ 2012-08-13 18:18 UTC (permalink / raw) To: Avi Kivity, Marcelo Tosatti Cc: Michael Tokarev, Gerd Hoffmann, KVM list, Gleb Natapov, qemu-devel, qemu-stable 0cdd3d1444 fixed reading back the counter load time from the kernel while assuming the kernel would always update its load time on writing the state. That is only true for channel 1, and so pit_get_channel_info returned wrong output pin states for high counter values. Fix this by applying the offset also on kvm_pit_put. For this purpose, we cache the clock offset in KVMPITState, only updating it on VM state changes or when we write the state while the VM is stopped. Signed-off-by: Jan Kiszka <jan.kiszka@siemens.com> --- hw/kvm/i8254.c | 52 ++++++++++++++++++++++++++++++++++------------------ 1 files changed, 34 insertions(+), 18 deletions(-) diff --git a/hw/kvm/i8254.c b/hw/kvm/i8254.c index c5d3711..53d13e3 100644 --- a/hw/kvm/i8254.c +++ b/hw/kvm/i8254.c @@ -35,7 +35,8 @@ typedef struct KVMPITState { PITCommonState pit; LostTickPolicy lost_tick_policy; - bool state_valid; + bool vm_stopped; + int64_t kernel_clock_offset; } KVMPITState; static int64_t abs64(int64_t v) @@ -43,19 +44,11 @@ static int64_t abs64(int64_t v) return v < 0 ? -v : v; } -static void kvm_pit_get(PITCommonState *pit) +static void kvm_pit_update_clock_offset(KVMPITState *s) { - KVMPITState *s = DO_UPCAST(KVMPITState, pit, pit); - struct kvm_pit_state2 kpit; - struct kvm_pit_channel_state *kchan; - struct PITChannelState *sc; int64_t offset, clock_offset; struct timespec ts; - int i, ret; - - if (s->state_valid) { - return; - } + int i; /* * Measure the delta between CLOCK_MONOTONIC, the base used for @@ -72,6 +65,21 @@ static void kvm_pit_get(PITCommonState *pit) clock_offset = offset; } } + s->kernel_clock_offset = clock_offset; +} + +static void kvm_pit_get(PITCommonState *pit) +{ + KVMPITState *s = DO_UPCAST(KVMPITState, pit, pit); + struct kvm_pit_state2 kpit; + struct kvm_pit_channel_state *kchan; + struct PITChannelState *sc; + int i, ret; + + /* No need to re-read the state if VM is stopped. */ + if (s->vm_stopped) { + return; + } if (kvm_has_pit_state2()) { ret = kvm_vm_ioctl(kvm_state, KVM_GET_PIT2, &kpit); @@ -106,7 +114,7 @@ static void kvm_pit_get(PITCommonState *pit) sc->mode = kchan->mode; sc->bcd = kchan->bcd; sc->gate = kchan->gate; - sc->count_load_time = kchan->count_load_time + clock_offset; + sc->count_load_time = kchan->count_load_time + s->kernel_clock_offset; } sc = &pit->channels[0]; @@ -114,17 +122,23 @@ static void kvm_pit_get(PITCommonState *pit) pit_get_next_transition_time(sc, sc->count_load_time); } -static void kvm_pit_put(PITCommonState *s) +static void kvm_pit_put(PITCommonState *pit) { + KVMPITState *s = DO_UPCAST(KVMPITState, pit, pit); struct kvm_pit_state2 kpit; struct kvm_pit_channel_state *kchan; struct PITChannelState *sc; int i, ret; - kpit.flags = s->channels[0].irq_disabled ? KVM_PIT_FLAGS_HPET_LEGACY : 0; + /* The offset keeps changing as long as the VM is stopped. */ + if (s->vm_stopped) { + kvm_pit_update_clock_offset(s); + } + + kpit.flags = pit->channels[0].irq_disabled ? KVM_PIT_FLAGS_HPET_LEGACY : 0; for (i = 0; i < 3; i++) { kchan = &kpit.channels[i]; - sc = &s->channels[i]; + sc = &pit->channels[i]; kchan->count = sc->count; kchan->latched_count = sc->latched_count; kchan->count_latched = sc->count_latched; @@ -137,7 +151,7 @@ static void kvm_pit_put(PITCommonState *s) kchan->mode = sc->mode; kchan->bcd = sc->bcd; kchan->gate = sc->gate; - kchan->count_load_time = sc->count_load_time; + kchan->count_load_time = sc->count_load_time - s->kernel_clock_offset; } ret = kvm_vm_ioctl(kvm_state, @@ -211,10 +225,12 @@ static void kvm_pit_vm_state_change(void *opaque, int running, KVMPITState *s = opaque; if (running) { - s->state_valid = false; + kvm_pit_update_clock_offset(s); + s->vm_stopped = false; } else { + kvm_pit_update_clock_offset(s); kvm_pit_get(&s->pit); - s->state_valid = true; + s->vm_stopped = true; } } -- 1.7.3.4 ^ permalink raw reply related [flat|nested] 26+ messages in thread
* [Qemu-devel] [PATCH uq/master] kvm: i8254: Finish time conversion fix @ 2012-08-13 18:18 ` Jan Kiszka 0 siblings, 0 replies; 26+ messages in thread From: Jan Kiszka @ 2012-08-13 18:18 UTC (permalink / raw) To: Avi Kivity, Marcelo Tosatti Cc: KVM list, Gleb Natapov, Michael Tokarev, qemu-stable, qemu-devel, Gerd Hoffmann 0cdd3d1444 fixed reading back the counter load time from the kernel while assuming the kernel would always update its load time on writing the state. That is only true for channel 1, and so pit_get_channel_info returned wrong output pin states for high counter values. Fix this by applying the offset also on kvm_pit_put. For this purpose, we cache the clock offset in KVMPITState, only updating it on VM state changes or when we write the state while the VM is stopped. Signed-off-by: Jan Kiszka <jan.kiszka@siemens.com> --- hw/kvm/i8254.c | 52 ++++++++++++++++++++++++++++++++++------------------ 1 files changed, 34 insertions(+), 18 deletions(-) diff --git a/hw/kvm/i8254.c b/hw/kvm/i8254.c index c5d3711..53d13e3 100644 --- a/hw/kvm/i8254.c +++ b/hw/kvm/i8254.c @@ -35,7 +35,8 @@ typedef struct KVMPITState { PITCommonState pit; LostTickPolicy lost_tick_policy; - bool state_valid; + bool vm_stopped; + int64_t kernel_clock_offset; } KVMPITState; static int64_t abs64(int64_t v) @@ -43,19 +44,11 @@ static int64_t abs64(int64_t v) return v < 0 ? -v : v; } -static void kvm_pit_get(PITCommonState *pit) +static void kvm_pit_update_clock_offset(KVMPITState *s) { - KVMPITState *s = DO_UPCAST(KVMPITState, pit, pit); - struct kvm_pit_state2 kpit; - struct kvm_pit_channel_state *kchan; - struct PITChannelState *sc; int64_t offset, clock_offset; struct timespec ts; - int i, ret; - - if (s->state_valid) { - return; - } + int i; /* * Measure the delta between CLOCK_MONOTONIC, the base used for @@ -72,6 +65,21 @@ static void kvm_pit_get(PITCommonState *pit) clock_offset = offset; } } + s->kernel_clock_offset = clock_offset; +} + +static void kvm_pit_get(PITCommonState *pit) +{ + KVMPITState *s = DO_UPCAST(KVMPITState, pit, pit); + struct kvm_pit_state2 kpit; + struct kvm_pit_channel_state *kchan; + struct PITChannelState *sc; + int i, ret; + + /* No need to re-read the state if VM is stopped. */ + if (s->vm_stopped) { + return; + } if (kvm_has_pit_state2()) { ret = kvm_vm_ioctl(kvm_state, KVM_GET_PIT2, &kpit); @@ -106,7 +114,7 @@ static void kvm_pit_get(PITCommonState *pit) sc->mode = kchan->mode; sc->bcd = kchan->bcd; sc->gate = kchan->gate; - sc->count_load_time = kchan->count_load_time + clock_offset; + sc->count_load_time = kchan->count_load_time + s->kernel_clock_offset; } sc = &pit->channels[0]; @@ -114,17 +122,23 @@ static void kvm_pit_get(PITCommonState *pit) pit_get_next_transition_time(sc, sc->count_load_time); } -static void kvm_pit_put(PITCommonState *s) +static void kvm_pit_put(PITCommonState *pit) { + KVMPITState *s = DO_UPCAST(KVMPITState, pit, pit); struct kvm_pit_state2 kpit; struct kvm_pit_channel_state *kchan; struct PITChannelState *sc; int i, ret; - kpit.flags = s->channels[0].irq_disabled ? KVM_PIT_FLAGS_HPET_LEGACY : 0; + /* The offset keeps changing as long as the VM is stopped. */ + if (s->vm_stopped) { + kvm_pit_update_clock_offset(s); + } + + kpit.flags = pit->channels[0].irq_disabled ? KVM_PIT_FLAGS_HPET_LEGACY : 0; for (i = 0; i < 3; i++) { kchan = &kpit.channels[i]; - sc = &s->channels[i]; + sc = &pit->channels[i]; kchan->count = sc->count; kchan->latched_count = sc->latched_count; kchan->count_latched = sc->count_latched; @@ -137,7 +151,7 @@ static void kvm_pit_put(PITCommonState *s) kchan->mode = sc->mode; kchan->bcd = sc->bcd; kchan->gate = sc->gate; - kchan->count_load_time = sc->count_load_time; + kchan->count_load_time = sc->count_load_time - s->kernel_clock_offset; } ret = kvm_vm_ioctl(kvm_state, @@ -211,10 +225,12 @@ static void kvm_pit_vm_state_change(void *opaque, int running, KVMPITState *s = opaque; if (running) { - s->state_valid = false; + kvm_pit_update_clock_offset(s); + s->vm_stopped = false; } else { + kvm_pit_update_clock_offset(s); kvm_pit_get(&s->pit); - s->state_valid = true; + s->vm_stopped = true; } } -- 1.7.3.4 ^ permalink raw reply related [flat|nested] 26+ messages in thread
* Re: [PATCH uq/master] kvm: i8254: Finish time conversion fix 2012-08-13 18:18 ` [Qemu-devel] " Jan Kiszka @ 2012-08-13 18:40 ` Michael Tokarev -1 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-13 18:40 UTC (permalink / raw) To: Jan Kiszka Cc: Avi Kivity, Marcelo Tosatti, Gerd Hoffmann, KVM list, Gleb Natapov, qemu-devel, qemu-stable On 13.08.2012 22:18, Jan Kiszka wrote: > 0cdd3d1444 fixed reading back the counter load time from the kernel > while assuming the kernel would always update its load time on writing > the state. That is only true for channel 1, and so pit_get_channel_info > returned wrong output pin states for high counter values. > > Fix this by applying the offset also on kvm_pit_put. For this purpose, > we cache the clock offset in KVMPITState, only updating it on VM state > changes or when we write the state while the VM is stopped. Wug. The fix (consisting of two halves) appears to be quite messy. Is it a (temporary) workaround or a real solution? And yes, this second half fixes the reported issue with grub timekeeping, and should fix the seabios problem as well (so it shouldn't be necessary to mess with timekeeping in seabios anymore). Thank you Jan! /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] [PATCH uq/master] kvm: i8254: Finish time conversion fix @ 2012-08-13 18:40 ` Michael Tokarev 0 siblings, 0 replies; 26+ messages in thread From: Michael Tokarev @ 2012-08-13 18:40 UTC (permalink / raw) To: Jan Kiszka Cc: KVM list, Gleb Natapov, Marcelo Tosatti, qemu-devel, qemu-stable, Avi Kivity, Gerd Hoffmann On 13.08.2012 22:18, Jan Kiszka wrote: > 0cdd3d1444 fixed reading back the counter load time from the kernel > while assuming the kernel would always update its load time on writing > the state. That is only true for channel 1, and so pit_get_channel_info > returned wrong output pin states for high counter values. > > Fix this by applying the offset also on kvm_pit_put. For this purpose, > we cache the clock offset in KVMPITState, only updating it on VM state > changes or when we write the state while the VM is stopped. Wug. The fix (consisting of two halves) appears to be quite messy. Is it a (temporary) workaround or a real solution? And yes, this second half fixes the reported issue with grub timekeeping, and should fix the seabios problem as well (so it shouldn't be necessary to mess with timekeeping in seabios anymore). Thank you Jan! /mjt ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [PATCH uq/master] kvm: i8254: Finish time conversion fix 2012-08-13 18:40 ` [Qemu-devel] " Michael Tokarev @ 2012-08-14 7:41 ` Jan Kiszka -1 siblings, 0 replies; 26+ messages in thread From: Jan Kiszka @ 2012-08-14 7:41 UTC (permalink / raw) To: Michael Tokarev Cc: Avi Kivity, Marcelo Tosatti, Gerd Hoffmann, KVM list, Gleb Natapov, qemu-devel, qemu-stable [-- Attachment #1: Type: text/plain, Size: 1396 bytes --] On 2012-08-13 20:40, Michael Tokarev wrote: > On 13.08.2012 22:18, Jan Kiszka wrote: >> 0cdd3d1444 fixed reading back the counter load time from the kernel >> while assuming the kernel would always update its load time on writing >> the state. That is only true for channel 1, and so pit_get_channel_info >> returned wrong output pin states for high counter values. >> >> Fix this by applying the offset also on kvm_pit_put. For this purpose, >> we cache the clock offset in KVMPITState, only updating it on VM state >> changes or when we write the state while the VM is stopped. > > Wug. The fix (consisting of two halves) appears to be quite messy. I will split it up into offset caching and application to kvm_pit_put. > Is it a (temporary) workaround or a real solution? No, this is the real solution. It may look complex, but it is required due to the different time bases of the in-kernel PIT and QEMU's vmclock. We didn't care about this in qemu-kvm in the past, but upstream now actually supports migration between in-kernel and user space models, and it also supports the PC speaker with the in-kernel PIT enabled. > > And yes, this second half fixes the reported issue with grub timekeeping, > and should fix the seabios problem as well (so it shouldn't be necessary > to mess with timekeeping in seabios anymore). Thanks, great to hear! Jan [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 262 bytes --] ^ permalink raw reply [flat|nested] 26+ messages in thread
* Re: [Qemu-devel] [PATCH uq/master] kvm: i8254: Finish time conversion fix @ 2012-08-14 7:41 ` Jan Kiszka 0 siblings, 0 replies; 26+ messages in thread From: Jan Kiszka @ 2012-08-14 7:41 UTC (permalink / raw) To: Michael Tokarev Cc: KVM list, Gleb Natapov, Marcelo Tosatti, qemu-devel, qemu-stable, Avi Kivity, Gerd Hoffmann [-- Attachment #1: Type: text/plain, Size: 1396 bytes --] On 2012-08-13 20:40, Michael Tokarev wrote: > On 13.08.2012 22:18, Jan Kiszka wrote: >> 0cdd3d1444 fixed reading back the counter load time from the kernel >> while assuming the kernel would always update its load time on writing >> the state. That is only true for channel 1, and so pit_get_channel_info >> returned wrong output pin states for high counter values. >> >> Fix this by applying the offset also on kvm_pit_put. For this purpose, >> we cache the clock offset in KVMPITState, only updating it on VM state >> changes or when we write the state while the VM is stopped. > > Wug. The fix (consisting of two halves) appears to be quite messy. I will split it up into offset caching and application to kvm_pit_put. > Is it a (temporary) workaround or a real solution? No, this is the real solution. It may look complex, but it is required due to the different time bases of the in-kernel PIT and QEMU's vmclock. We didn't care about this in qemu-kvm in the past, but upstream now actually supports migration between in-kernel and user space models, and it also supports the PC speaker with the in-kernel PIT enabled. > > And yes, this second half fixes the reported issue with grub timekeeping, > and should fix the seabios problem as well (so it shouldn't be necessary > to mess with timekeeping in seabios anymore). Thanks, great to hear! Jan [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 262 bytes --] ^ permalink raw reply [flat|nested] 26+ messages in thread
end of thread, other threads:[~2012-08-14 7:41 UTC | newest] Thread overview: 26+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2012-08-09 18:27 TSC in qem[-kvm] 1.1+ and in-kernel irqchip Michael Tokarev 2012-08-09 18:27 ` [Qemu-devel] " Michael Tokarev 2012-08-09 19:06 ` Marcelo Tosatti 2012-08-09 19:06 ` [Qemu-devel] " Marcelo Tosatti [not found] ` <20120809204748.GA32346@amt.cnet> 2012-08-09 21:36 ` Michael Tokarev 2012-08-09 21:36 ` [Qemu-devel] " Michael Tokarev 2012-08-10 7:33 ` Gleb Natapov 2012-08-10 7:33 ` Gleb Natapov 2012-08-10 9:24 ` Michael Tokarev 2012-08-10 9:24 ` Michael Tokarev 2012-08-12 8:10 ` Gleb Natapov 2012-08-12 8:10 ` [Qemu-devel] " Gleb Natapov 2012-08-12 9:24 ` Michael Tokarev 2012-08-12 9:24 ` [Qemu-devel] " Michael Tokarev 2012-08-13 13:07 ` Jan Kiszka 2012-08-13 13:07 ` [Qemu-devel] " Jan Kiszka 2012-08-13 13:16 ` Michael Tokarev 2012-08-13 13:16 ` Michael Tokarev 2012-08-13 13:41 ` Jan Kiszka 2012-08-13 13:41 ` Jan Kiszka 2012-08-13 18:18 ` [PATCH uq/master] kvm: i8254: Finish time conversion fix Jan Kiszka 2012-08-13 18:18 ` [Qemu-devel] " Jan Kiszka 2012-08-13 18:40 ` Michael Tokarev 2012-08-13 18:40 ` [Qemu-devel] " Michael Tokarev 2012-08-14 7:41 ` Jan Kiszka 2012-08-14 7:41 ` [Qemu-devel] " Jan Kiszka
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.