2006-11-17 21:22:29

by Dhaval Giani

[permalink] [raw]
Subject: [BUG][acpi-cpufreq/userspace-governor]Frequency does not change

Hey there,

Looks like I spoke too soon. I tried changing the frequency in cpu1
and then it all fell apart. I got a ridiculously high value. To test
it, I rebooted my system, and this is what happened.

[root@localhost dhaval]# cd /sys/devices/system/cpu/cpu0/cpufreq/
[root@localhost cpufreq]# cat *
0
1862000
1862000
1596000
1862000 1596000
ondemand userspace
1862000
acpi-cpufreq
userspace
1862000
1596000
1862000
cat: stats: Is a directory
[root@localhost cpufreq]# echo 1596000 > scaling_setspeed
[root@localhost cpufreq]# cat *
0
1862000
1862000
1596000
1862000 1596000
ondemand userspace
0
acpi-cpufreq
userspace
1862000
1596000
0
cat: stats: Is a directory
[root@localhost cpufreq]# cd ../../cpu1/cpufreq/
[root@localhost cpufreq]# cat *
1
1862000
1862000
1596000
1862000 1596000
ondemand userspace
1862000
acpi-cpufreq
userspace
1862000
1596000
1862000
cat: stats: Is a directory
[root@localhost cpufreq]# echo 1596000 > scaling_setspeed
[root@localhost cpufreq]# cat *
1
1596000
1862000
1596000
1862000 1596000
ondemand userspace
4294967295
acpi-cpufreq
userspace
1862000
1596000
4294967295
cat: stats: Is a directory
[root@localhost cpufreq]# cd ../../cpu1/cpufreq
[root@localhost cpufreq]# cat *
1
1596000
1862000
1596000
1862000 1596000
ondemand userspace
4294967295
acpi-cpufreq
userspace
1862000
1596000
4294967295
cat: stats: Is a directory


The dmesg is as follows,
acpi-cpufreq: get_cur_freq_on_cpu (0)
acpi-cpufreq: get_cur_val = 100665128
acpi-cpufreq: cur freq = 1862000
userspace: cpufreq_set for cpu 0, freq 1596000 kHz
cpufreq-core: target for CPU 0: 1596000 kHz, relation 0
acpi-cpufreq: acpi_cpufreq_target 1596000 (0)
freq-table: request for target 1596000 kHz (relation: 0) for cpu 0
freq-table: target is 1 (1596000 kHz, 9)
cpufreq-core: notification 0 of frequency transition to 0 kHz
userspace: saving cpu_cur_freq of cpu 0 to be 0 kHz
cpufreq-core: notification 1 of frequency transition to 0 kHz
userspace: saving cpu_cur_freq of cpu 0 to be 0 kHz
acpi-cpufreq: get_cur_freq_on_cpu (0)
printk: 2 messages suppressed.
acpi-cpufreq: get_cur_freq_on_cpu (1)
acpi-cpufreq: get_cur_val = 100665128
acpi-cpufreq: cur freq = 1862000
userspace: cpufreq_set for cpu 1, freq 1596000 kHz
cpufreq-core: target for CPU 1: 1596000 kHz, relation 0
acpi-cpufreq: acpi_cpufreq_target 1596000 (1)
freq-table: request for target 1596000 kHz (relation: 0) for cpu 1
freq-table: target is 1 (1596000 kHz, 9)
cpufreq-core: notification 0 of frequency transition to 4294967295 kHz
printk: 6 messages suppressed.
acpi-cpufreq: get_cur_freq_on_cpu (0)
acpi-cpufreq: get_cur_val = 100664859
acpi-cpufreq: cur freq = 1596000
acpi-cpufreq: get_cur_freq_on_cpu (1)
acpi-cpufreq: get_cur_val = 100664859
acpi-cpufreq: cur freq = 1596000
[root@localhost cpufreq]#

This is on the 2.6.19-rc5-mm2 with the patch at
http://lkml.org/lkml/2006/11/15/302 applied.

Thanks and regards
Dhaval Giani


2006-11-17 22:25:11

by Dhaval Giani

[permalink] [raw]
Subject: Re: [BUG][acpi-cpufreq/userspace-governor]Frequency does not change

