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

Jung-uk Kim <jkim_at_FreeBSD.org> wrote:

> On Wednesday 15 June 2011 06:19 pm, Jung-uk Kim wrote:
> > On Wednesday 15 June 2011 04:39 pm, Jung-uk Kim wrote:
> > > On Wednesday 15 June 2011 03:27 pm, Ian FREISLICH wrote:
> > > > > > The problem I noticed first is that it takes unusually long
> > > > > > until a key press is repeated. With the default eventtimer
> > > > > > (HPET) it seems to take about 4s, which can be slightly
> > > > > > improved by switching to i8254.
> > > > > >
> > > > > > The "error beep" seems to take longer than usual, too,
> > > > > > and the system "feels sluggish" in general.
> > > > > >
> > > > > > An effect that is easier to measure is that the system is
> > > > > > unable to properly keep the time. Again the problem is less
> > > > > > severe when using i8254 instead of HPET:
> > > > >
> > > > > [SNIP]
> > > > >
> > > > > First of all, please do not mix timecounter issues with
> > > > > eventtimer. They are not directly related.
> > > > >
> > > > > 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'
> >
> > The OP sent me some data.  The following is cooked data from what I
> > got:
> >
> > TSC		Delta		Elapsed Time
> > ---------------+---------------+------------
> > 2245026970
> > 2249708604	4681634		0.3003693189
> > 2255874998	6166394		0.3956301509
> > 2260656402	4781404		0.3067704701
> > 2261993048	1336646		0.0857579744
> > 2264175164	2182116		0.1400025497
> > 2266445706	2270542		0.1456758803
> > 2266987003	541297		0.0347291162
> > 2267645095	658092		0.0422225757
> > 2268274965	629870		0.0404118782
> > 2268979787	704822		0.0452207294
> > 2270482069	1502282		0.0963850274
> > 2271140877	658808		0.0422685136
> >
> > HPET		Delta		Elapsed Time
> > ---------------+---------------+------------
> > 1322734365
> > 1337156221	14421856	1.0072408644
> > 1351548130	14391909	1.0051493276
> > 1365949265	14401135	1.0057936833
> > 1380376349	14427084	1.0076059946
> > 1394823985	14447636	1.0090413726
> > 1409273964	14449979	1.0092050107
> > 1423719753	14445789	1.0089123757
> > 1438167064	14447311	1.0090186742
> > 1452613630	14446566	1.0089666424
> > 1467062977	14449347	1.0091608710
> > 1481522037	14459060	1.0098392393
> > 1495969404	14447367	1.0090225853
> >
> > As you can see, HPET increases normally (within errors from
> > sleep(3) accuracy, syscall overhead, etc.) but TSC-low is totally
> > erratic (and too low).  I don't know how this can happen, though.
> > :-(
> >
> > I need some time to figure it out.
> 
> Can you please test the attached patch?  Theoretically, it should not 
> make a difference but I'd like to see if it does, just in case.

As you suspected, it doesn't seem to make a difference:

fk_at_r500 ~/test/freebsd/timeissues $awk '/low.counter/ { o=c; c=$2; d=o?c-o:"-"; print c " " d  }' kern.timecounter2
3065017784 -
3066228257 1210473
3074551564 8323307
3081121276 6569712
3084706794 3585518
3087211252 2504458
3090413096 3201844
3100133126 9720030
3104014847 3881721
3105442070 1427223
fk_at_r500 ~/test/freebsd/timeissues $awk '/HPET.counter/ { o=c; c=$2; d=o?c-o:"-"; print c " " d  }' kern.timecounter2
3544564602 -
3559020869 14456267
3573467329 14446460
3587889861 14422532
3602318403 14428542
3616764316 14445913
3631211075 14446759
3645625298 14414223
3660038347 14413049
3674482395 14444048

The unfiltered data is attached.

Fabian