[BUG] cpufreq: constant cpu_khz

[BUG] cpufreq: constant cpu_khz

[Peter Zijlstra]

Hi,


I noticed that my sched_clock() was slow on a number of machine, so I
started looking at cpufreq. I inserted the following printk in the
set_cyc2ns_scale() function, which is called from the cpufreq change
notifier:

diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
index 46af716..8dffd82 100644
--- a/arch/x86/kernel/tsc.c
+++ b/arch/x86/kernel/tsc.c
@@ -261,6 +263,9 @@ static void set_cyc2ns_scale(unsigned long cpu_khz, int cpu)
 	if (cpu_khz)
 		*scale = (NSEC_PER_MSEC << CYC2NS_SCALE_FACTOR)/cpu_khz;
 
+	printk(KERN_DEBUG "set_cyc2ns_scale: %lu %lu %d\n",
+			*scale, cpu_khz, cpu);
+
 	sched_clock_idle_wakeup_event(0);
 	local_irq_restore(flags);
 }


And on my laptop:

root@lappy:~# dmesg | grep cyc2ns | tail -10
[   91.378693] set_cyc2ns_scale: 854 1198980 0
[   91.378713] set_cyc2ns_scale: 854 1198980 0
[  110.548064] set_cyc2ns_scale: 854 1198980 0
[  110.548106] set_cyc2ns_scale: 854 1198980 0
[  110.756121] set_cyc2ns_scale: 854 1198980 0
[  110.756135] set_cyc2ns_scale: 854 1198980 0
[  440.812063] set_cyc2ns_scale: 854 1198980 0
[  440.812106] set_cyc2ns_scale: 854 1198980 0
[  441.593140] set_cyc2ns_scale: 854 1198980 0
[  441.593159] set_cyc2ns_scale: 854 1198980 0

even though I'm sure there were some 800 <-> 1200 MHz changes there
esp. as:

root@lappy:~# cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 11
model name      : Intel(R) Pentium(R) III Mobile CPU      1200MHz
stepping        : 1
cpu MHz         : 798.000
cache size      : 512 KB
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 2
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 sep mtrr pge mca cmov pat pse36 mmx fxsr sse up nopl
bogomips        : 1598.64
clflush size    : 32
power management:


On my opteron:

[root@opteron ~]# dmesg | grep cyc2ns | tail -10
[    0.000000] set_cyc2ns_scale: 427 2394004 0
[    0.000000] set_cyc2ns_scale: 427 2394004 1
[   14.784154] set_cyc2ns_scale: 427 2394004 0
[   14.788342] set_cyc2ns_scale: 427 2394004 1
[   14.792789] set_cyc2ns_scale: 427 2394004 0
[   14.797028] set_cyc2ns_scale: 427 2394004 1
[   15.841049] set_cyc2ns_scale: 427 2394004 0
[   15.845250] set_cyc2ns_scale: 427 2394004 1
[   15.849503] set_cyc2ns_scale: 427 2394004 0
[   15.853785] set_cyc2ns_scale: 427 2394004 1
[root@opteron ~]# cat /proc/cpuinfo
processor       : 0
vendor_id       : AuthenticAMD
cpu family      : 15
model           : 67
model name      : Dual-Core AMD Opteron(tm) Processor 1216
stepping        : 2
cpu MHz         : 1000.000
cache size      : 1024 KB
physical id     : 0
siblings        : 2
core id         : 0
cpu cores       : 2
apicid          : 0
initial apicid  : 0
fpu             : yes
fpu_exception   : yes
cpuid level     : 1
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy
bogomips        : 1995.00
TLB size        : 1024 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc

processor       : 1
vendor_id       : AuthenticAMD
cpu family      : 15
model           : 67
model name      : Dual-Core AMD Opteron(tm) Processor 1216
stepping        : 2
cpu MHz         : 1000.000
cache size      : 1024 KB
physical id     : 0
siblings        : 2
core id         : 1
cpu cores       : 2
apicid          : 1
initial apicid  : 1
fpu             : yes
fpu_exception   : yes
cpuid level     : 1
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy
bogomips        : 1995.00
TLB size        : 1024 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc

Re: [BUG] cpufreq: constant cpu_khz

[Peter Zijlstra]

On Mon, 2008-08-25 at 08:33 +0200, Peter Zijlstra wrote:
> Hi,
> 
> 
> I noticed that my sched_clock() was slow on a number of machine, so I
> started looking at cpufreq.

The below seems to fix the problem for me, but I don't have enough clue
to know if its the correct fix, please advise.

diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
index 46af716..2f10f8c 100644
--- a/arch/x86/kernel/tsc.c
+++ b/arch/x86/kernel/tsc.c
@@ -314,7 +319,7 @@ static int time_cpufreq_notifier(struct
notifier_block *nb, unsigned long val,
 			mark_tsc_unstable("cpufreq changes");
 	}
 
-	set_cyc2ns_scale(tsc_khz_ref, freq->cpu);
+	set_cyc2ns_scale(tsc_khz, freq->cpu);
 
 	return 0;
 }

Re: [BUG] cpufreq: constant cpu_khz

[Ingo Molnar]

* Peter Zijlstra <peterz@infradead.org> wrote:

> > I noticed that my sched_clock() was slow on a number of machine, so 
> > I started looking at cpufreq.
> 
> The below seems to fix the problem for me, but I don't have enough 
> clue to know if its the correct fix, please advise.

