TSC in qem[-kvm] 1.1+ and in-kernel irqchip

TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

[Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Marcelo Tosatti]

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.

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Marcelo Tosatti]

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.

Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Gleb Natapov]

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.

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Gleb Natapov]

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.

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Gleb Natapov]

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.

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Gleb Natapov]

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.

Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

Re: TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Jan Kiszka]

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

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Jan Kiszka]

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

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Michael Tokarev]

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

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Jan Kiszka]

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

Re: [Qemu-devel] TSC in qem[-kvm] 1.1+ and in-kernel irqchip

[Jan Kiszka]

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

[PATCH uq/master] kvm: i8254: Finish time conversion fix

[Jan Kiszka]

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

[Qemu-devel] [PATCH uq/master] kvm: i8254: Finish time conversion fix

[Jan Kiszka]

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

Re: [PATCH uq/master] kvm: i8254: Finish time conversion fix

[Michael Tokarev]

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

Re: [Qemu-devel] [PATCH uq/master] kvm: i8254: Finish time conversion fix

[Michael Tokarev]

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

Re: [PATCH uq/master] kvm: i8254: Finish time conversion fix

[Jan Kiszka]

[-- 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 --]

Re: [Qemu-devel] [PATCH uq/master] kvm: i8254: Finish time conversion fix

[Jan Kiszka]

[-- 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 --]