Ok, so there was one thing which I had not tried. I tried to get back
to 1.86 Ghz. This is what happened,

The console first,
[root@localhost cpufreq]# echo 1862000 > scaling_setspeed
[dhaval@localhost ~]$
Message from syslogd@localhost at Sat Nov 18 03:51:49 2006 ...
localhost kernel: Oops: 0002 [1] SMP

Message from syslogd@localhost at Sat Nov 18 03:51:49 2006 ...
localhost kernel: last sysfs file:
/devices/system/cpu/cpu0/cpufreq/scaling_setspeed

Message from syslogd@localhost at Sat Nov 18 03:51:49 2006 ...
localhost kernel: CR2: ffff81081f319a78

And then the dnesg
<snip>
userspace: cpufreq_set for cpu 0, freq 1862000 kHz
cpufreq-core: target for CPU 0: 1862000 kHz, relation 0
acpi-cpufreq: acpi_cpufreq_target 1862000 (0)
freq-table: request for target 1862000 kHz (relation: 0) for cpu 0
freq-table: target is 0 (1862000 kHz, 0)
acpi-cpufreq: next_pref_state is 0
cpufreq-core: notification 0 of frequency transition to 1862000 kHz
userspace: saving cpu_cur_freq of cpu 0 to be 1862000 kHz
cpufreq-core: notification 1 of frequency transition to 1862000 kHz
Unable to handle kernel paging request at ffff81081f319a78 RIP:
[<ffffffff804b36ce>] cpufreq_stats_update+0x38/0x52
PGD 8063 PUD 0
Oops: 0002 [1] SMP
last sysfs file: /devices/system/cpu/cpu0/cpufreq/scaling_setspeed
CPU 0
Modules linked in:
Pid: 3635, comm: bash Not tainted 2.6.19-rc5-mm2 #11
RIP: 0010:[<ffffffff804b36ce>] [<ffffffff804b36ce>]
cpufreq_stats_update+0x38/0x52
RSP: 0018:ffff810012c8fd28 EFLAGS: 00010202
RAX: 0000000000012fb0 RBX: 0000000000000000 RCX: ffff81001f319a80
RDX: 00000000ffffffff RSI: ffff81001f2f7c00 RDI: ffffffff80d47c00
RBP: 0000000100008f3f R08: ffffffff809bbc40 R09: 0000000000000000
R10: 0000000000000007 R11: ffff81001e73a778 R12: ffff810012c8fe18
R13: 0000000000000000 R14: ffffffff80d47b38 R15: 0000000000000001
FS: 00002aeeeb25fd30(0000) GS:ffffffff807e6000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: ffff81081f319a78 CR3: 000000001e87b000 CR4: 00000000000006e0
Process bash (pid: 3635, threadinfo ffff810012c8e000, task ffff81001e73a040)
Stack: ffff810012c8fdd8 00000000ffffffff ffff81001f2f7c00 ffffffff804b372f
ffff810012c8fe18 0000000000000000 ffff810012c8fe18 0000000000000001
0000000000000000 ffffffff8054e528 ffffffff80d47bc0 ffff810012c8fe18
Call Trace:
[<ffffffff804b372f>] cpufreq_stat_notifier_trans+0x47/0x75
[<ffffffff8054e528>] notifier_call_chain+0x20/0x32
[<ffffffff8023d273>] srcu_notifier_call_chain+0x36/0x4f
[<ffffffff804b3168>] cpufreq_notify_transition+0xd0/0xe8
[<ffffffff8021ba51>] acpi_cpufreq_target+0x2fb/0x359
[<ffffffff804b3d3b>] store_speed+0xac/0xc5
[<ffffffff804b1ad5>] store+0x44/0x5b
[<ffffffff802ba23f>] sysfs_write_file+0xd3/0x107
[<ffffffff802814b6>] vfs_write+0xad/0x153
[<ffffffff80281a52>] sys_write+0x45/0x6e
[<ffffffff8020953e>] system_call+0x7e/0x83
DWARF2 unwinder stuck at system_call+0x7e/0x83
Leftover inexact backtrace:


