oops on resume

oops on resume

[Brian J. Murrell]

Distribution: Fedora Core/Rawhide
Hardware Environment: Dell Inspiron 4150
Software Environment: Fedora Core 2/Rawhide
Problem Description: when returning from a sleep, the kernel oopses

Steps to reproduce:
- boot kernel (fedora kernel 2.6.7-1.503 currently which is
2.6.8-rc2-bk11 according to the changelog in the kernel package)
- as root: "echo mem >/sys/power/state" and watch as it goes to sleep

Stopping tasks: ===============================================|
PM: Entering state.

- press power button to wake it up and watch on the console as it does:

Back to C!
zapping low mappings.
Warning: CPU frequency out of sync: cpufreq and timingcore thinks of 1200000, i.divide error: 0000 [#1]
Modules linked in: parport_pc(U) lp(U) parport(U) autofs4(U) ds(U) yenta_socket)CPU:    0
EIP:    0060:[<02111d75>]    Not tainted
EFLAGS: 00000216   (2.6.7-1.503custom)
EIP is at time_cpufreq_notifier+0x29c/0x2a3
eax: 0233f4e8   ebx: 00000891   ecx: 0021794a   edx: 0000080e
esi: 000003ea   edi: 002191c0   ebp: 00000000   esp: 2108cec0
ds: 0068   es: 007b   ss: 0068
Process bash (pid: 14500, threadinfo=2108c000 task=1f3b6030)
Stack: 0233ccc0 2108cef0 00000008 00000004 0212c929 2108cef0 21fcb684 023c1828
       02291741 02324a1e 00124f80 002191c0 00000000 00124f80 002191c0 0210ebc0
       0235edb4 023548e0 0222c151 00000000 00000002 00000246 0222f17c 021390ae
Call Trace:
 [<0212c929>] notifier_call_chain+0x17/0x2b
 [<02291741>] cpufreq_resume+0xa9/0xd1
 [<0210ebc0>] mtrr_restore+0x42/0x47
 [<0222c151>] sysdev_resume+0x55/0xa5
 [<0222f17c>] device_power_up+0x5/0xa
 [<021390ae>] suspend_enter+0x25/0x2d
 [<02139131>] enter_state+0x54/0x7f
 [<02139239>] state_store+0x84/0x99
 [<021391b5>] state_store+0x0/0x99
 [<021a56df>] subsys_attr_store+0x19/0x21
 [<021a5852>] flush_write_buffer+0x1d/0x22
 [<021a5879>] sysfs_write_file+0x22/0x35
 [<02160b77>] vfs_write+0xb6/0xe2
 [<02160c11>] sys_write+0x2c/0x42
Code: 31 c0 5b 5e 5f 5d c3 55 bd a4 cc 33 02 57 56 53 83 ec 24 8b

Any ideas?

b.

Re: oops on resume

[Dominik Brodowski]

On Thu, Aug 05, 2004 at 03:02:04PM -0400, Brian J. Murrell wrote:
> Warning: CPU frequency out of sync: cpufreq and timingcore thinks of 1200000, i.divide error: 0000 [#1]
> Modules linked in: parport_pc(U) lp(U) parport(U) autofs4(U) ds(U) yenta_socket)CPU:    0

Oops. Can you do a 

