* 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking.
@ 2003-06-28 21:31 Valdis.Kletnieks
2003-06-29 0:10 ` Andrew Morton
2003-07-01 0:25 ` john stultz
0 siblings, 2 replies; 7+ messages in thread
From: Valdis.Kletnieks @ 2003-06-28 21:31 UTC (permalink / raw)
To: linux-kernel
[-- Attachment #1: Type: text/plain, Size: 1570 bytes --]
2.5.73-mm1 is fine.
This is *not* the "clock runs really really fas"t issue - I left -mm2 running overnight and
in some 8 hours the system clock only drifted a few seconds versus wall clock (and it's
possible it was off a few seconds when it booted, as it didn't get an NTP sync at boot).
Audio plays "too fast" - a 4 minute .ogg goes through in about 3:40, sounding a bit
high-pitched in the process.
lspci -v:
00:1f.5 Multimedia audio controller: Intel Corp. 82801CA/CAM AC'97 Audio (rev 02)
Subsystem: Cirrus Logic: Unknown device 5959
Flags: bus master, medium devsel, latency 0, IRQ 11
I/O ports at d800 [size=256]
I/O ports at dc80 [size=64]
relevant dmesg output:
Advanced Linux Sound Architecture Driver Version 0.9.4 (Mon Jun 09 12:01:18 2003 UTC).
request_module: failed /sbin/modprobe -- snd-card-0. error = -16
PCI: Setting latency timer of device 0000:00:1f.5 to 64
intel8x0: clocking to 51084
ALSA sound/pci/intel8x0.c:2520: joystick(s) found
ALSA device list:
#0: Intel 82801CA-ICH3 at 0xd800, irq 11
The 'clocking to 51084' is *VERY* suspicious, as previously this value was
*always* 48000. Something very strange obviously happened in
intel8x0_measure_ac97_clock(), but I can't figure out what. I don't
think the mdelay(50) is off - the Bogomips value hasn't changed from 3185.04.
The problem is deterministic - on 3 reboots, I've gotten 51084 twice and 51085
once. Unless an odd latency is hitting spin_lock_irq(save,restore), I don't
see how that code can break?
Any ideas?
[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking.
2003-06-28 21:31 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking Valdis.Kletnieks
@ 2003-06-29 0:10 ` Andrew Morton
2003-06-29 18:10 ` Valdis.Kletnieks
2003-07-01 0:25 ` john stultz
1 sibling, 1 reply; 7+ messages in thread
From: Andrew Morton @ 2003-06-29 0:10 UTC (permalink / raw)
To: Valdis.Kletnieks; +Cc: linux-kernel
Valdis.Kletnieks@vt.edu wrote:
>
> This is *not* the "clock runs really really fas"t issue - I left -mm2 running overnight and
> in some 8 hours the system clock only drifted a few seconds versus wall clock (and it's
> possible it was off a few seconds when it booted, as it didn't get an NTP sync at boot).
>
> Audio plays "too fast" - a 4 minute .ogg goes through in about 3:40, sounding a bit
> high-pitched in the process.
>
> lspci -v:
> 00:1f.5 Multimedia audio controller: Intel Corp. 82801CA/CAM AC'97 Audio (rev 02)
> Subsystem: Cirrus Logic: Unknown device 5959
> Flags: bus master, medium devsel, latency 0, IRQ 11
> I/O ports at d800 [size=256]
> I/O ports at dc80 [size=64]
>
> relevant dmesg output:
> Advanced Linux Sound Architecture Driver Version 0.9.4 (Mon Jun 09 12:01:18 2003 UTC).
> request_module: failed /sbin/modprobe -- snd-card-0. error = -16
> PCI: Setting latency timer of device 0000:00:1f.5 to 64
> intel8x0: clocking to 51084
> ALSA sound/pci/intel8x0.c:2520: joystick(s) found
> ALSA device list:
> #0: Intel 82801CA-ICH3 at 0xd800, irq 11
>
> The 'clocking to 51084' is *VERY* suspicious
It could be that do_gettimeofday() has gone silly. Could you
add this patch and see what it says?
sound/pci/intel8x0.c | 6 ++----
1 files changed, 2 insertions(+), 4 deletions(-)
diff -puN sound/pci/intel8x0.c~intel8x0-cleanup sound/pci/intel8x0.c
--- 25/sound/pci/intel8x0.c~intel8x0-cleanup 2003-06-28 17:07:43.000000000 -0700
+++ 25-akpm/sound/pci/intel8x0.c 2003-06-28 17:09:07.000000000 -0700
@@ -2062,10 +2062,8 @@ static void __devinit intel8x0_measure_a
t = stop_time.tv_sec - start_time.tv_sec;
t *= 1000000;
- if (stop_time.tv_usec < start_time.tv_usec)
- t -= start_time.tv_usec - stop_time.tv_usec;
- else
- t += stop_time.tv_usec - start_time.tv_usec;
+ t += stop_time.tv_usec - start_time.tv_usec;
+ printk(KERN_INFO "%s: measured %lu usecs\n", __FUNCTION__, t);
if (t == 0) {
snd_printk(KERN_ERR "?? calculation error..\n");
return;
_
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking.
2003-06-29 0:10 ` Andrew Morton
@ 2003-06-29 18:10 ` Valdis.Kletnieks
2003-06-29 20:33 ` Alan Cox
0 siblings, 1 reply; 7+ messages in thread
From: Valdis.Kletnieks @ 2003-06-29 18:10 UTC (permalink / raw)
To: Andrew Morton; +Cc: linux-kernel, davej
[-- Attachment #1: Type: text/plain, Size: 4936 bytes --]
On Sat, 28 Jun 2003 17:10:36 PDT, Andrew Morton said:
> > The 'clocking to 51084' is *VERY* suspicious
>
> It could be that do_gettimeofday() has gone silly. Could you
> add this patch and see what it says?
Woo woo. Good catch, Andrew. It says:
intel8x0_measure_ac97_clock: measured 39909 usecs
Hmm.. wonder why it's 40K rather than the expected 50K...
Turns out we're running at 1.2G rather than 1.6G.. Or at least /proc/cpuinfo
says we are. However, things are not always what they seem....
Some testing indicates it's probably b0rkage in Dave Jone's recent work
splitting/reorging the speedstep driver....
cset-davej@codemonkey.org.uk|ChangeSet|20030626004701|05850.txt
(although the comments in the cset say Dominik Brodowski did the cleanups?)
after enabling debugging in arch/i386/kernel/cpu/cpufreq/cpufreq-ich.c
(which required the attached patch), we have this (annotated) dmesg output:
Machine check exception polling timer started.
OK, so we know approx where in boot we are now..
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x10300410 0x0
from speedstep_get_freqs()
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x10300410 0x0
cpufreq: read at pmbase 0x800 + 0x50 returned 0x0
cpufreq: writing 0x1 to pmbase 0x800 + 0x50
cpufreq: read at pmbase 0x800 + 0x50 returned 0x1
cpufreq: change to 0 MHz succeeded
all this from first call from get_freqs() to set_state(SPEEDSTEP_LOW,0);
Does that 'to 0mz' give you warm-n-fuzzies? Not me.... freqs.new isn't initialized yet...
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0xc300410 0x0
speedstep_get_freqs() checking that we actually went low
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0xc300410 0x0
cpufreq: read at pmbase 0x800 + 0x50 returned 0x1
cpufreq: writing 0x0 to pmbase 0x800 + 0x50
cpufreq: read at pmbase 0x800 + 0x50 returned 0x0
cpufreq: change to 1200 MHz succeeded
set_state(SPEEDSTEP_HIGH,0); and again we got the wrong value in
the message. We went *from* 1200 *to* 1600.
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x10300410 0x0
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x10300410 0x0
cpufreq: currently at high speed setting - 1600 MHz
speedstep_cpu_init();
cpufreq: speed=1600000 low=1200000 high=1600000
my debugging to make sure low/high were set right. All is good at this point,
and we return from speedstep_cpu_init().
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x10300410 0x0
cpufreq: read at pmbase 0x800 + 0x50 returned 0x0
cpufreq: writing 0x0 to pmbase 0x800 + 0x50
(remember - LOW is 1 and HIGH is 0 here)
cpufreq: read at pmbase 0x800 + 0x50 returned 0x0
cpufreq: change to 1200 MHz succeeded
Umm.. No. We went from 1.6G to 1.6G.
OK.. Who's the wise guy? ;)
Looks to me like cpufreq_add_device() calls cpufreq_set_policy(), which ends up
calling speedstep_set_state() with notify=1. Rememer the missing warm-n-fuzzies?
freqs.old = speedstep_get_processor_frequency(speedstep_processor);
freqs.new = speedstep_freqs[SPEEDSTEP_LOW].frequency;
freqs.cpu = 0; /* speedstep.c is UP only driver */
if (notify)
cpufreq_notify_transition(&freqs, CPUFREQ_PRECHANGE);
which ends up calling notify_transition() ends up calling adjust_jiffies(),
and things get pear-shaped ;)
If we're going from 1200 to 1600, this Does The Wrong Thing because
adjust_jiffies will be passed old == new == 1200 and fail to actually change
the loops_per_jiffy because the tests are > and <.
More subtly evil, when cpu_set_policy() runs, we go from 1600 to 1600, and
notify_transition is called with bogus values. So as a result,
adjust_jiffies() gets called with old=1600 new=1200, and we reset the jiffies
inappropriately. Meanwhile, similar evil happens in time_cpufreq_notifier(),
where cpu_khz will be incorrectly set to 1200. So cat /proc/cpuinfo
says we're at 1.2G when we're really still at 1.6G.
End result? Processor is running at 1.6G, /proc/cpuinfo *says* 1.2G, and
jiffies_per_loop is set for 1.2G. We call mdelay(50) at 1.6G and enough loops
for 1.2G, and end up at 80%. So the 50ms is really 40ms, and i810 gets the wrong
clocking.
And there's this remaining nit in speedstep_set_state():
if (state == (value & 0x1)) {
dprintk (KERN_INFO "cpufreq: change to %u MHz succeeded\n", (freqs.new / 1000));
} else {
Not initialized the first call, and even after will print the SPEEDSTEP_LOW number no matter what.
Oh, and the debugging patch:
--- arch/i386/kernel/cpu/cpufreq/speedstep-ich.c.dist 2003-06-29 10:34:17.949264614 -0400
+++ arch/i386/kernel/cpu/cpufreq/speedstep-ich.c 2003-06-29 10:36:34.833000667 -0400
@@ -295,7 +295,7 @@
return -EIO;
dprintk(KERN_INFO "cpufreq: currently at %s speed setting - %i MHz\n",
- (speed == speedstep_low_freq) ? "low" : "high",
+ (speed == speedstep_freqs[SPEEDSTEP_LOW].frequency) ? "low" : "high",
(speed / 1000));
/* cpuinfo and default policy values */
[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking.
2003-06-29 18:10 ` Valdis.Kletnieks
@ 2003-06-29 20:33 ` Alan Cox
2003-06-29 20:56 ` Valdis.Kletnieks
0 siblings, 1 reply; 7+ messages in thread
From: Alan Cox @ 2003-06-29 20:33 UTC (permalink / raw)
To: Valdis.Kletnieks; +Cc: Andrew Morton, Linux Kernel Mailing List, davej
On Sul, 2003-06-29 at 19:10, Valdis.Kletnieks@vt.edu wrote:
> > It could be that do_gettimeofday() has gone silly. Could you
> > add this patch and see what it says?
>
> Woo woo. Good catch, Andrew. It says:
>
> intel8x0_measure_ac97_clock: measured 39909 usecs
>
> Hmm.. wonder why it's 40K rather than the expected 50K...
Lots of laptops clock the i810 audio off an existing clock and software
fix up the difference. Saves components.
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking.
2003-06-29 20:33 ` Alan Cox
@ 2003-06-29 20:56 ` Valdis.Kletnieks
0 siblings, 0 replies; 7+ messages in thread
From: Valdis.Kletnieks @ 2003-06-29 20:56 UTC (permalink / raw)
To: Alan Cox; +Cc: Andrew Morton, Linux Kernel Mailing List, davej
[-- Attachment #1: Type: text/plain, Size: 382 bytes --]
On Sun, 29 Jun 2003 21:33:33 BST, Alan Cox said:
> > Hmm.. wonder why it's 40K rather than the expected 50K...
>
> Lots of laptops clock the i810 audio off an existing clock and software
> fix up the difference. Saves components.
And works fine until the speedstep stuff leaves you running at 1.6G
but jiffies_per_loop set for 1.2G, which is why mdelay(50) only
waited 40ms. ;)
[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking.
2003-06-28 21:31 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking Valdis.Kletnieks
2003-06-29 0:10 ` Andrew Morton
@ 2003-07-01 0:25 ` john stultz
2003-07-01 0:41 ` Valdis.Kletnieks
1 sibling, 1 reply; 7+ messages in thread
From: john stultz @ 2003-07-01 0:25 UTC (permalink / raw)
To: Valdis.Kletnieks; +Cc: lkml, Andrew Morton
On Sat, 2003-06-28 at 14:31, Valdis.Kletnieks@vt.edu wrote:
> 2.5.73-mm1 is fine.
>
> This is *not* the "clock runs really really fas"t issue - I left -mm2 running overnight and
> in some 8 hours the system clock only drifted a few seconds versus wall clock (and it's
> possible it was off a few seconds when it booted, as it didn't get an NTP sync at boot).
>
> Audio plays "too fast" - a 4 minute .ogg goes through in about 3:40, sounding a bit
> high-pitched in the process.
> Any ideas?
Hrmmm. Are you seeing something like:
Loosing too many ticks!
TSC cannot be used as a timesource. (Are you running with SpeedStep?)
Falling back to a sane timesource.
in your dmesg?
I just realized that in clock_fallback() from my lost-tick-speedstep-fix
we don't re-calibrate loops_per_jiffies. The conversion from cycles to
loops should be pretty close, but that might need some additional work.
Hrmmm..
-john
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking.
2003-07-01 0:25 ` john stultz
@ 2003-07-01 0:41 ` Valdis.Kletnieks
0 siblings, 0 replies; 7+ messages in thread
From: Valdis.Kletnieks @ 2003-07-01 0:41 UTC (permalink / raw)
To: john stultz; +Cc: lkml, Andrew Morton
[-- Attachment #1: Type: text/plain, Size: 895 bytes --]
On Mon, 30 Jun 2003 17:25:48 PDT, john stultz said:
> On Sat, 2003-06-28 at 14:31, Valdis.Kletnieks@vt.edu wrote:
> > 2.5.73-mm1 is fine.
> >
> > This is *not* the "clock runs really really fas"t issue - I left -mm2 runni
ng overnight and
> > in some 8 hours the system clock only drifted a few seconds versus wall clo
ck (and it's
> > possible it was off a few seconds when it booted, as it didn't get an NTP s
ync at boot).
> >
> > Audio plays "too fast" - a 4 minute .ogg goes through in about 3:40, soundi
ng a bit
> > high-pitched in the process.
>
> > Any ideas?
>
> Hrmmm. Are you seeing something like:
>
> Loosing too many ticks!
> TSC cannot be used as a timesource. (Are you running with SpeedStep?)
> Falling back to a sane timesource.
Nope, it's a pretty clear bug in the Speedstep code leaving loops_per_jiffies bogus.
I posted a follow-up note explaining in more detail...
[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2003-07-01 0:26 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2003-06-28 21:31 2.5.73-mm2 - odd audio problem, bad intel8x0/ac97 clocking Valdis.Kletnieks
2003-06-29 0:10 ` Andrew Morton
2003-06-29 18:10 ` Valdis.Kletnieks
2003-06-29 20:33 ` Alan Cox
2003-06-29 20:56 ` Valdis.Kletnieks
2003-07-01 0:25 ` john stultz
2003-07-01 0:41 ` Valdis.Kletnieks
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).