Code: 48 01 04 d1 48 89 6e 08 48 c7 c7 00 7c d4 80 e8 7d 85 09 00
RIP [<ffffffff804b36ce>] cpufreq_stats_update+0x38/0x52
RSP <ffff810012c8fd28>
CR2: ffff81081f319a78
<3>BUG: sleeping function called from invalid context at kernel/rwsem.c:20
in_atomic():0, irqs_disabled():1
2 locks held by bash/3635:
#0: (userspace_mutex){--..}, at: [<ffffffff804b3cfa>] store_speed+0x6b/0xc5
#1: (&cpufreq_stats_lock){--..}, at: [<ffffffff804b36b3>]
cpufreq_stats_update+0x1d/0x52

Call Trace:
[<ffffffff8020ac25>] show_trace+0x34/0x47
[<ffffffff8020ac4a>] dump_stack+0x12/0x17
[<ffffffff80245725>] down_read+0x15/0x40
[<ffffffff8023cbdb>] blocking_notifier_call_chain+0x13/0x36
[<ffffffff8023308a>] do_exit+0x20/0x807
[<ffffffff8054e488>] do_page_fault+0x738/0x7b8
[<ffffffff8054c49d>] error_exit+0x0/0x96
DWARF2 unwinder stuck at error_exit+0x0/0x96
Leftover inexact backtrace:
[<ffffffff804b36ce>] cpufreq_stats_update+0x38/0x52
[<ffffffff804b36b3>] cpufreq_stats_update+0x1d/0x52
[<ffffffff804b372f>] cpufreq_stat_notifier_trans+0x47/0x75
[<ffffffff8054e528>] notifier_call_chain+0x20/0x32
[<ffffffff8023d273>] srcu_notifier_call_chain+0x36/0x4f
[<ffffffff804b3168>] cpufreq_notify_transition+0xd0/0xe8
[<ffffffff8021ba51>] acpi_cpufreq_target+0x2fb/0x359
[<ffffffff8054a79d>] __mutex_lock_slowpath+0x230/0x23b
[<ffffffff804b3d3b>] store_speed+0xac/0xc5
[<ffffffff804b1ad5>] store+0x44/0x5b
[<ffffffff802ba23f>] sysfs_write_file+0xd3/0x107
[<ffffffff802814b6>] vfs_write+0xad/0x153
[<ffffffff80281a52>] sys_write+0x45/0x6e
[<ffffffff8020953e>] system_call+0x7e/0x83

Thanks
Dhaval