> -	set_cyc2ns_scale(tsc_khz_ref, freq->cpu);
> +	set_cyc2ns_scale(tsc_khz, freq->cpu);

hm, that too is due to the tsc.c unification - Alok Cc:-ed. Applied your 
fix to x86/urgent.

	Ingo

Re: [BUG] cpufreq: constant cpu_khz

[Alok Kataria]

On Mon, 2008-08-25 at 05:39 -0700, Ingo Molnar wrote:
> * Peter Zijlstra <peterz@infradead.org> wrote:
> 
> > > I noticed that my sched_clock() was slow on a number of machine, so
> > > I started looking at cpufreq.
> >
> > The below seems to fix the problem for me, but I don't have enough
> > clue to know if its the correct fix, please advise.
> 
> > -     set_cyc2ns_scale(tsc_khz_ref, freq->cpu);
> > +     set_cyc2ns_scale(tsc_khz, freq->cpu);
> 
> hm, that too is due to the tsc.c unification - Alok Cc:-ed. Applied your
> fix to x86/urgent.
> 

Yes the fix is correct, tsc_khz can change in the loop above.
Looking at tsc_64.c before the integration, that too had this bug but
32bit was good. So this is the right fix.

Thanks,
Alok


>         Ingo

Re: [BUG] cpufreq: constant cpu_khz

[Dave Jones]

On Mon, Aug 25, 2008 at 02:39:26PM +0200, Ingo Molnar wrote:
 > 
 > * Peter Zijlstra <peterz@infradead.org> wrote:
 > 
 > > > I noticed that my sched_clock() was slow on a number of machine, so 
 > > > I started looking at cpufreq.
 > > 
 > > The below seems to fix the problem for me, but I don't have enough 
 > > clue to know if its the correct fix, please advise.
 > 
 > > -	set_cyc2ns_scale(tsc_khz_ref, freq->cpu);
 > > +	set_cyc2ns_scale(tsc_khz, freq->cpu);
 > 
 > hm, that too is due to the tsc.c unification - Alok Cc:-ed. Applied your 
 > fix to x86/urgent.

ACKed-by: Dave Jones <davej@redhat.com>

Good catch Peter.  I'm puzzled how that bug was latent on 64bit
for so long with no-one realising though.

	Dave

-- 
http://www.codemonkey.org.uk

Re: [BUG] cpufreq: constant cpu_khz

[Ingo Molnar]

* Dave Jones <davej@codemonkey.org.uk> wrote:

>  > hm, that too is due to the tsc.c unification - Alok Cc:-ed. Applied 
>  > your fix to x86/urgent.
> 
> ACKed-by: Dave Jones <davej@redhat.com>
> 
> Good catch Peter.  I'm puzzled how that bug was latent on 64bit for so 
> long with no-one realising though.

i think it's the combination of these two factors:

 - bootup frequently is typically full-speed, so we calibrate things 
   right

 - cpufreq events are relatively slow-scale - and when they trigger the 
   system is definitely not under load. So how precisely the scheduler 
   functions isnt all that important in such scenarios - there's tons of
   CPU power available.

but it's indeed nice to have this fixed, and i just pushed the fix to 
Linus.

	Ingo

Re: [BUG] cpufreq: constant cpu_khz

[Arjan van de Ven]

On Mon, 25 Aug 2008 19:57:12 +0200
Ingo Molnar <mingo@elte.hu> wrote:

> 
> * Dave Jones <davej@codemonkey.org.uk> wrote:
> 
> >  > hm, that too is due to the tsc.c unification - Alok Cc:-ed.
> >  > Applied your fix to x86/urgent.
> > 
> > ACKed-by: Dave Jones <davej@redhat.com>
> > 
> > Good catch Peter.  I'm puzzled how that bug was latent on 64bit for
> > so long with no-one realising though.
> 
> i think it's the combination of these two factors:
> 
>  - bootup frequently is typically full-speed, so we calibrate things 
>    right
> 
>  - cpufreq events are relatively slow-scale - and when they trigger
> the system is definitely not under load. So how precisely the
> scheduler functions isnt all that important in such scenarios -
> there's tons of CPU power available.
> 

- many many of the 64 bit capable cpus are constant-tsc anyway

Re: [BUG] cpufreq: constant cpu_khz

[Peter Zijlstra]

On Mon, 2008-08-25 at 11:22 -0700, Arjan van de Ven wrote:
> On Mon, 25 Aug 2008 19:57:12 +0200
> Ingo Molnar <mingo@elte.hu> wrote:
> 
> > 
> > * Dave Jones <davej@codemonkey.org.uk> wrote:
> > 
> > >  > hm, that too is due to the tsc.c unification - Alok Cc:-ed.
> > >  > Applied your fix to x86/urgent.
> > > 
> > > ACKed-by: Dave Jones <davej@redhat.com>
> > > 
> > > Good catch Peter.  I'm puzzled how that bug was latent on 64bit for
> > > so long with no-one realising though.
> > 
> > i think it's the combination of these two factors:
> > 
> >  - bootup frequently is typically full-speed, so we calibrate things 
> >    right
> > 
> >  - cpufreq events are relatively slow-scale - and when they trigger
> > the system is definitely not under load. So how precisely the
> > scheduler functions isnt all that important in such scenarios -
> > there's tons of CPU power available.
> > 
> 
> - many many of the 64 bit capable cpus are constant-tsc anyway

Ironically I noticed it first on 64bit ;-)