Re: [9fans] odd clock behaviour

Re: [9fans] odd clock behaviour

[rog]

[-- Attachment #1: Type: text/plain, Size: 84 bytes --]

> If you refer to my T23, It's a 1GHz machine (according to my BIOS).

mine too.

[-- Attachment #2: Type: message/rfc822, Size: 3383 bytes --]

[-- Attachment #2.1.1: Type: text/plain, Size: 67 bytes --]

If you refer to my T23, It's a 1GHz machine (according to my BIOS).

[-- Attachment #2.1.2: Type: message/rfc822, Size: 1573 bytes --]

From: "Russ Cox" <rsc@plan9.bell-labs.com>
To: 9fans@cse.psu.edu
Subject: Re: [9fans] odd clock behaviour
Date: Thu, 13 Mar 2003 12:06:54 -0500
Message-ID: <b529fedd4dd9b2c2134daa1ff3eaf11b@plan9.bell-labs.com>

If you believe the /dev/time numbers,
your processor is running at 300MHz,
which sounds plausible but not for a T23.
The clock tick numbers advanced by 160 billion
over the 100 seconds.  Is it a 1.6GHz 
machine?  That sounds more likely.

If so, we're really confused about the
clock speed.  It sounds like even though
it was plugged in it dipped down to 300MHz.

Russ

Re: [9fans] odd clock behaviour

[rog]

i just found my machine in the odd timer state again, so have
the opportunite to play with it a bit more...

presotto:
> Try setting the variable i8253dotimerset to 0 (it's now set to 1).
>	echo off > '#P'/i8253timerset

presumably i should do this at boot time, but i'd never know for sure
whether i'd nailed the problem because it presents itself so rarely.

anyway, it doesn't seem to fix much at run time.  it does change stuff
though:

% echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
1048176273 1048211930 1048211930303113804 14857013246208 305454592
1048176320 1048212205 1048212205836287972 14941176119552 305454592
% echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
1048176368 1048212488 1048212488976582421 15027662622720 305454592
1048176414 1048212763 1048212763054236813 15111380900864 305454592
% echo -n off > '#P'/i8253timerset
% echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
1048176621 1048213988 1048213988275370902 15485630322688 305454592
1048176798 1048214298 1048214298823858727 15580488784384 305454592
% % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
1048176875 1048214418 1048214418231644733 15616962440960 305454592
1048177053 1048214695 1048214695742160153 15701729302272 305454592
%

i.e. before the change, sleep 100 was sleeping for 45 realtime seconds
for 275 seconds elapsed in /dev/time.

after changing i8253timeset, sleep 100 sleeps for 178 realtime seconds
for 277 seconds elapsed in /dev/time.

the timer was running normally when i booted the machine up.

on boot, my processor is reported as a 
996MHz GenuineIntel PentiumIII/Xeon (cpuid: AX 0x068A DX 0x383F9FF)

i had a look in my bios settings for stuff that could be influencing
the timers at runtime.

what we've got (i'm running it on AC):

	Power Mode for AC		Maximum Performance
	(which presumably chooses "Fixed Max" out of the options
	for processor speed of "Fixed Max/Medium/Slow", "Auto Medium/Slow")

	SpeedStep Technology	Automatic
	(which says it's "Maximum Performance" on AC, i.e. always at high speed)

	CPU power management	Automatic
	(says: "enables or disables the power saving feature that stops
	the microprocessor clock automatically when there are no system
	activities.")

the last one seems like a possible culprit, i guess.

Re: [9fans] odd clock behaviour

[Russ Cox]

> As long as edf isn't being used (which I think is true everywhere)
> it won't hurt to do that.  I think that rsc does it for vmware
> to avoid slow downs due to the constant clock trimming.

Actually I do it because setting the timer is a REALLY
expensive operation in VMware, and completely unnecessary
if you're not using edf.

Re: [9fans] odd clock behaviour

[David Presotto]

Try setting the variable i8253dotimerset to 0 (it's now set to 1).
	echo off > '#P'/i8253timerset
This will keep timerintr() from constantly
changing the period.  I'm always afraid that changing the 8253
on the fly will break something since it's not done much by
other systems and therefore not really well tested.

As long as edf isn't being used (which I think is true everywhere)
it won't hurt to do that.  I think that rsc does it for vmware
to avoid slow downs due to the constant clock trimming.

Re: [9fans] odd clock behaviour

[rog]

dan:
> Usually, it's the result of running the system under load 

well, when i observed it today, it was after running
tra overnight. i've put a script in my lib/profile
to check if the time is running ok at boot time,
so when i see it again, at least i'll know whether
it happens after loading or before...

dave:
> You're clearly not running timesync since the frequency (the last
> number) hasn't been tweaked at all.

actually, i was running timesync, but it didn't
seem to be kicking in.

> Do you have some music player running that might be using it as a
> clock source?

no, as far as i'm aware i was using a completely vanilla system;
apart from the above-mentioned heavy network activity,
i don't think i was doing anything unusual at all.

when i rebooted, it was all back to normal.

Re: [9fans] odd clock behaviour

[David Presotto]

> i'm running on an IBM Thinkpad (T22), and occasionally (not always) i
> get the clock running much faster than it should (#r/rtc still gives
> the correct time)
>
> as an example (i ran this a few minutes ago):
> % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
> 1047563747 1047629025 1047629025597639124 41354973397504 305454592
> 1047563792 1047629508 1047629508199623282 41502386389760 305454592
> % % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
> 1047563991 1047632392 1047632392826308124 42383508857344 305454592
> 1047564039 1047632728 1047632728118785531 42485925484288 305454592
> % % % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
> 1047564093 1047633210 1047633210610709377 42633304858112 305454592
> 1047564136 1047633742 1047633742398391924 42795741847808 305454592
> %
>
> i.e.  /dev/time advanced by 483, 336 and 532 seconds respectively,
> while #r/rtc advanced by 45, 48 and 43 seconds respectively,
> all for a nominally 100 second sleep!
>

The 305454592 is 256 times the i8253 clock frequency.  I just clock 0
as the HZ clock interrupt and clock 2 as the TOD clock.  It's frequency
is 1193182, but I really multiply it and ticks by 256 to give timesync
a number with more precision to tweak, i.e., it gives me a more precise
multiplier.

You're clearly not running timesync since the frequency (the last
number) hasn't been tweaked at all.

However, your your i8253's are ticking at an incredibly variable rate.
It looks to me like something else is using clock 2.  It supposed to be
there for us to screw with as we will but apparently not.  Do you have
some music player running that might be using it as a clock source?

Re: [9fans] odd clock behaviour

[Dan Cross]

ps- I should mention that I've seen similar, if not the same, behavior
under FreeBSD on the same hardware.

	- Dan C.

Re: [9fans] odd clock behaviour

[Dan Cross]

> has anyone else experienced odd clock behaviour on their plan 9
> system?
> 
> i'm running on an IBM Thinkpad (T22), and occasionally (not always) i
> get the clock running much faster than it should (#r/rtc still gives
> the correct time)

The exact same thing happens on my Thinkpad (T21).  Usually, it's the
result of running the system under load (ie, playing a CD through the
USB audio interface) or it coming out of screen-blanking mode.  I've
never investigated why it happens.

	- Dan C.

Re: [9fans] odd clock behaviour

[Fco.J.Ballesteros]

[-- Attachment #1: Type: text/plain, Size: 67 bytes --]

If you refer to my T23, It's a 1GHz machine (according to my BIOS).

[-- Attachment #2: Type: message/rfc822, Size: 1573 bytes --]

From: "Russ Cox" <rsc@plan9.bell-labs.com>
To: 9fans@cse.psu.edu
Subject: Re: [9fans] odd clock behaviour
Date: Thu, 13 Mar 2003 12:06:54 -0500
Message-ID: <b529fedd4dd9b2c2134daa1ff3eaf11b@plan9.bell-labs.com>

If you believe the /dev/time numbers,
your processor is running at 300MHz,
which sounds plausible but not for a T23.
The clock tick numbers advanced by 160 billion
over the 100 seconds.  Is it a 1.6GHz 
machine?  That sounds more likely.

If so, we're really confused about the
clock speed.  It sounds like even though
it was plugged in it dipped down to 300MHz.

Russ

Re: [9fans] odd clock behaviour

[Russ Cox]

If you believe the /dev/time numbers,
your processor is running at 300MHz,
which sounds plausible but not for a T23.
The clock tick numbers advanced by 160 billion
over the 100 seconds.  Is it a 1.6GHz 
machine?  That sounds more likely.

If so, we're really confused about the
clock speed.  It sounds like even though
it was plugged in it dipped down to 300MHz.

Russ

Re: [9fans] odd clock behaviour

[David Presotto]

[-- Attachment #1: Type: text/plain, Size: 83 bytes --]

Timesync could be pushing your time up faster than it should.  Are you
running it?

[-- Attachment #2: Type: message/rfc822, Size: 3028 bytes --]

From: Sam <sah@softcardsystems.com>
To: <9fans@cse.psu.edu>
Subject: Re: [9fans] odd clock behaviour
Date: Thu, 13 Mar 2003 11:22:57 -0500 (EST)
Message-ID: <Pine.LNX.4.30.0303131122030.10504-100000@athena>

I've noticed a clock drift on my 600E.

On Thu, 13 Mar 2003
rog@vitanuova.com wrote:

> has anyone else experienced odd clock behaviour on their plan 9
> system?
>
> i'm running on an IBM Thinkpad (T22), and occasionally (not always) i
> get the clock running much faster than it should (#r/rtc still gives
> the correct time)
>
> as an example (i ran this a few minutes ago):
> % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
> 1047563747 1047629025 1047629025597639124 41354973397504 305454592
> 1047563792 1047629508 1047629508199623282 41502386389760 305454592
> % % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
> 1047563991 1047632392 1047632392826308124 42383508857344 305454592
> 1047564039 1047632728 1047632728118785531 42485925484288 305454592
> % % % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
> 1047564093 1047633210 1047633210610709377 42633304858112 305454592
> 1047564136 1047633742 1047633742398391924 42795741847808 305454592
> %
>
> i.e.  /dev/time advanced by 483, 336 and 532 seconds respectively,
> while #r/rtc advanced by 45, 48 and 43 seconds respectively,
> all for a nominally 100 second sleep!
>
> the power has been plugged in continuously (i.e.  it shouldn't have
> invoked any funny power-saving clock changing).
>
> this leads to some odd effects on the user interface, not to mention
> the fact that date(1) now thinks it's 11:18am tomorrow...
>
>   cheers,
>     rog.
>

Re: [9fans] odd clock behaviour

[Sam]

I've noticed a clock drift on my 600E.

On Thu, 13 Mar 2003
rog@vitanuova.com wrote:

> has anyone else experienced odd clock behaviour on their plan 9
> system?
>
> i'm running on an IBM Thinkpad (T22), and occasionally (not always) i
> get the clock running much faster than it should (#r/rtc still gives
> the correct time)
>
> as an example (i ran this a few minutes ago):
> % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
> 1047563747 1047629025 1047629025597639124 41354973397504 305454592
> 1047563792 1047629508 1047629508199623282 41502386389760 305454592
> % % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
> 1047563991 1047632392 1047632392826308124 42383508857344 305454592
> 1047564039 1047632728 1047632728118785531 42485925484288 305454592
> % % % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
> 1047564093 1047633210 1047633210610709377 42633304858112 305454592
> 1047564136 1047633742 1047633742398391924 42795741847808 305454592
> %
>
> i.e.  /dev/time advanced by 483, 336 and 532 seconds respectively,
> while #r/rtc advanced by 45, 48 and 43 seconds respectively,
> all for a nominally 100 second sleep!
>
> the power has been plugged in continuously (i.e.  it shouldn't have
> invoked any funny power-saving clock changing).
>
> this leads to some odd effects on the user interface, not to mention
> the fact that date(1) now thinks it's 11:18am tomorrow...
>
>   cheers,
>     rog.
>

Re: [9fans] odd clock behaviour

[Russ Cox]

It could still be funny power-saving clock changing.
The next time it happens try running this:

#define RDTSC BYTE $0x0F; BYTE $0x31
TEXT	rdtsc(SB), $0	/* time stamp counter: cycles since power up */
	MOVL	.ret+0(FP), CX
	RDTSC
	MOVL	AX, 0(CX)
	MOVL	DX, 4(CX)
	RET

#include <u.h>
#include <libc.h>

extern uvlong rdtsc(void);

void
main(void)
{
	print("%llud\n", rdtsc());
}

and see if the cycle counter is flying away.

Re: [9fans] odd clock behaviour

[rog]

nemo:
> On my Thinkpad T23:
[...]
> Seems to be ok.

it's only occasionally a problem on mine; it might be some
odd condition at boot time, or something, that causes it.

that's why i asked, as it's likely to be a subtle kernel
problem, rather than an obvious one...

it's very annoying when it happens, though
(e.g. it's going to play havoc with my mkfiles
when i next log in, not to mention the fact that i've now
got at least one fossil archive that's misdated!)

Re: [9fans] odd clock behaviour

[Fco.J.Ballesteros]

> has anyone else experienced odd clock behaviour on their plan 9
> system?
> 
> i'm running on an IBM Thinkpad (T22), and occasionally (not always) i

On my Thinkpad T23:

; echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
1047569236 1047565639 1047565639053190468 343274780928 305442630
1047569336 1047565739 1047565739074228979 373824773376 305442617
; 

Seems to be ok.

[9fans] odd clock behaviour

[rog]

has anyone else experienced odd clock behaviour on their plan 9
system?

i'm running on an IBM Thinkpad (T22), and occasionally (not always) i
get the clock running much faster than it should (#r/rtc still gives
the correct time)

as an example (i ran this a few minutes ago):
% echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
1047563747 1047629025 1047629025597639124 41354973397504 305454592
1047563792 1047629508 1047629508199623282 41502386389760 305454592
% % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
1047563991 1047632392 1047632392826308124 42383508857344 305454592
1047564039 1047632728 1047632728118785531 42485925484288 305454592
% % % echo `{cat '#r/rtc'; cat /dev/time; }; sleep 100; echo `{cat '#r/rtc'; cat /dev/time; }
1047564093 1047633210 1047633210610709377 42633304858112 305454592
1047564136 1047633742 1047633742398391924 42795741847808 305454592
%

i.e.  /dev/time advanced by 483, 336 and 532 seconds respectively,
while #r/rtc advanced by 45, 48 and 43 seconds respectively,
all for a nominally 100 second sleep!

the power has been plugged in continuously (i.e.  it shouldn't have
invoked any funny power-saving clock changing).

this leads to some odd effects on the user interface, not to mention
the fact that date(1) now thinks it's 11:18am tomorrow...

  cheers,
    rog.