On 11/18/06, Dhaval Giani <[email protected]> wrote:
> Hey there,
>
> Looks like I spoke too soon. I tried changing the frequency in cpu1
> and then it all fell apart. I got a ridiculously high value. To test
> it, I rebooted my system, and this is what happened.
>
> [root@localhost dhaval]# cd /sys/devices/system/cpu/cpu0/cpufreq/
> [root@localhost cpufreq]# cat *
> 0
> 1862000
> 1862000
> 1596000
> 1862000 1596000
> ondemand userspace
> 1862000
> acpi-cpufreq
> userspace
> 1862000
> 1596000
> 1862000
> cat: stats: Is a directory
> [root@localhost cpufreq]# echo 1596000 > scaling_setspeed
> [root@localhost cpufreq]# cat *
> 0
> 1862000
> 1862000
> 1596000
> 1862000 1596000
> ondemand userspace
> 0
> acpi-cpufreq
> userspace
> 1862000
> 1596000
> 0
> cat: stats: Is a directory
> [root@localhost cpufreq]# cd ../../cpu1/cpufreq/
> [root@localhost cpufreq]# cat *
> 1
> 1862000
> 1862000
> 1596000
> 1862000 1596000
> ondemand userspace
> 1862000
> acpi-cpufreq
> userspace
> 1862000
> 1596000
> 1862000
> cat: stats: Is a directory
> [root@localhost cpufreq]# echo 1596000 > scaling_setspeed
> [root@localhost cpufreq]# cat *
> 1
> 1596000
> 1862000
> 1596000
> 1862000 1596000
> ondemand userspace
> 4294967295
> acpi-cpufreq
> userspace
> 1862000
> 1596000
> 4294967295
> cat: stats: Is a directory
> [root@localhost cpufreq]# cd ../../cpu1/cpufreq
> [root@localhost cpufreq]# cat *
> 1
> 1596000
> 1862000
> 1596000
> 1862000 1596000
> ondemand userspace
> 4294967295
> acpi-cpufreq
> userspace
> 1862000
> 1596000
> 4294967295
> cat: stats: Is a directory
>
>
> The dmesg is as follows,
> acpi-cpufreq: get_cur_freq_on_cpu (0)
> acpi-cpufreq: get_cur_val = 100665128
> acpi-cpufreq: cur freq = 1862000
> userspace: cpufreq_set for cpu 0, freq 1596000 kHz
> cpufreq-core: target for CPU 0: 1596000 kHz, relation 0
> acpi-cpufreq: acpi_cpufreq_target 1596000 (0)
> freq-table: request for target 1596000 kHz (relation: 0) for cpu 0
> freq-table: target is 1 (1596000 kHz, 9)
> cpufreq-core: notification 0 of frequency transition to 0 kHz
> userspace: saving cpu_cur_freq of cpu 0 to be 0 kHz
> cpufreq-core: notification 1 of frequency transition to 0 kHz
> userspace: saving cpu_cur_freq of cpu 0 to be 0 kHz
> acpi-cpufreq: get_cur_freq_on_cpu (0)
> printk: 2 messages suppressed.
> acpi-cpufreq: get_cur_freq_on_cpu (1)
> acpi-cpufreq: get_cur_val = 100665128
> acpi-cpufreq: cur freq = 1862000
> userspace: cpufreq_set for cpu 1, freq 1596000 kHz
> cpufreq-core: target for CPU 1: 1596000 kHz, relation 0
> acpi-cpufreq: acpi_cpufreq_target 1596000 (1)
> freq-table: request for target 1596000 kHz (relation: 0) for cpu 1
> freq-table: target is 1 (1596000 kHz, 9)
> cpufreq-core: notification 0 of frequency transition to 4294967295 kHz
> printk: 6 messages suppressed.
> acpi-cpufreq: get_cur_freq_on_cpu (0)
> acpi-cpufreq: get_cur_val = 100664859
> acpi-cpufreq: cur freq = 1596000
> acpi-cpufreq: get_cur_freq_on_cpu (1)
> acpi-cpufreq: get_cur_val = 100664859
> acpi-cpufreq: cur freq = 1596000
> [root@localhost cpufreq]#
>
> This is on the 2.6.19-rc5-mm2 with the patch at
> http://lkml.org/lkml/2006/11/15/302 applied.
>
> Thanks and regards
> Dhaval Giani
>

2006-11-17 23:19:21

by Pallipadi, Venkatesh

[permalink] [raw]
Subject: RE: [BUG][acpi-cpufreq/userspace-governor]Frequency does not change




>-----Original Message-----
>From: Dhaval Giani [mailto:[email protected]]
>Sent: Friday, November 17, 2006 1:22 PM
>To: Pallipadi, Venkatesh; [email protected];
>Diefenbaugh, Paul S; [email protected]; Sadykov, Denis M
>Cc: [email protected]
>Subject: [BUG][acpi-cpufreq/userspace-governor]Frequency does
>not change
>
>Hey there,
>
>Looks like I spoke too soon. I tried changing the frequency in cpu1
>and then it all fell apart. I got a ridiculously high value. To test
>it, I rebooted my system, and this is what happened.
>

You will also need another patch here.
http://lists.linux.org.uk/mailman/private/cpufreq/2006-November/006591.h
tml

Please apply that patch along with the other one that you already
applied and let me know if you still see the issue.

Thanks,
Venki

2006-11-17 23:48:33

by Dhaval Giani

[permalink] [raw]
Subject: Re: [BUG][acpi-cpufreq/userspace-governor]Frequency does not change

Hey,