cat /sys/devices/system/cpu/cpu0/cpufreq/*

on a running system, please?

Thanks,

	Dominik

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 997 bytes --]

On Thu, 2004-08-05 at 21:26 +0200, Dominik Brodowski wrote:
> cat /sys/devices/system/cpu/cpu0/cpufreq/*

Just to be sure you knew which values where for which nodes I did a

grep ".*" /sys/devices/system/cpu/cpu0/cpufreq/*

and got:

/sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq:1200000
/sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq:2200000
/sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_min_freq:1200000
/sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies:2200000 1200000
/sys/devices/system/cpu/cpu0/cpufreq/scaling_available_governors:userspace performance
/sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq:1200000
/sys/devices/system/cpu/cpu0/cpufreq/scaling_driver:speedstep-ich
/sys/devices/system/cpu/cpu0/cpufreq/scaling_governor:userspace
/sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq:2200000
/sys/devices/system/cpu/cpu0/cpufreq/scaling_min_freq:1200000
/sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed:1200000

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dave Jones]

On Thu, Aug 05, 2004 at 03:34:42PM -0400, Brian J. Murrell wrote:
 > On Thu, 2004-08-05 at 21:26 +0200, Dominik Brodowski wrote:
 > > cat /sys/devices/system/cpu/cpu0/cpufreq/*
 > 
 > Just to be sure you knew which values where for which nodes I did a
 > 
 > grep ".*" /sys/devices/system/cpu/cpu0/cpufreq/*
 > 
 > and got:
 > 
 > /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq:1200000
 > /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq:2200000
 > /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_min_freq:1200000
 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies:2200000 1200000
 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_governors:userspace performance
 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq:1200000
 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_driver:speedstep-ich
 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor:userspace
 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq:2200000
 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_min_freq:1200000
 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed:1200000


My guess is that speedstep_get_processor_frequency() is returning null

What does /proc/cpuinfo say ?

		Dave

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 2625 bytes --]

On Thu, 2004-08-05 at 20:52 +0100, Dave Jones wrote:
> On Thu, Aug 05, 2004 at 03:34:42PM -0400, Brian J. Murrell wrote:
>  > On Thu, 2004-08-05 at 21:26 +0200, Dominik Brodowski wrote:
>  > > cat /sys/devices/system/cpu/cpu0/cpufreq/*
>  > 
>  > Just to be sure you knew which values where for which nodes I did a
>  > 
>  > grep ".*" /sys/devices/system/cpu/cpu0/cpufreq/*
>  > 
>  > and got:
>  > 
>  > /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq:1200000
>  > /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq:2200000
>  > /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_min_freq:1200000
>  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies:2200000 1200000
>  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_governors:userspace performance
>  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq:1200000
>  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_driver:speedstep-ich
>  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor:userspace
>  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq:2200000
>  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_min_freq:1200000
>  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed:1200000
> 
> 
> My guess is that speedstep_get_processor_frequency() is returning null
> 
> What does /proc/cpuinfo say ?

Right now:

processor       : 0
vendor_id       : GenuineIntel
cpu family      : 15
model           : 2
model name      : Mobile Intel(R) Pentium(R) 4 - M CPU 2.20GHz
stepping        : 7
cpu MHz         : 1196.613
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 mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe cid
bogomips        : 2359.29

After a bit of "cat </dev/urandom >/dev/null":

processor       : 0
vendor_id       : GenuineIntel
cpu family      : 15
model           : 2
model name      : Mobile Intel(R) Pentium(R) 4 - M CPU 2.20GHz
stepping        : 7
cpu MHz         : 2193.791
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 mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe cid
bogomips        : 4325.37

Do you want shall I enable SPEEDSTEP_DEBUG and see what comes out?

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dave Jones]

On Thu, Aug 05, 2004 at 04:02:50PM -0400, Brian J. Murrell wrote:
 > On Thu, 2004-08-05 at 20:52 +0100, Dave Jones wrote:
 > > On Thu, Aug 05, 2004 at 03:34:42PM -0400, Brian J. Murrell wrote:
 > >  > On Thu, 2004-08-05 at 21:26 +0200, Dominik Brodowski wrote:
 > >  > > cat /sys/devices/system/cpu/cpu0/cpufreq/*
 > >  > 
 > >  > Just to be sure you knew which values where for which nodes I did a
 > >  > 
 > >  > grep ".*" /sys/devices/system/cpu/cpu0/cpufreq/*
 > >  > 
 > >  > and got:
 > >  > 
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq:1200000
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq:2200000
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_min_freq:1200000
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies:2200000 1200000
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_governors:userspace performance
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq:1200000
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_driver:speedstep-ich
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor:userspace
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq:2200000
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_min_freq:1200000
 > >  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed:1200000
 > > 
 > > 
 > > My guess is that speedstep_get_processor_frequency() is returning null
 > > 
 > > What does /proc/cpuinfo say ?
 > 
 > Right now:
 > 
 > processor       : 0
 > vendor_id       : GenuineIntel
 > cpu family      : 15
 > model           : 2
 > model name      : Mobile Intel(R) Pentium(R) 4 - M CPU 2.20GHz

Interesting. http://processorfinder.intel.com/scripts/list.asp?ProcFam=826
shows that this has a 400MHz FSB. speedstep_get_processor_frequency()
doesn't support that, so that *could* be it. Although that should have
triggered this message..

    if (!fsb)
	        printk(KERN_DEBUG "speedstep-lib: couldn't detect FSB speed. Please send an e-mail to <linux@brodo.de>\n");

Very odd.

 > Do you want shall I enable SPEEDSTEP_DEBUG and see what comes out?

Might be useful, though right now, my bets are on an unknown FSB.

		Dave

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 717 bytes --]

On Thu, 2004-08-05 at 21:08 +0100, Dave Jones wrote:
> Although that should have
> triggered this message..
> 
>     if (!fsb)
> 	        printk(KERN_DEBUG "speedstep-lib: couldn't detect FSB speed. Please send an e-mail to <linux@brodo.de>\n");

At KERN_DEBUG though.  My /proc/sys/kernel/printk is at:

$ cat /proc/sys/kernel/printk
6       4       1       7

I don't recall how those 4 fields work.  Will I get KERN_DEBUG on the
console with those settings?

> Might be useful, though right now, my bets are on an unknown FSB.

Yeah, me too.  Any (one have any) idea how to calculate fsb for that
sucker?  I may as well throw that code in there too to see if it
alleviates the problem.

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dave Jones]

On Thu, Aug 05, 2004 at 04:19:30PM -0400, Brian J. Murrell wrote:

 > Yeah, me too.  Any (one have any) idea how to calculate fsb for that
 > sucker?

Hunting for docs on developer.intel.com right now. So far I've turned
up nothing useful. Can you edit pentium4_get_frequency() in arch/i386/kernel/cpu/cpufreq/speedstep-lib.c
so that before the switch (fsb_code) {   add a
		printk ("FSB code = %d\n", fsb_code);

Hopefully, Intel are predictable and this is going to be '4'.

 > I may as well throw that code in there too to see if it
 > alleviates the problem.

reminds me, moving speedstep's dprintk over to the same style
as longhaul/powernow-k7 should happen sometime, then it's just a
module parameter away instead of a recompile.

		Dave

Re: oops on resume

[Dominik Brodowski]

On Thu, Aug 05, 2004 at 09:29:41PM +0100, Dave Jones wrote:
> On Thu, Aug 05, 2004 at 04:19:30PM -0400, Brian J. Murrell wrote:
> 
>  > Yeah, me too.  Any (one have any) idea how to calculate fsb for that
>  > sucker?
> 
> Hunting for docs on developer.intel.com right now. So far I've turned
> up nothing useful. Can you edit pentium4_get_frequency() in arch/i386/kernel/cpu/cpufreq/speedstep-lib.c
> so that before the switch (fsb_code) {   add a
> 		printk ("FSB code = %d\n", fsb_code);

_and_ enable SPEEDSTEP_DEBUG in both speedstep-ich.c and speedstep-lib.c

> Hopefully, Intel are predictable and this is going to be '4'.
> 
>  > I may as well throw that code in there too to see if it
>  > alleviates the problem.
> 
> reminds me, moving speedstep's dprintk over to the same style
> as longhaul/powernow-k7 should happen sometime, then it's just a
> module parameter away instead of a recompile.

... though I'd prefer if it'd be done at the cpufreq-core level, i.e.
cpufreq_dprintk(); with a sysfs-exported ( /sys/parameters/cpufreq/debug )
boot-time parameter cpufreq.debug=1

	Dominik

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 820 bytes --]

On Thu, 2004-08-05 at 21:29 +0100, Dave Jones wrote:
> Can you edit pentium4_get_frequency() in arch/i386/kernel/cpu/cpufreq/speedstep-lib.c
> so that before the switch (fsb_code) {   add a
> 		printk ("FSB code = %d\n", fsb_code);
> 
> Hopefully, Intel are predictable and this is going to be '4'.

You are not going to believe this.  It's 0:

...
TC classifier action (bugs to netdev@oss.sgi.com cc hadi@cyberus.ca)
vesafb: probe of vesafb0 failed with error -6
Simple Boot Flag at 0x79 set to 0x1
FSB code = 0
FSB code = 0
FSB code = 0
FSB code = 0
apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac)
apm: overridden by ACPI.
...

I put a bunch more debug in there too:

FSB code = 0, msr_lo = 372247062
fsb = 100000
mult = 372247062
pentium4_get_frequency() returns = 2200000

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dave Jones]

On Thu, Aug 05, 2004 at 05:26:05PM -0400, Brian J. Murrell wrote:
 > On Thu, 2004-08-05 at 21:29 +0100, Dave Jones wrote:
 > > Can you edit pentium4_get_frequency() in arch/i386/kernel/cpu/cpufreq/speedstep-lib.c
 > > so that before the switch (fsb_code) {   add a
 > > 		printk ("FSB code = %d\n", fsb_code);
 > > 
 > > Hopefully, Intel are predictable and this is going to be '4'.
 > 
 > You are not going to believe this.  It's 0:

Ok, that matches Dominik's theory that it's a quad-pumped 100MHz bus.

		Dave

Re: oops on resume

[Dave Jones]

On Thu, Aug 05, 2004 at 05:26:05PM -0400, Brian J. Murrell wrote:

oops, I forgot to ask..

 > I put a bunch more debug in there too:
 > 
 > FSB code = 0, msr_lo = 372247062
 > fsb = 100000
 > mult = 372247062
 > pentium4_get_frequency() returns = 2200000

What does this print when you resume ?

		Dave

Re: oops on resume

[Dominik Brodowski]

On Thu, Aug 05, 2004 at 04:19:30PM -0400, Brian J. Murrell wrote:
>  > >  > /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies:2200000 1200000

This means speedstep_get_processor_frequency() works in the beginning -- else 
it wouldn't export these two (sane) values here.

> Interesting. http://processorfinder.intel.com/scripts/list.asp?ProcFam=826
> shows that this has a 400MHz FSB. speedstep_get_processor_frequency()
> doesn't support that, so that *could* be it. Although that should have
> triggered this message..

it's the quad-pumped 100MHz FSB which is as effictive as a 400MHz, so this
shouldn't be the problem.

> Might be useful, though right now, my bets are on an unknown FSB.
What do I win ;-) ?


My bet is that speedstep_get_processor_frequency() returns something 
between one and 100000 kHz instead of the proper value _only_ _upon_
_resuming_. So it'd be great if you could enable SPEEDSTEP_DEBUG in both
files mentioned above, re-test the "resume process", and tell us what the
lines right before the oops say.

Thanks,
	Dominik

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 2571 bytes --]

On Thu, 2004-08-05 at 23:09 +0200, Dominik Brodowski wrote:
> My bet is that speedstep_get_processor_frequency() returns something 
> between one and 100000 kHz instead of the proper value _only_ _upon_
> _resuming_.

Yeah.

> So it'd be great if you could enable SPEEDSTEP_DEBUG in both
> files mentioned above, re-test the "resume process", and tell us what the
> lines right before the oops say.

OK.  BTW: while building I got a compile error:

arch/i386/kernel/cpu/cpufreq/speedstep-smi.c: In function `speedstep_set_state':arch/i386/kernel/cpu/cpufreq/speedstep-smi.c:183: error: `freqs' undeclared (first use in this function)

I worked around that to get it to build, but something needs fixing
there, obviously.

The messages I get before the oops (and the oops for posterity):

Back to C!
zapping low mappings.
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x16300a16 0x0
FSB code = 0, msr_lo = 372247062
fsb = 100000
mult = 372247062
speedstep-lib: P4 - FSB 100000 kHz; Multiplier 22
pentium4_get_frequency() returns = 2200000
Warning: CPU frequency out of sync: cpufreq and timingcore thinks of 1200000, i.do_div(4757913600000, 2200000)
do_div(4826899000000, 2200000)
do_div(4306623200000, 2200000)
divide error: 0000 [#1]
Modules linked in: parport_pc(U) lp(U) parport(U) autofs4(U) ds(U) yenta_socket)CPU:    0
EIP:    0060:[<02111f15>]    Not tainted
EFLAGS: 00000216   (2.6.7-1.503custom)
EIP is at time_cpufreq_notifier+0x29c/0x2a3
eax: 0233f4e8   ebx: 00000892   ecx: 00217a7d   edx: 0000063c
esi: 000003ea   edi: 002191c0   ebp: 00000000   esp: 20704ec0
ds: 0068   es: 007b   ss: 0068
Process bash (pid: 3853, threadinfo=20704000 task=1f6b6630)
Stack: 0233ccc0 20704ef0 00000008 00000004 0212c929 20704ef0 21f6b684 023c1828
       02291741 02324d42 00124f80 002191c0 00000000 00124f80 002191c0 0210ebc0
       0235edb4 023548e0 0222c151 00000000 00000002 00000246 0222f17c 021390ae
Call Trace:
 [<0212c929>] notifier_call_chain+0x17/0x2b
 [<02291741>] cpufreq_resume+0xa9/0xd1
 [<0210ebc0>] mtrr_restore+0x42/0x47
 [<0222c151>] sysdev_resume+0x55/0xa5
 [<0222f17c>] device_power_up+0x5/0xa
 [<021390ae>] suspend_enter+0x25/0x2d
 [<02139131>] enter_state+0x54/0x7f
 [<02139239>] state_store+0x84/0x99
 [<021391b5>] state_store+0x0/0x99
 [<021a56df>] subsys_attr_store+0x19/0x21
 [<021a5852>] flush_write_buffer+0x1d/0x22
 [<021a5879>] sysfs_write_file+0x22/0x35
 [<02160b77>] vfs_write+0xb6/0xe2
 [<02160c11>] sys_write+0x2c/0x42
Code: 31 c0 5b 5e 5f 5d c3 55 bd a4 cc 33 02 57 56 53 83 ec 24 8b


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dominik Brodowski]

[Sidenote: hopefully this message won't be blocked by your blacklist.]

On Thu, Aug 05, 2004 at 05:45:37PM -0400, Brian J. Murrell wrote:
> On Thu, 2004-08-05 at 23:09 +0200, Dominik Brodowski wrote:
> > My bet is that speedstep_get_processor_frequency() returns something 
> > between one and 100000 kHz instead of the proper value _only_ _upon_
> > _resuming_.
> 
> Yeah.

But I lost my bet, too... 

> OK.  BTW: while building I got a compile error:
> 
> arch/i386/kernel/cpu/cpufreq/speedstep-smi.c: In function `speedstep_set_state':arch/i386/kernel/cpu/cpufreq/speedstep-smi.c:183: error: `freqs' undeclared (first use in this function)

Thanks, it's fixed in the current version, which hopefully will get into 2.6.8.

> The messages I get before the oops (and the oops for posterity):
> 
> Back to C!
> zapping low mappings.
> speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x16300a16 0x0
> FSB code = 0, msr_lo = 372247062
> fsb = 100000
> mult = 372247062
> speedstep-lib: P4 - FSB 100000 kHz; Multiplier 22
> pentium4_get_frequency() returns = 2200000

... which is absolutely correct.

> Warning: CPU frequency out of sync: cpufreq and timingcore thinks of 1200000, i.
> do_div(4757913600000, 2200000)
> do_div(4826899000000, 2200000)
> do_div(4306623200000, 2200000)

... these divides look sane to me, too.

1st (should) return(s) 2162688 loops per jiffies...
2nd (should) return(s) 2194045 kHz ~ 2.2 GHz
3rd (should) return(s) 1957556 as fast_gettimeoffset_quotient.

Next thing is:

		set_cyc2ns_scale(cpu_khz/1000);

cpu_khz was set a few lines above to (hopefully) 2194045;
(inlined) set_cyc2ns_scale() consists of only one instruction:

	cyc2ns_scale = (1000 << CYC2NS_SCALE_FACTOR)/cpu_mhz;

and then time_cpufreq_notifier() exits with one further instruction:

	write_sequnlock_irq(&xtime_lock);

	return 0;


So that's _really_ strange. Could you add a "debug trap" in the form of

	printk("I got here!\n");
before set_cyc2ns_scale, the write_sequnlock_irq and the return statement?
Then we'll hopefully know for sure what breaks.

Thanks,
	Dominik

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 4961 bytes --]

On Thu, 2004-08-05 at 23:09 +0200, Dominik Brodowski wrote:
> 
> My bet is that speedstep_get_processor_frequency() returns something 
> between one and 100000 kHz instead of the proper value _only_ _upon_
> _resuming_.

What do _I_ win?  :-)

>  So it'd be great if you could enable SPEEDSTEP_DEBUG in both
> files mentioned above, re-test the "resume process", and tell us what the
> lines right before the oops say.

OK, enabled, and a boatload of other debug that I inserted in there:

Back to C!
zapping low mappings.
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x16300a16 0x0
FSB code = 0, msr_lo = 372247062
fsb = 100000
mult = 372247062
speedstep-lib: P4 - FSB 100000 kHz; Multiplier 22
pentium4_get_frequency() returns = 2200000
Warning: CPU frequency out of sync: cpufreq and timingcore thinks of 1200000, is 2200000 kHz.
here we are in time_cpufreq_notifier 0
here we are in time_cpufreq_notifier 1
here we are in cpufreq_scale 0, old = 2162688, div = 2200000, mult = 2200000
calling do_div(4757913600000, 2200000)
here we are in cpufreq_scale 1, returning 2162688
here we are in cpufreq_scale 0, old = 2193684, div = 2200000, mult = 2200000
calling do_div(4826104800000, 2200000)
here we are in cpufreq_scale 1, returning 2193684
here we are in time_cpufreq_notifier 2, cpu_khz = 2193684
here we are in cpufreq_scale 0, old = 1957878, div = 2200000, mult = 2200000
calling do_div(4307331600000, 2200000)
here we are in cpufreq_scale 1, returning 1957878
here we are in time_cpufreq_notifier 3, fast_gettimeoffset_quotient = 1957878
here we are in set_cyc2ns_scale 0, cpu_mhz = 2193
here we are in time_cpufreq_notifier 4
here we are in time_cpufreq_notifier 5
divide error: 0000 [#1]
Modules linked in: parport_pc(U) lp(U) parport(U) autofs4(U) ds(U) yenta_socket(U) pcmcia_core(U) sunrpc(U) 3c59x(U) floppy(U) sg(U) scsi_mod(U) dm_mod(U) uhci_hcd(U) button(U) battery(U) asus_acpi(U) ac(U) radeon(U) md5(U) ipv6(U) ext3(U)
jbd(U)
CPU:    0
EIP:    0060:[<02111fd6>]    Not tainted
EFLAGS: 00000202   (2.6.7-1.503custom)
EIP is at time_cpufreq_notifier+0x35d/0x36c
eax: 0233f4e8   ebx: 00000891   ecx: 0233d480   edx: 00000000
esi: 00000891   edi: 02302986   ebp: 001ddff6   esp: 204f4eb4
ds: 0068   es: 007b   ss: 0068
Process bash (pid: 4250, threadinfo=204f4000 task=1eca5830)
Stack: 02302a53 e0f84e80 00000000 0233ccc0 204f4ef0 00000008 00000004 0212c929
       204f4ef0 21f6b684 023c1828 02291741 02324f2b 00124f80 002191c0 00000000
       00124f80 002191c0 0210ebc0 0235edb4 023548e0 0222c151 00000000 00000002
Call Trace:
 [<0212c929>] notifier_call_chain+0x17/0x2b
 [<02291741>] cpufreq_resume+0xa9/0xd1
 [<0210ebc0>] mtrr_restore+0x42/0x47
 [<0222c151>] sysdev_resume+0x55/0xa5
 [<0222f17c>] device_power_up+0x5/0xa
 [<021390ae>] suspend_enter+0x25/0x2d
 [<02139131>] enter_state+0x54/0x7f
 [<02139239>] state_store+0x84/0x99
 [<021391b5>] state_store+0x0/0x99
 [<021a56df>] subsys_attr_store+0x19/0x21
 [<021a5852>] flush_write_buffer+0x1d/0x22
 [<021a5879>] sysfs_write_file+0x22/0x35
 [<02160b77>] vfs_write+0xb6/0xe2
 [<02160c11>] sys_write+0x2c/0x42
Code: e8 cd ce 00 00 83 c4 0c 31 c0 5b 5e 5f 5d c3 55 bd a4 cc 33

Here is my printk littered time_cpufreq_notifier to correlate all those
messages above:

static int
time_cpufreq_notifier(struct notifier_block *nb, unsigned long val,
		       void *data)
{
	struct cpufreq_freqs *freq = data;

printk("here we are in time_cpufreq_notifier 0\n");
	write_seqlock_irq(&xtime_lock);
	if (!ref_freq) {
		ref_freq = freq->old;
		loops_per_jiffy_ref = cpu_data[freq->cpu].loops_per_jiffy;
#ifndef CONFIG_SMP
		fast_gettimeoffset_ref = fast_gettimeoffset_quotient;
		cpu_khz_ref = cpu_khz;
#endif
	}

	if ((val == CPUFREQ_PRECHANGE  && freq->old < freq->new) ||
	    (val == CPUFREQ_POSTCHANGE && freq->old > freq->new) ||
	    (val == CPUFREQ_RESUMECHANGE)) {
printk("here we are in time_cpufreq_notifier 1\n");
		if (!(freq->flags & CPUFREQ_CONST_LOOPS))
			cpu_data[freq->cpu].loops_per_jiffy = cpufreq_scale(loops_per_jiffy_ref, ref_freq, freq->new);
#ifndef CONFIG_SMP
		if (cpu_khz)
			cpu_khz = cpufreq_scale(cpu_khz_ref, ref_freq, freq->new);
printk("here we are in time_cpufreq_notifier 2, cpu_khz = %lu\n", cpu_khz);
		if (use_tsc) {
			if (!(freq->flags & CPUFREQ_CONST_LOOPS)) {
				fast_gettimeoffset_quotient = cpufreq_scale(fast_gettimeoffset_ref, freq->new, ref_freq);
printk("here we are in time_cpufreq_notifier 3, fast_gettimeoffset_quotient = %lu\n", fast_gettimeoffset_quotient);
				set_cyc2ns_scale(cpu_khz/1000);
			}
		}
#endif
printk("here we are in time_cpufreq_notifier 4\n");
	}
printk("here we are in time_cpufreq_notifier 5\n");
	write_sequnlock_irq(&xtime_lock);
printk("here we are in time_cpufreq_notifier 6\n");

	return 0;
}

Notice in the debug output, we never get the "here we are in
time_cpufreq_notifier 6" message.

Thots?

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dominik Brodowski]

On Fri, Aug 06, 2004 at 01:43:34PM -0400, Brian J. Murrell wrote:
> printk("here we are in time_cpufreq_notifier 5\n");
> 	write_sequnlock_irq(&xtime_lock);
> printk("here we are in time_cpufreq_notifier 6\n");

So _this_ is where it fails... Davej, any idea?

	Dominik

Re: oops on resume

[Dave Jones]

On Fri, Aug 06, 2004 at 07:55:30PM +0200, Dominik Brodowski wrote:
 > On Fri, Aug 06, 2004 at 01:43:34PM -0400, Brian J. Murrell wrote:
 > > printk("here we are in time_cpufreq_notifier 5\n");
 > > 	write_sequnlock_irq(&xtime_lock);
 > > printk("here we are in time_cpufreq_notifier 6\n");
 > 
 > So _this_ is where it fails... Davej, any idea?

Why on _earth_ would that divide by zero ?!
I'd like to see an objdump -D output of that function.
What compiler was used?

		Dave

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 550 bytes --]

On Fri, 2004-08-06 at 22:13 +0100, Dave Jones wrote:
> Why on _earth_ would that divide by zero ?!

You got me.  :-)

> I'd like to see an objdump -D output of that function.

How do I do that?

> What compiler was used?

Whatever is on rawhide at the moment... 

$ gcc --version
gcc (GCC) 3.4.1 20040714 (Red Hat 3.4.1-7)
Copyright (C) 2004 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dave Jones]

On Fri, Aug 06, 2004 at 05:18:29PM -0400, Brian J. Murrell wrote:
 > On Fri, 2004-08-06 at 22:13 +0100, Dave Jones wrote:
 > > Why on _earth_ would that divide by zero ?!
 > 
 > You got me.  :-)
 > 
 > > I'd like to see an objdump -D output of that function.
 > 
 > How do I do that?

no worries because..

 > > What compiler was used?
 > Whatever is on rawhide at the moment... 

I have that locally.

Can you add some debug printk's just before the cpufreq_scale() calls
in time_cpufreq_notifier ?  I'd like to know what's being passed there.
Might be worth a printk actually _in_ cpufreq_scale() too, to make
sure the args are getting through ok.

		Dave

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 3060 bytes --]

On Fri, 2004-08-06 at 22:44 +0100, Dave Jones wrote:
> 
> I have that locally.

Heh.  Yeah, I guess so.

> Can you add some debug printk's just before the cpufreq_scale() calls
> in time_cpufreq_notifier ?  I'd like to know what's being passed there.
> Might be worth a printk actually _in_ cpufreq_scale() too, to make
> sure the args are getting through ok.

Here it is:

Back to C!
zapping low mappings.
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x16300a16 0x0
FSB code = 0, msr_lo = 372247062
fsb = 100000
mult = 372247062
speedstep-lib: P4 - FSB 100000 kHz; Multiplier 22
pentium4_get_frequency() returns = 2200000
Warning: CPU frequency out of sync: cpufreq and timingcore thinks of 1200000, i.here we are in time_cpufreq_notifier 0
here we are in time_cpufreq_notifier 1
calling cpufreq_scale(2162688, 2200000, 2200000)
here we are in cpufreq_scale 0, old = 2162688, div = 2200000, mult = 2200000
calling do_div(4757913600000, 2200000)
here we are in cpufreq_scale 1, returning 2162688
calling cpufreq_scale(2193684, 2200000, 2200000)
here we are in cpufreq_scale 0, old = 2193684, div = 2200000, mult = 2200000
calling do_div(4826104800000, 2200000)
here we are in cpufreq_scale 1, returning 2193684
here we are in time_cpufreq_notifier 2, cpu_khz = 2193684
calling cpufreq_scale(1957878, 2200000, 2200000)
here we are in cpufreq_scale 0, old = 1957878, div = 2200000, mult = 2200000
calling do_div(4307331600000, 2200000)
here we are in cpufreq_scale 1, returning 1957878
here we are in time_cpufreq_notifier 3, fast_gettimeoffset_quotient = 1957878
here we are in set_cyc2ns_scale 0, cpu_mhz = 2193
here we are in time_cpufreq_notifier 4
here we are in time_cpufreq_notifier 5
divide error: 0000 [#1]
Modules linked in: parport_pc(U) lp(U) parport(U) autofs4(U) ds(U) yenta_socket)CPU:    0
EIP:    0060:[<02112032>]    Not tainted
EFLAGS: 00000202   (2.6.7-1.503custom)
EIP is at time_cpufreq_notifier+0x3b9/0x3c8
eax: 0233f4e8   ebx: 00000891   ecx: 0233d480   edx: 00000000
esi: 00000891   edi: 023029aa   ebp: 001ddff6   esp: 21162eb4
ds: 0068   es: 007b   ss: 0068
Process bash (pid: 4695, threadinfo=21162000 task=1ecde130)
Stack: 02302a77 e0f84e80 00000000 0233ccc0 21162ef0 00000008 00000004 0212c929
       21162ef0 21f6b684 023c1828 02291741 02324f4f 00124f80 002191c0 00000000
       00124f80 002191c0 0210ebc0 0235edb4 023548e0 0222c151 00000000 00000002
Call Trace:
 [<0212c929>] notifier_call_chain+0x17/0x2b
 [<02291741>] cpufreq_resume+0xa9/0xd1
 [<0210ebc0>] mtrr_restore+0x42/0x47
 [<0222c151>] sysdev_resume+0x55/0xa5
 [<0222f17c>] device_power_up+0x5/0xa
 [<021390ae>] suspend_enter+0x25/0x2d
 [<02139131>] enter_state+0x54/0x7f
 [<02139239>] state_store+0x84/0x99
 [<021391b5>] state_store+0x0/0x99
 [<021a56df>] subsys_attr_store+0x19/0x21
 [<021a5852>] flush_write_buffer+0x1d/0x22
 [<021a5879>] sysfs_write_file+0x22/0x35
 [<02160b77>] vfs_write+0xb6/0xe2
 [<02160c11>] sys_write+0x2c/0x42
Code: e8 71 ce 00 00 83 c4 0c 31 c0 5b 5e 5f 5d c3 55 bd a4 cc 33


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dave Jones]

On Fri, Aug 06, 2004 at 06:10:28PM -0400, Brian J. Murrell wrote:

 > here we are in time_cpufreq_notifier 1
 > calling cpufreq_scale(2162688, 2200000, 2200000)
 > here we are in cpufreq_scale 0, old = 2162688, div = 2200000, mult = 2200000
 > calling do_div(4757913600000, 2200000)
 > here we are in cpufreq_scale 1, returning 2162688
 > calling cpufreq_scale(2193684, 2200000, 2200000)
 > here we are in cpufreq_scale 0, old = 2193684, div = 2200000, mult = 2200000
 > calling do_div(4826104800000, 2200000)
 > here we are in cpufreq_scale 1, returning 2193684
 > here we are in time_cpufreq_notifier 2, cpu_khz = 2193684
 > calling cpufreq_scale(1957878, 2200000, 2200000)
 > here we are in cpufreq_scale 0, old = 1957878, div = 2200000, mult = 2200000
 > calling do_div(4307331600000, 2200000)
 > here we are in cpufreq_scale 1, returning 1957878
 > here we are in time_cpufreq_notifier 3, fast_gettimeoffset_quotient = 1957878
 > here we are in set_cyc2ns_scale 0, cpu_mhz = 2193

Did you get the 3rd cpufreq_scale() call too ? I think that might be
the one thats going awry.

(The one in the fast_gettimeoffset_quotient = .. line)

		Dave

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 1451 bytes --]

On Fri, 2004-08-06 at 23:51 +0100, Dave Jones wrote:
> On Fri, Aug 06, 2004 at 06:10:28PM -0400, Brian J. Murrell wrote:
> 
>  > here we are in time_cpufreq_notifier 1
> 1> calling cpufreq_scale(2162688, 2200000, 2200000)
> 1> here we are in cpufreq_scale 0, old = 2162688, div = 2200000, mult = 2200000
> 1> calling do_div(4757913600000, 2200000)
> 1> here we are in cpufreq_scale 1, returning 2162688
> 2> calling cpufreq_scale(2193684, 2200000, 2200000)
> 2> here we are in cpufreq_scale 0, old = 2193684, div = 2200000, mult = 2200000
> 2> calling do_div(4826104800000, 2200000)
> 2> here we are in cpufreq_scale 1, returning 2193684
>  > here we are in time_cpufreq_notifier 2, cpu_khz = 2193684
> 3> calling cpufreq_scale(1957878, 2200000, 2200000)
> 3> here we are in cpufreq_scale 0, old = 1957878, div = 2200000, mult = 2200000
> 3> calling do_div(4307331600000, 2200000)
> 3> here we are in cpufreq_scale 1, returning 1957878
>  > here we are in time_cpufreq_notifier 3, fast_gettimeoffset_quotient = 1957878
>  > here we are in set_cyc2ns_scale 0, cpu_mhz = 2193
> 
> Did you get the 3rd cpufreq_scale() call too ? I think that might be
> the one thats going awry.

Those are the three up there aren't they?  I've prefixed each block of
debug with the number of the cpufreq_scale() call.  I could be mistaken.

> (The one in the fast_gettimeoffset_quotient = .. line)

Yup, that's #3 up there isn't it?

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dave Jones]

On Fri, Aug 06, 2004 at 07:00:15PM -0400, Brian J. Murrell wrote:
 > On Fri, 2004-08-06 at 23:51 +0100, Dave Jones wrote:
 > > On Fri, Aug 06, 2004 at 06:10:28PM -0400, Brian J. Murrell wrote:
 > > 
 > >  > here we are in time_cpufreq_notifier 1
 > > 1> calling cpufreq_scale(2162688, 2200000, 2200000)
 > > 1> here we are in cpufreq_scale 0, old = 2162688, div = 2200000, mult = 2200000
 > > 1> calling do_div(4757913600000, 2200000)
 > > 1> here we are in cpufreq_scale 1, returning 2162688
 > > 2> calling cpufreq_scale(2193684, 2200000, 2200000)
 > > 2> here we are in cpufreq_scale 0, old = 2193684, div = 2200000, mult = 2200000
 > > 2> calling do_div(4826104800000, 2200000)
 > > 2> here we are in cpufreq_scale 1, returning 2193684
 > >  > here we are in time_cpufreq_notifier 2, cpu_khz = 2193684
 > > 3> calling cpufreq_scale(1957878, 2200000, 2200000)
 > > 3> here we are in cpufreq_scale 0, old = 1957878, div = 2200000, mult = 2200000
 > > 3> calling do_div(4307331600000, 2200000)
 > > 3> here we are in cpufreq_scale 1, returning 1957878
 > >  > here we are in time_cpufreq_notifier 3, fast_gettimeoffset_quotient = 1957878
 > >  > here we are in set_cyc2ns_scale 0, cpu_mhz = 2193
 > > 
 > > Did you get the 3rd cpufreq_scale() call too ? I think that might be
 > > the one thats going awry.
 > 
 > Those are the three up there aren't they?  I've prefixed each block of
 > debug with the number of the cpufreq_scale() call.  I could be mistaken.
 > 
 > > (The one in the fast_gettimeoffset_quotient = .. line)
 > 
 > Yup, that's #3 up there isn't it?

oops, couldnt see the wood for the trees.

hmm, puzzled.

		Dave

Re: oops on resume

[Dominik Brodowski]

On Fri, Aug 06, 2004 at 07:55:30PM +0200, Dominik Brodowski wrote:
> On Fri, Aug 06, 2004 at 01:43:34PM -0400, Brian J. Murrell wrote:
> > printk("here we are in time_cpufreq_notifier 5\n");
> > 	write_sequnlock_irq(&xtime_lock);
> > printk("here we are in time_cpufreq_notifier 6\n");
> 
> So _this_ is where it fails... Davej, any idea?

Might it be that interrupts are still disabled during the RESUME
notification, and 

#define write_sequnlock_irq(lock)                                       \
        do { write_sequnlock(lock); local_irq_enable(); } while(0)

tries to enable them?

Thanks,
	Dominik

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 575 bytes --]

On Sat, 2004-08-07 at 15:24 +0200, Dominik Brodowski wrote:
> 
> Might it be that interrupts are still disabled during the RESUME
> notification, and 
> 
> #define write_sequnlock_irq(lock)                                       \
>         do { write_sequnlock(lock); local_irq_enable(); } while(0)
> 
> tries to enable them?

But that sounds like such a fundamental issue that surely I would not be
the first person to find it, especially considering how long even I was
seeing it before I found the time to work it up into a bug report.

Am I wrong?

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dominik Brodowski]

On Sat, Aug 07, 2004 at 03:03:42PM -0400, Brian J. Murrell wrote:
> On Sat, 2004-08-07 at 15:24 +0200, Dominik Brodowski wrote:
> > 
> > Might it be that interrupts are still disabled during the RESUME
> > notification, and 
> > 
> > #define write_sequnlock_irq(lock)                                       \
> >         do { write_sequnlock(lock); local_irq_enable(); } while(0)
> > 
> > tries to enable them?
> 
> But that sounds like such a fundamental issue that surely I would not be
> the first person to find it, especially considering how long even I was
> seeing it before I found the time to work it up into a bug report.

Problem is, I don't use the resume funcitonality on my notebook as that's
only available with the "vga" video driver instead of "i830"; and I can't
even try it now as my notebook is in quite a sick state [disk corruption!]
caused either by Ingo's voluntary-preempt patches or some experimenting by
myself, which accessed free'd data as if it were non-free'd...

Anyways, I've prepared a patch to work around the "local_irq_enable()" call.
Could you test it, please?

	Dominik

diff -ruN linux-original/arch/i386/kernel/timers/timer_tsc.c linux/arch/i386/kernel/timers/timer_tsc.c
--- linux-original/arch/i386/kernel/timers/timer_tsc.c	2004-08-05 17:44:47.000000000 +0200
+++ linux/arch/i386/kernel/timers/timer_tsc.c	2004-08-08 18:23:27.791458408 +0200
@@ -265,7 +265,8 @@
 {
 	struct cpufreq_freqs *freq = data;
 
-	write_seqlock_irq(&xtime_lock);
+	if (val != CPUFREQ_RESUMECHANGE)
+		write_seqlock_irq(&xtime_lock);
 	if (!ref_freq) {
 		ref_freq = freq->old;
 		loops_per_jiffy_ref = cpu_data[freq->cpu].loops_per_jiffy;
@@ -291,7 +292,9 @@
 		}
 #endif
 	}
-	write_sequnlock_irq(&xtime_lock);
+
+	if (val != CPUFREQ_RESUMECHANGE)
+		write_sequnlock_irq(&xtime_lock);
 
 	return 0;
 }

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 636 bytes --]

On Sun, 2004-08-08 at 18:24 +0200, Dominik Brodowski wrote:
> 
> Problem is, I don't use the resume funcitonality on my notebook

But surely lots of people are.  If the patch below were necessary and
correct, would not a lot more people be having the same problem?  Unless
I am mis-understanding the intent of the patch.  Do you mean it as a
further test/confirmation that write_seqlock_irq() is the culprit or do
you mean the patch as the solution to my problem?

> Anyways, I've prepared a patch to work around the "local_irq_enable()" call.
> Could you test it, please?

Sure.  I will let you know how it does.

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dominik Brodowski]

On Mon, Aug 09, 2004 at 09:37:46AM -0400, Brian J. Murrell wrote:
> On Sun, 2004-08-08 at 18:24 +0200, Dominik Brodowski wrote:
> > 
> > Problem is, I don't use the resume funcitonality on my notebook
> 
> But surely lots of people are.  If the patch below were necessary and
> correct, would not a lot more people be having the same problem?

Not necessarily. Bugs are sometimes very difficult to trigger.

> Unless
> I am mis-understanding the intent of the patch.  Do you mean it as a
> further test/confirmation that write_seqlock_irq() is the culprit or do
> you mean the patch as the solution to my problem?

It's actually a try for a solution.

Thanks,
	Dominik

Re: oops on resume

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 3293 bytes --]

On Sun, 2004-08-08 at 18:24 +0200, Dominik Brodowski wrote:
> 
> Anyways, I've prepared a patch to work around the "local_irq_enable()" call.
> Could you test it, please?

No oops this time, but here is the console output:

Back to C!
zapping low mappings.
speedstep-lib: P4 - MSR_EBC_FREQUENCY_ID: 0x16300a16 0x0
FSB code = 0, msr_lo = 372247062
fsb = 100000
mult = 372247062
speedstep-lib: P4 - FSB 100000 kHz; Multiplier 22
pentium4_get_frequency() returns = 2200000
Warning: CPU frequency out of sync: cpufreq and timingcore thinks of 1200000, is 2200000 kHz.
here we are in time_cpufreq_notifier 0
here we are in time_cpufreq_notifier 1
calling cpufreq_scale(2162688, 2200000, 2200000)
here we are in cpufreq_scale 0, old = 2162688, div = 2200000, mult = 2200000
calling do_div(4757913600000, 2200000)
here we are in cpufreq_scale 1, returning 2162688
calling cpufreq_scale(2193778, 2200000, 2200000)
here we are in cpufreq_scale 0, old = 2193778, div = 2200000, mult = 2200000
calling do_div(4826311600000, 2200000)
here we are in cpufreq_scale 1, returning 2193778
here we are in time_cpufreq_notifier 2, cpu_khz = 2193778
calling cpufreq_scale(1957794, 2200000, 2200000)
here we are in cpufreq_scale 0, old = 1957794, div = 2200000, mult = 2200000
calling do_div(4307146800000, 2200000)
here we are in cpufreq_scale 1, returning 1957794
here we are in time_cpufreq_notifier 3, fast_gettimeoffset_quotient = 1957794
here we are in set_cyc2ns_scale 0, cpu_mhz = 2193
here we are in time_cpufreq_notifier 4
here we are in time_cpufreq_notifier 5
here we are in time_cpufreq_notifier 6
here we are in cpufreq_scale 0, old = 2162688, div = 2200000, mult = 2200000
calling do_div(4757913600000, 2200000)
here we are in cpufreq_scale 1, returning 2162688
PM: Finishing up.
PCI: Setting latency timer of device 0000:00:1d.0 to 64
PCI: Setting latency timer of device 0000:00:1d.0 to 64
ACPI: PCI interrupt 0000:00:1f.1[A] -> GSI 11 (level, low) -> IRQ 11
eth0: command 0x5800 did not complete! Status=0xffff
eth0: command 0x2804 did not complete! Status=0xffff
drivers/acpi/osl.c:737: spin_lock(drivers/acpi/osl.c:21fe0bf8) already locked by drivers/acpi/osl.c/737
drivers/acpi/osl.c:756: spin_unlock(drivers/acpi/osl.c:21fe0bf8) not locked
Restarting tasks... done
eth0: command 0x3002 did not complete! Status=0xffff
eth0: command 0x3002 did not complete! Status=0xffff
eth0: command 0x3002 did not complete! Status=0xffff
eth0: command 0x3002 did not complete! Status=0xffff
eth0: command 0x5800 did not complete! Status=0xffff
eth0: command 0x2804 did not complete! Status=0xffff
eth0: command 0x3002 did not complete! Status=0xffff
eth0: command 0x3002 did not complete! Status=0xffff
eth0: command 0x3002 did not complete! Status=0xffff
eth0: command 0x3002 did not complete! Status=0xffff
eth0: command 0x3002 did not complete! Status=0xffff


So we do hit "time_cpufreq_notifier 6" now, but we also get some errors
about spinlocks.  The screen is black and my ssh session is dead so I am
not so sure of the state of the machine.  I should have put a getty on
that serial console.  Wait, I just logged in "blindly" on the console
and did a shutdown, so it seems to have resumed ok, apart from the above
issues.

b.


[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 143 bytes --]

_______________________________________________
Cpufreq mailing list
Cpufreq@www.linux.org.uk
http://www.linux.org.uk/mailman/listinfo/cpufreq

Re: oops on resume

[Dominik Brodowski]

On Mon, Aug 09, 2004 at 01:27:50PM -0400, Brian J. Murrell wrote:
> So we do hit "time_cpufreq_notifier 6" now, but we also get some errors
> about spinlocks.
... which is not cpufreq-related, AFAICS.

> The screen is black
Have you tried the different acpi_sleep options? Also, check out the
comments in this bug: http://bugzilla.kernel.org/show_bug.cgi?id=1877

> and my ssh session is dead
'cause there seems to be some problem with the eth driver and/or hardware.
Try building it as a module, rmmod it before resume, modprobe it afterwards.

> that serial console.  Wait, I just logged in "blindly" on the console
> and did a shutdown, so it seems to have resumed ok, apart from the above
> issues.

Good luck in solving the other issues, I'll push the oops-avoiding patch
upstreams soon.

Thanks,
	Dominik