Re: [PATCH 1/4] new timeofday core subsystem (v. B1)

[john stultz <johnstul@us.ibm.com>]

On Fri, 2005-06-03 at 01:29 -0600, Frank Sorenson wrote:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
> 
> john stultz wrote:
> > Andrew, All,
> > 	I'm just re-spinning this to resolve a conflict w/ the CPUFREQ changes
> > Linus accepted last night.
> <snip>
> 
> I have found an issue with these TOD subsystem patches, and I
> think it's only an issue on systems that use CPUFREQ.  Whenever
> the frequency changes, at least some portions of the kernel
> get confused about their notion of time.  Here are some
> example entries from my syslog:
> 
> Jun  3 00:33:40 moebius kernel: [  145.023201] cpufreq-core: target for CPU 0: 800000 kHz, relation 0
> Jun  3 00:33:47 moebius kernel: [  114.838909] cpufreq-core: target for CPU 0: 1000000 kHz, relation 0
> Jun  3 00:33:47 moebius kernel: [  114.838977] freq-table: request for target 1000000 kHz (relation: 0) for cpu 0
> Jun  3 00:33:47 moebius kernel: [   92.161872] codec_semaphore: semaphore is not ready [0x1][0x700300]
> Jun  3 00:33:52 moebius kernel: [   97.433279] cpufreq-core: target for CPU 0: 1200000 kHz, relation 0
> Jun  3 00:33:58 moebius kernel: [   66.352233] cpufreq-core: target for CPU 0: 1400000 kHz, relation 0
> Jun  3 00:34:08 moebius kernel: [   85.547260] cpufreq-core: target for CPU 0: 1200000 kHz, relation 0
> Jun  3 00:34:16 moebius kernel: [  211.791738] cpufreq-core: target for CPU 0: 800000 kHz, relation 0
> Jun  3 00:34:27 moebius kernel: [  112.941898] cpufreq-core: target for CPU 0: 1000000 kHz, relation 0
> Jun  3 00:34:31 moebius kernel: [  231.793121] cpufreq-core: target for CPU 0: 800000 kHz, relation 0
> Jun  3 00:34:41 moebius kernel: [  147.122593] cpufreq-core: target for CPU 0: 1200000 kHz, relation 0
> Jun  3 00:34:42 moebius kernel: [  123.906802] cpufreq-core: target for CPU 0: 1000000 kHz, relation 0
> Jun  3 00:34:46 moebius kernel: [  251.342116] cpufreq-core: target for CPU 0: 800000 kHz, relation 0
> Jun  3 00:34:51 moebius kernel: [  192.985214] cpufreq-core: target for CPU 0: 1000000 kHz, relation 0
> 
> The printk times are taken from sched_clock(), which now
> varies depending on the cpu frequency.  Without these patches,
> the printk times appear to consistently increase at the right rate.
> I'm not sure what other portions of the kernel are affected by
> this (watchdogs firing, or other issues?).

Hrm. So, I've been looking into this and I'm a bit stumped, as I'm not
really changing the behavior of sched_clock().

sched_clock() is a pretty bad interface as it just takes the current TSC
value (relative to zero) and scales it using the current cpukhz value
(well, indirectly using cycles_2_ns). Since it doesn't ever accumulate
the past time, frequency changes affect the full interval (since the TSC
was reset) which can cause large errors. The rational for this was that
sched_clock() was supposed to be as fast as possible just to give a
quick guide to the scheduler and occasional incorrect values are
acceptable. 

I'm looking further into it, but could you send me privately the dmesg
output for both with and without the TOD patch?

thanks
-john