On 11/18/06, Pallipadi, Venkatesh <[email protected]> wrote:
>
>
>
> >-----Original Message-----
> >From: Dhaval Giani [mailto:[email protected]]
> >Sent: Friday, November 17, 2006 1:22 PM
> >To: Pallipadi, Venkatesh; [email protected];
> >Diefenbaugh, Paul S; [email protected]; Sadykov, Denis M
> >Cc: [email protected]
> >Subject: [BUG][acpi-cpufreq/userspace-governor]Frequency does
> >not change
> >
> >Hey there,
> >
> >Looks like I spoke too soon. I tried changing the frequency in cpu1
> >and then it all fell apart. I got a ridiculously high value. To test
> >it, I rebooted my system, and this is what happened.
> >
>
> You will also need another patch here.
> http://lists.linux.org.uk/mailman/private/cpufreq/2006-November/006591.h
> tml
>
> Please apply that patch along with the other one that you already
> applied and let me know if you still see the issue.
>

Applied, still having the oops.

> Thanks,
> Venki
>

Thanks
Dhaval

2006-11-18 22:39:59

by Pallipadi, Venkatesh

[permalink] [raw]
Subject: [PATCH] Bug fix for acpi-cpufreq and cpufreq_stats oops on frequency change notification


Fixes the oops in cpufreq_stats with acpi_cpufreq driver.
The issue was that the frequency was reported as 0 in acpi-cpufreq.c.
The bug is due to different indicies for freq_table and ACPI perf table.

Also adds a check in cpufreq_stats to check for error return from
freq_table_get_index() and avoid using the error return value.

Patch fixes the issue reported at
http://www.ussg.iu.edu/hypermail/linux/kernel/0611.2/0629.html
and also other similar issue here
http://bugme.osdl.org/show_bug.cgi?id=7383 comment 53

Signed-off-by: Dhaval Giani <[email protected]>
Signed-off-by: Venkatesh Pallipadi <[email protected]>

Index: linux-2.6.19-rc-mm/drivers/cpufreq/cpufreq_stats.c
===================================================================
--- linux-2.6.19-rc-mm.orig/drivers/cpufreq/cpufreq_stats.c
+++ linux-2.6.19-rc-mm/drivers/cpufreq/cpufreq_stats.c
@@ -285,6 +285,7 @@ cpufreq_stat_notifier_trans (struct noti
stat = cpufreq_stats_table[freq->cpu];
if (!stat)
return 0;
+
old_index = freq_table_get_index(stat, freq->old);
new_index = freq_table_get_index(stat, freq->new);

@@ -292,6 +293,9 @@ cpufreq_stat_notifier_trans (struct noti
if (old_index == new_index)
return 0;

+ if (old_index == -1 || new_index == -1)
+ return 0;
+
spin_lock(&cpufreq_stats_lock);
stat->last_index = new_index;
#ifdef CONFIG_CPU_FREQ_STAT_DETAILS
Index: linux-2.6.19-rc-mm/arch/i386/kernel/cpu/cpufreq/acpi-cpufreq.c
===================================================================
--- linux-2.6.19-rc-mm.orig/arch/i386/kernel/cpu/cpufreq/acpi-cpufreq.c
+++ linux-2.6.19-rc-mm/arch/i386/kernel/cpu/cpufreq/acpi-cpufreq.c
@@ -390,8 +390,8 @@ static int acpi_cpufreq_target(struct cp
cpumask_t online_policy_cpus;
struct drv_cmd cmd;
unsigned int msr;
- unsigned int next_state = 0;
- unsigned int next_perf_state = 0;
+ unsigned int next_state = 0; /* Index into freq_table */
+ unsigned int next_perf_state = 0; /* Index into perf table */
unsigned int i;
int result = 0;

@@ -456,8 +456,8 @@ static int acpi_cpufreq_target(struct cp
else
cpu_set(policy->cpu, cmd.mask);

- freqs.old = data->freq_table[perf->state].frequency;
- freqs.new = data->freq_table[next_perf_state].frequency;
+ freqs.old = perf->states[perf->state].core_frequency * 1000;
+ freqs.new = data->freq_table[next_state].frequency;
for_each_cpu_mask(i, cmd.mask) {
freqs.cpu = i;
cpufreq_notify_transition(&freqs, CPUFREQ_PRECHANGE);
@@ -694,6 +694,7 @@ static int acpi_cpufreq_cpu_init(struct
valid_states++;
}
data->freq_table[valid_states].frequency = CPUFREQ_TABLE_END;
+ perf->state = 0;

result = cpufreq_frequency_table_cpuinfo(policy, data->freq_table);
if (result)