Skip site navigation (1)Skip section navigation (2)
Date:      Wed, 23 Mar 2016 12:54:10 +0000
From:      bugzilla-noreply@freebsd.org
To:        freebsd-bugs@FreeBSD.org
Subject:   [Bug 208238] [Hyper-V] TSC frequency is not correctly detected: "calcru: runtime went backwards"
Message-ID:  <bug-208238-8@https.bugs.freebsd.org/bugzilla/>

next in thread | raw e-mail | index | archive | help
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D208238

            Bug ID: 208238
           Summary: [Hyper-V] TSC frequency is not correctly detected:
                    "calcru: runtime went backwards"
           Product: Base System
           Version: 11.0-CURRENT
          Hardware: Any
                OS: Any
            Status: New
          Severity: Affects Some People
          Priority: ---
         Component: kern
          Assignee: freebsd-bugs@FreeBSD.org
          Reporter: decui@microsoft.com

I can easily get a large number of messages in the system log similar to th=
is:

# dmesg | grep backwards
calcru: runtime went backwards from 5188 usec to 2727 usec for pid 770 (cro=
n)
calcru: runtime went backwards from 2944 usec to 1488 usec for pid 766
(sendmail)
calcru: runtime went backwards from 2497 usec to 1262 usec for pid 766
(sendmail)


It looks this is caused by the wrongly-detected TSC frequency and I made th=
is
patch to address this:

https://github.com/dcui/freebsd/commit/07acbd8a3771adba9ac0fca807ec629ff05a=
807c

"
use hyper-v time counter (rather than i8254) to calibrate TSC
The i8254 PIT counter emulated by Hyper-V is not reliable.

In probe_tsc_freq() -> DELAY -> init_ops.early_delay() -> i8254_delay(),
getit() can return these values when it is invoked 10 times:
  1 pit count0 =3D 228
  2 pit count0 =3D 131
  3 pit count0 =3D 34
  4 pit count0 =3D 65473 <-- this is a normal wrap-around.
  5 pit count0 =3D 65375
  6 pit count0 =3D 65278
  7 pit count0 =3D 65180
  8 pit count0 =3D 65388 <-- this is bad!
  9 pit count0 =3D 65290
 10 pit count0 =3D 65193

For the 8th time, the 'delta' in i8254_delay() is < 0 while
it shouldn't, so the later "delta +=3D i8254_max_count;" and
"ticks_left -=3D delta" will cause i8254_delay() to wait shorter than
expected, and finally probe_tsc_freq() get a smaller 'tsc_freq'.

A smaller 'tsc_freq' can cause time inaccuracy in dtrace.
It can also cause warnings like

calcru: runtime went backwards from 50 usec to 25 usec for pid 0 (kernel)
calcru: runtime went backwards from 1471 usec to 743 usec for pid 0 (kernel)
calcru: runtime went backwards from 40 usec to 20 usec for pid 0 (kernel)
calcru: runtime went backwards from 18 usec to 9 usec for pid 0 (kernel)
calcru: runtime went backwards from 46204978 usec to 23362331 usec for pid 0
(kernel)

We use Hyper-V time counter, which is much more reliable than i8254,
to calibrate TSC.
"

--=20
You are receiving this mail because:
You are the assignee for the bug.=



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?bug-208238-8>