Re: Time keeping Issues with the low-resolution TSC timecounter

From: Ian FREISLICH <ianf_at_clue.co.za>
Date: Thu, 16 Jun 2011 08:42:56 +0200
Jung-uk Kim wrote:
> On Wednesday 15 June 2011 03:27 pm, Ian FREISLICH wrote:
> > > Can you please show me verbose boot messages *without* your
> > > patch? Does "sysctl kern.timecounter.hardware=HPET" help
> > > *without* touching eventtimers?
> >
> > I have the same issue with my system (Atom N270).  The effect that
> > I see is about 29 wall clock seconds are recorded as 1 system
> > second.
> 
> Can please you send me output from the following?
> 
> sh -c 'count=10; while [ $count -gt 0 ]; do count=$((count - 1));\
> sysctl kern.timecounter; sleep 1; done'

Interesting it doesn't seem to be constant.  While there was lots
going on (launching exmh and scanning my mail folders opening and
reading 20k files) keyboard repeats work as normal and xclock ticks
one a second.  When the activity stops, xclock ticks every 6 seconds.

While the system clock recorded 10 seconds of wall clock, stopwatch
ran for 42 seconds.

Script started on Thu Jun 16 08:23:51 2011

[mini] /usr/home/ianf $ time sh -c 'count=10; while [ $count -gt 0 ]; do count=$((cou nt - 1)); sysctl kern.timecounter; sleep 1; done'
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 12748229
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3380795670
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 9828
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 1915282150
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 4005701
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3480043331
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 22926
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 1927865521
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 5223570
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3552023679
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 57522
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 1940447630
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 5712953
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3621090061
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 45866
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 1953031506
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 5262197
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3686395330
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 48107
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 1965606144
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 4740225
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3751416462
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 27234
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 1978190005
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 2658298
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3810197474
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 10285
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 1990767555
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 2336065
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3876017411
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 55956
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 2003351574
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 838327
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3937135944
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 37164
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 2015929369
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.tick: 1
kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000)
kern.timecounter.hardware: TSC-low
kern.timecounter.stepwarnings: 0
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 2857839
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 4012322248
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 11432
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.TSC-low.mask: 4294967295
kern.timecounter.tc.TSC-low.counter: 2028502028
kern.timecounter.tc.TSC-low.frequency: 12469046
kern.timecounter.tc.TSC-low.quality: 1000
kern.timecounter.smp_tsc: 1
kern.timecounter.invariant_tsc: 1

real    0m10.084s
user    0m0.030s
sys     0m0.045s
[mini] /usr/home/ianf $ exit

Script done on Thu Jun 16 08:24:04 2011

> > I had do something similar to the OP to make my system useable since
> > it doesn't seem possible to influence timecounter choice at boot
> > time. 
> 
> You can just add the following line in /etc/sysctl.conf for now:

I set the quality to 800 in x86/x86/tsc.c.  It makes the system
start too slow to wait for rc.d/sysctl to execute.

-- 
Ian Freislich
Received on Thu Jun 16 2011 - 04:43:02 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:40:14 UTC