9front - general discussion about 9front
 help / color / mirror / Atom feed
From: Michael Forney <mforney@mforney.org>
To: 9front@9front.org
Subject: Re: [9front] qemu clock/timer issue
Date: Thu, 17 Feb 2022 19:25:49 -0800	[thread overview]
Message-ID: <CAGw6cBtR6EMcDdYXwuRtSf4YBi-_iC8TxTPd5cjT3XRb6d+Sog@mail.gmail.com> (raw)
In-Reply-To: <CAH_zEu5n1mNXiz=ymKU-_zPwM67qgZXb=ow8Ujm8D+x0igzHAQ@mail.gmail.com>

On 2022-02-05, Nick Owens <mischief@offblast.org> wrote:
> kvm emulates a local APIC timer which the 9front kernel uses. the
> timer period is clamped to a minimum period, and my understanding is
> that the purpose is to protect the host from CPU consumption by
> guests, but i don't have a citation for that. 9front requests a timer
> period shorter than what the default minimum is and kvm warns about
> it. it maybe needs more investigation as to whether we really need
> such short timers.
>
> in the meantime, you can lower the timer period minimum with
>
> echo "options kvm min_timer_period_us=10" >> /etc/modprobe.d/kvm.conf
>
> which is 10000ns. it won't kill all of the warnings since sometimes
> the timer period is slightly shorter, but it will help with the dmesg
> spam.

Thanks for the info! I tried lowering to min_timer_period_us=5 and
even then it seems that 9front requests even shorter lapic timers:

kvm: vcpu 2: requested 828 ns lapic timer period limited to 5000 ns
kvm: vcpu 0: requested 828 ns lapic timer period limited to 5000 ns
kvm: vcpu 3: requested 3822 ns lapic timer period limited to 5000 ns
kvm: vcpu 1: requested 2526 ns lapic timer period limited to 5000 ns

I did some more debugging and I believe the issue is with CPU
frequency detection using hpetcpufreq(). I should have noticed this
earlier, but without *nohpet=1, 9front detects the CPUs as having a
very low clock rate, for example 27 MHz, when it should be 3.3 GHz.

Nothing in the code seemed wrong to me, so I added some debug prints
to try to figure out where detection was going wrong.

Here's a boot log with HPET, detecting the wrong frequency:

Plan 9
HPET: fed00000 8086a201 100 MHz
loops=1000
	cycles 17384 [13196648 13214032]
	hpet 502 [394 896]
loops=2000
	cycles 42652 [56658413 56701065]
	hpet 643 [1318776 1319419]
<snip>
loops=38000
	cycles 477510 [2494452748 2494930258]
	hpet 13729 [75232811 75246540]
loops=39000
	cycles 491293 [2781515810 2782007103]
	hpet 14149 [83936532 83950681]
loops=40000
	cycles 498652 [2935179496 2935678148]
	hpet 1986869 [88595551 90582420]
498652 cycles 1986869 hpet ticks
cpuhz=25097376 cpumhz=25 cyclefreq=25097376 loopconst=1930
125 holes free
0x00026000 0x0009f000 495616
0x00100000 0x00110000 65536
0x005a1000 0x7ffff000 2141577216
2142138368 bytes free
pcirouting: PCI.0.1.3 at pin 1 link 60 irq 9 -> 10
cpu0: 25MHz GenuineIntel P6 (AX 000306F2 CX F7FAB223 DX 1F8BFBFF)
LAPIC: fee00000 0xfffffe80fee00000
ELCR: 0C00
cpu0: lapic clock at 8MHz
cpu1: 25MHz GenuineIntel P6 (AX 000306F2 CX F7FAB223 DX 1F8BFBFF)
cpu2: 25MHz GenuineIntel P6 (AX 000306F2 CX F7FAB223 DX 1F8BFBFF)
cpu3: 25MHz GenuineIntel P6 (AX 000306F2 CX F7FAB223 DX 1F8BFBFF)

It seems that the hpetcpufreq loop is seeing a huge jump in hpet ticks
at some point, causing the loop to stop prematurely. Looking through
qemu source, I believe the HPET is emulated with it's
"QEMU_CLOCK_VIRTUAL", which uses the host's
clock_gettime(CLOCK_MONOTONIC), taking care to save offsets so it
doesn't increase in between vm_stop and vm_start. I confirmed that
vm_stop is never called while reproducing the bug, which means that
reading the HPET counter is effectively doing
clock_gettime(CLOCK_MONOTONIC)/10 (100 MHz, so 10 ns period).

As I was debugging, I noticed that it doesn't happen all of the time,
and I can usually trigger it by resizing the qemu window. When I run
with -display none, I do not see the issue.

I am not quite sure how TSC works under VT-x (and my searches weren't
too helpful), but if is only counting cycles of the virtual CPUs,
while HPET is counting real time on the host, that could explain this
result. Perhaps when the qemu window is resized, the virtual CPU stops
running for some period, but the HPET keeps ticking. Then, when it is
resumed, 9front sees a huge jump in HPET ticks, with a comparatively
small number of clock cycles, and deduces from this that the CPU clock
speed is very slow.

This leaves me with a few questions:
- Is there a more robust method for determining CPU clock rate?
- Why does i8253cpufreq() work with qemu? As far as I can tell, they
are both implemented in qemu using the same clock, but it seems that
it is immune to the resize trick.

Maybe this is something I need to ask qemu developers.

  reply	other threads:[~2022-02-21  3:39 UTC|newest]

Thread overview: 5+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2022-02-05  2:04 Michael Forney
2022-02-05 17:04 ` hiro
2022-02-05 18:14 ` Nick Owens
2022-02-18  3:25   ` Michael Forney [this message]
2022-02-21 22:35     ` cinap_lenrek

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=CAGw6cBtR6EMcDdYXwuRtSf4YBi-_iC8TxTPd5cjT3XRb6d+Sog@mail.gmail.com \
    --to=mforney@mforney.org \
    --cc=9front@9front.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).