Created attachment 360613 [details] ful message log Description of problem: cpuspeed/3825 is trying to acquire lock Observed that cpuspeed start does not slow processor, locked into 2.6GHz clock. Rebooted, got second stacktrace... now starting and stopping cpuspeed works as expected! Version-Release number of selected component (if applicable): cpuspeed-1.5-10.fc11.x86_64 How reproducible: Not sure! starting and stopping cpuspeed several times did not trigger it, and I accidentally deleted all my log files a couple of days ago... :-( Happenmed again when I rebooted and stopped cpuspeed. Steps to Reproduce: 1. switch machine on 2. log in 3. bring up services 4. stop cpuspeed Actual results: #### first observation Sep 11 15:38:49 saturn cpuspeed: Disabling ondemand cpu frequency scaling governor Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: ======================================================= Sep 11 15:38:49 saturn kernel: [ INFO: possible circular locking dependency detected ] Sep 11 15:38:49 saturn kernel: 2.6.30.5-43.fc11.x86_64.debug #1 Sep 11 15:38:49 saturn kernel: ------------------------------------------------------- Sep 11 15:38:49 saturn kernel: cpuspeed/3825 is trying to acquire lock: Sep 11 15:38:49 saturn kernel: (&(&dbs_info->work)->work){+.+...}, at: [<ffffffff8106f5b4>] __cancel_work_timer+0xc1/0x237 Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: but task is already holding lock: Sep 11 15:38:49 saturn kernel: (dbs_mutex){+.+.+.}, at: [<ffffffffa0261cf4>] cpufreq_governor_dbs+0x24c/0x2e8 [cpufreq_ondemand] Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: which lock already depends on the new lock. Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: the existing dependency chain (in reverse order) is: Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: -> #2 (dbs_mutex){+.+.+.}: Sep 11 15:38:49 saturn kernel: [<ffffffff81088b45>] __lock_acquire+0xa72/0xc07 Sep 11 15:38:49 saturn kernel: [<ffffffff81088dc8>] lock_acquire+0xee/0x12e Sep 11 15:38:49 saturn kernel: [<ffffffff814c1138>] __mutex_lock_common+0x5b/0x3b0 Sep 11 15:38:49 saturn kernel: [<ffffffff814c15b0>] mutex_lock_nested+0x4f/0x6b Sep 11 15:38:49 saturn kernel: [<ffffffffa0261b41>] cpufreq_governor_dbs+0x99/0x2e8 [cpufreq_ondemand] Sep 11 15:38:49 saturn kernel: [<ffffffff813d66be>] __cpufreq_governor+0xb6/0x10a Sep 11 15:38:49 saturn kernel: [<ffffffff813d691b>] __cpufreq_set_policy+0x1ad/0x241 Sep 11 15:38:49 saturn kernel: [<ffffffff813d7505>] store_scaling_governor+0x1a4/0x1f2 Sep 11 15:38:49 saturn kernel: [<ffffffff813d7c8f>] store+0x6d/0xa6 Sep 11 15:38:49 saturn kernel: [<ffffffff81187420>] sysfs_write_file+0x10a/0x15a Sep 11 15:38:49 saturn kernel: [<ffffffff8112523e>] vfs_write+0xbd/0x12e Sep 11 15:38:49 saturn kernel: [<ffffffff811253a1>] sys_write+0x59/0x91 Sep 11 15:38:49 saturn kernel: [<ffffffff81012002>] system_call_fastpath+0x16/0x1b Sep 11 15:38:49 saturn kernel: [<ffffffffffffffff>] 0xffffffffffffffff Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: -> #1 (&per_cpu(cpu_policy_rwsem, cpu)){+++++.}: Sep 11 15:38:49 saturn kernel: [<ffffffff81088b45>] __lock_acquire+0xa72/0xc07 Sep 11 15:38:49 saturn kernel: [<ffffffff81088dc8>] lock_acquire+0xee/0x12e Sep 11 15:38:49 saturn kernel: [<ffffffff814c1930>] down_write+0x5b/0xa4 Sep 11 15:38:49 saturn kernel: [<ffffffff813d7b77>] lock_policy_rwsem_write+0x5e/0xa5 Sep 11 15:38:49 saturn kernel: [<ffffffffa026188d>] do_dbs_timer+0x6f/0x28a [cpufreq_ondemand] Sep 11 15:38:49 saturn kernel: [<ffffffff8106ed9c>] worker_thread+0x222/0x33e Sep 11 15:38:49 saturn kernel: [<ffffffff81074058>] kthread+0x6d/0xae Sep 11 15:38:49 saturn kernel: [<ffffffff8101318a>] child_rip+0xa/0x20 Sep 11 15:38:49 saturn kernel: [<ffffffffffffffff>] 0xffffffffffffffff Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: -> #0 (&(&dbs_info->work)->work){+.+...}: Sep 11 15:38:49 saturn kernel: [<ffffffff81088a22>] __lock_acquire+0x94f/0xc07 Sep 11 15:38:49 saturn kernel: [<ffffffff81088dc8>] lock_acquire+0xee/0x12e Sep 11 15:38:49 saturn kernel: [<ffffffff8106f5ed>] __cancel_work_timer+0xfa/0x237 Sep 11 15:38:49 saturn kernel: [<ffffffff8106f74f>] cancel_delayed_work_sync+0x25/0x3b Sep 11 15:38:49 saturn kernel: [<ffffffffa0261d04>] cpufreq_governor_dbs+0x25c/0x2e8 [cpufreq_ondemand] Sep 11 15:38:49 saturn kernel: [<ffffffff813d66be>] __cpufreq_governor+0xb6/0x10a Sep 11 15:38:49 saturn kernel: [<ffffffff813d6905>] __cpufreq_set_policy+0x197/0x241 Sep 11 15:38:49 saturn kernel: [<ffffffff813d7505>] store_scaling_governor+0x1a4/0x1f2 Sep 11 15:38:49 saturn kernel: [<ffffffff813d7c8f>] store+0x6d/0xa6 Sep 11 15:38:49 saturn kernel: [<ffffffff81187420>] sysfs_write_file+0x10a/0x15a Sep 11 15:38:49 saturn kernel: [<ffffffff8112523e>] vfs_write+0xbd/0x12e Sep 11 15:38:49 saturn kernel: [<ffffffff811253a1>] sys_write+0x59/0x91 Sep 11 15:38:49 saturn kernel: [<ffffffff81012002>] system_call_fastpath+0x16/0x1b Sep 11 15:38:49 saturn kernel: [<ffffffffffffffff>] 0xffffffffffffffff Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: other info that might help us debug this: Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: 3 locks held by cpuspeed/3825: Sep 11 15:38:49 saturn kernel: #0: (&buffer->mutex){+.+.+.}, at: [<ffffffff81187361>] sysfs_write_file+0x4b/0x15a Sep 11 15:38:49 saturn kernel: #1: (&per_cpu(cpu_policy_rwsem, cpu)){+++++.}, at: [<ffffffff813d7b77>] lock_policy_rwsem_write+0x5e/0xa5 Sep 11 15:38:49 saturn kernel: #2: (dbs_mutex){+.+.+.}, at: [<ffffffffa0261cf4>] cpufreq_governor_dbs+0x24c/0x2e8 [cpufreq_ondemand] Sep 11 15:38:49 saturn kernel: Sep 11 15:38:49 saturn kernel: stack backtrace: Sep 11 15:38:49 saturn kernel: Pid: 3825, comm: cpuspeed Tainted: G W 2.6.30.5-43.fc11.x86_64.debug #1 Sep 11 15:38:49 saturn kernel: Call Trace: Sep 11 15:38:49 saturn kernel: [<ffffffff81087d0e>] print_circular_bug_tail+0x80/0x9f Sep 11 15:38:49 saturn kernel: [<ffffffff81087c56>] ? check_noncircular+0xb0/0xe8 Sep 11 15:38:49 saturn kernel: [<ffffffff81088a22>] __lock_acquire+0x94f/0xc07 Sep 11 15:38:49 saturn kernel: [<ffffffff81088dc8>] lock_acquire+0xee/0x12e Sep 11 15:38:49 saturn kernel: [<ffffffff8106f5b4>] ? __cancel_work_timer+0xc1/0x237 Sep 11 15:38:49 saturn kernel: [<ffffffff8106f5b4>] ? __cancel_work_timer+0xc1/0x237 Sep 11 15:38:49 saturn kernel: [<ffffffff8106f5ed>] __cancel_work_timer+0xfa/0x237 Sep 11 15:38:49 saturn kernel: [<ffffffff8106f5b4>] ? __cancel_work_timer+0xc1/0x237 Sep 11 15:38:49 saturn kernel: [<ffffffff810874c4>] ? trace_hardirqs_on_caller+0x139/0x173 Sep 11 15:38:49 saturn kernel: [<ffffffff814c142e>] ? __mutex_lock_common+0x351/0x3b0 Sep 11 15:38:49 saturn kernel: [<ffffffffa0261cf4>] ? cpufreq_governor_dbs+0x24c/0x2e8 [cpufreq_ondemand] Sep 11 15:38:49 saturn kernel: [<ffffffff814c2fb7>] ? _spin_unlock_irqrestore+0x5a/0x7f Sep 11 15:38:49 saturn kernel: [<ffffffff8106f74f>] cancel_delayed_work_sync+0x25/0x3b Sep 11 15:38:49 saturn kernel: [<ffffffffa0261d04>] cpufreq_governor_dbs+0x25c/0x2e8 [cpufreq_ondemand] Sep 11 15:38:49 saturn kernel: [<ffffffff813d66be>] __cpufreq_governor+0xb6/0x10a Sep 11 15:38:49 saturn kernel: [<ffffffff813d6905>] __cpufreq_set_policy+0x197/0x241 Sep 11 15:38:49 saturn kernel: [<ffffffff813d7505>] store_scaling_governor+0x1a4/0x1f2 Sep 11 15:38:49 saturn kernel: [<ffffffff813d7e13>] ? handle_update+0x0/0x5c Sep 11 15:38:49 saturn kernel: [<ffffffff813d7c8f>] store+0x6d/0xa6 Sep 11 15:38:49 saturn kernel: [<ffffffff81187420>] sysfs_write_file+0x10a/0x15a Sep 11 15:38:49 saturn kernel: [<ffffffff8112523e>] vfs_write+0xbd/0x12e Sep 11 15:38:49 saturn kernel: [<ffffffff811253a1>] sys_write+0x59/0x91 Sep 11 15:38:49 saturn kernel: [<ffffffff81012002>] system_call_fastpath+0x16/0x1b #### second observation (after a fresh reboot) Sep 11 16:17:05 saturn cpuspeed: Disabling ondemand cpu frequency scaling governor Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: ======================================================= Sep 11 16:17:05 saturn kernel: [ INFO: possible circular locking dependency detected ] Sep 11 16:17:05 saturn kernel: 2.6.30.5-43.fc11.x86_64.debug #1 Sep 11 16:17:05 saturn kernel: ------------------------------------------------------- Sep 11 16:17:05 saturn kernel: cpuspeed/3852 is trying to acquire lock: Sep 11 16:17:05 saturn kernel: (&(&dbs_info->work)->work){+.+...}, at: [<ffffffff8106f5b4>] __cancel_work_timer+0xc1/0x237 Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: but task is already holding lock: Sep 11 16:17:05 saturn kernel: (dbs_mutex){+.+.+.}, at: [<ffffffffa0256cf4>] cpufreq_governor_dbs+0x24c/0x2e8 [cpufreq_ondemand] Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: which lock already depends on the new lock. Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: the existing dependency chain (in reverse order) is: Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: -> #2 (dbs_mutex){+.+.+.}: Sep 11 16:17:05 saturn kernel: [<ffffffff81088b45>] __lock_acquire+0xa72/0xc07 Sep 11 16:17:05 saturn kernel: [<ffffffff81088dc8>] lock_acquire+0xee/0x12e Sep 11 16:17:05 saturn kernel: [<ffffffff814c1138>] __mutex_lock_common+0x5b/0x3b0 Sep 11 16:17:05 saturn kernel: [<ffffffff814c15b0>] mutex_lock_nested+0x4f/0x6b Sep 11 16:17:05 saturn kernel: [<ffffffffa0256b41>] cpufreq_governor_dbs+0x99/0x2e8 [cpufreq_ondemand] Sep 11 16:17:05 saturn kernel: [<ffffffff813d66be>] __cpufreq_governor+0xb6/0x10a Sep 11 16:17:05 saturn kernel: [<ffffffff813d691b>] __cpufreq_set_policy+0x1ad/0x241 Sep 11 16:17:05 saturn kernel: [<ffffffff813d7505>] store_scaling_governor+0x1a4/0x1f2 Sep 11 16:17:05 saturn kernel: [<ffffffff813d7c8f>] store+0x6d/0xa6 Sep 11 16:17:05 saturn kernel: [<ffffffff81187420>] sysfs_write_file+0x10a/0x15a Sep 11 16:17:05 saturn kernel: [<ffffffff8112523e>] vfs_write+0xbd/0x12e Sep 11 16:17:05 saturn kernel: [<ffffffff811253a1>] sys_write+0x59/0x91 Sep 11 16:17:05 saturn kernel: [<ffffffff81012002>] system_call_fastpath+0x16/0x1b Sep 11 16:17:05 saturn kernel: [<ffffffffffffffff>] 0xffffffffffffffff Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: -> #1 (&per_cpu(cpu_policy_rwsem, cpu)){+++++.}: Sep 11 16:17:05 saturn kernel: [<ffffffff81088b45>] __lock_acquire+0xa72/0xc07 Sep 11 16:17:05 saturn kernel: [<ffffffff81088dc8>] lock_acquire+0xee/0x12e Sep 11 16:17:05 saturn kernel: [<ffffffff814c1930>] down_write+0x5b/0xa4 Sep 11 16:17:05 saturn kernel: [<ffffffff813d7b77>] lock_policy_rwsem_write+0x5e/0xa5 Sep 11 16:17:05 saturn kernel: [<ffffffffa025688d>] do_dbs_timer+0x6f/0x28a [cpufreq_ondemand] Sep 11 16:17:05 saturn kernel: [<ffffffff8106ed9c>] worker_thread+0x222/0x33e Sep 11 16:17:05 saturn kernel: [<ffffffff81074058>] kthread+0x6d/0xae Sep 11 16:17:05 saturn kernel: [<ffffffff8101318a>] child_rip+0xa/0x20 Sep 11 16:17:05 saturn kernel: [<ffffffffffffffff>] 0xffffffffffffffff Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: -> #0 (&(&dbs_info->work)->work){+.+...}: Sep 11 16:17:05 saturn kernel: [<ffffffff81088a22>] __lock_acquire+0x94f/0xc07 Sep 11 16:17:05 saturn kernel: [<ffffffff81088dc8>] lock_acquire+0xee/0x12e Sep 11 16:17:05 saturn kernel: [<ffffffff8106f5ed>] __cancel_work_timer+0xfa/0x237 Sep 11 16:17:05 saturn kernel: [<ffffffff8106f74f>] cancel_delayed_work_sync+0x25/0x3b Sep 11 16:17:05 saturn kernel: [<ffffffffa0256d04>] cpufreq_governor_dbs+0x25c/0x2e8 [cpufreq_ondemand] Sep 11 16:17:05 saturn kernel: [<ffffffff813d66be>] __cpufreq_governor+0xb6/0x10a Sep 11 16:17:05 saturn kernel: [<ffffffff813d6905>] __cpufreq_set_policy+0x197/0x241 Sep 11 16:17:05 saturn kernel: [<ffffffff813d7505>] store_scaling_governor+0x1a4/0x1f2 Sep 11 16:17:05 saturn kernel: [<ffffffff813d7c8f>] store+0x6d/0xa6 Sep 11 16:17:05 saturn kernel: [<ffffffff81187420>] sysfs_write_file+0x10a/0x15a Sep 11 16:17:05 saturn kernel: [<ffffffff8112523e>] vfs_write+0xbd/0x12e Sep 11 16:17:05 saturn kernel: [<ffffffff811253a1>] sys_write+0x59/0x91 Sep 11 16:17:05 saturn kernel: [<ffffffff81012002>] system_call_fastpath+0x16/0x1b Sep 11 16:17:05 saturn kernel: [<ffffffffffffffff>] 0xffffffffffffffff Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: other info that might help us debug this: Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: 3 locks held by cpuspeed/3852: Sep 11 16:17:05 saturn kernel: #0: (&buffer->mutex){+.+.+.}, at: [<ffffffff81187361>] sysfs_write_file+0x4b/0x15a Sep 11 16:17:05 saturn kernel: #1: (&per_cpu(cpu_policy_rwsem, cpu)){+++++.}, at: [<ffffffff813d7b77>] lock_policy_rwsem_write+0x5e/0xa5 Sep 11 16:17:05 saturn kernel: #2: (dbs_mutex){+.+.+.}, at: [<ffffffffa0256cf4>] cpufreq_governor_dbs+0x24c/0x2e8 [cpufreq_ondemand] Sep 11 16:17:05 saturn kernel: Sep 11 16:17:05 saturn kernel: stack backtrace: Sep 11 16:17:05 saturn kernel: Pid: 3852, comm: cpuspeed Tainted: G W 2.6.30.5-43.fc11.x86_64.debug #1 Sep 11 16:17:05 saturn kernel: Call Trace: Sep 11 16:17:05 saturn kernel: [<ffffffff81087d0e>] print_circular_bug_tail+0x80/0x9f Sep 11 16:17:05 saturn kernel: [<ffffffff81087c56>] ? check_noncircular+0xb0/0xe8 Sep 11 16:17:05 saturn kernel: [<ffffffff81088a22>] __lock_acquire+0x94f/0xc07 Sep 11 16:17:05 saturn kernel: [<ffffffff81088dc8>] lock_acquire+0xee/0x12e Sep 11 16:17:05 saturn kernel: [<ffffffff8106f5b4>] ? __cancel_work_timer+0xc1/0x237 Sep 11 16:17:05 saturn kernel: [<ffffffff8106f5b4>] ? __cancel_work_timer+0xc1/0x237 Sep 11 16:17:05 saturn kernel: [<ffffffff8106f5ed>] __cancel_work_timer+0xfa/0x237 Sep 11 16:17:05 saturn kernel: [<ffffffff8106f5b4>] ? __cancel_work_timer+0xc1/0x237 Sep 11 16:17:05 saturn kernel: [<ffffffff810874c4>] ? trace_hardirqs_on_caller+0x139/0x173 Sep 11 16:17:05 saturn kernel: [<ffffffff814c142e>] ? __mutex_lock_common+0x351/0x3b0 Sep 11 16:17:05 saturn kernel: [<ffffffffa0256cf4>] ? cpufreq_governor_dbs+0x24c/0x2e8 [cpufreq_ondemand] Sep 11 16:17:05 saturn kernel: [<ffffffff814c2fb7>] ? _spin_unlock_irqrestore+0x5a/0x7f Sep 11 16:17:05 saturn kernel: [<ffffffff8106f74f>] cancel_delayed_work_sync+0x25/0x3b Sep 11 16:17:05 saturn kernel: [<ffffffffa0256d04>] cpufreq_governor_dbs+0x25c/0x2e8 [cpufreq_ondemand] Sep 11 16:17:05 saturn kernel: [<ffffffff813d66be>] __cpufreq_governor+0xb6/0x10a Sep 11 16:17:05 saturn kernel: [<ffffffff813d6905>] __cpufreq_set_policy+0x197/0x241 Sep 11 16:17:05 saturn kernel: [<ffffffff813d7505>] store_scaling_governor+0x1a4/0x1f2 Sep 11 16:17:05 saturn kernel: [<ffffffff813d7e13>] ? handle_update+0x0/0x5c Sep 11 16:17:05 saturn kernel: [<ffffffff813d7c8f>] store+0x6d/0xa6 Sep 11 16:17:05 saturn kernel: [<ffffffff81187420>] sysfs_write_file+0x10a/0x15a Sep 11 16:17:05 saturn kernel: [<ffffffff8112523e>] vfs_write+0xbd/0x12e Sep 11 16:17:05 saturn kernel: [<ffffffff811253a1>] sys_write+0x59/0x91 Sep 11 16:17:05 saturn kernel: [<ffffffff81012002>] system_call_fastpath+0x16/0x1b Sep 11 16:18:17 saturn ntpd[1876]: synchronized to LOCAL(0), stratum 10 Sep 11 16:18:17 saturn ntpd[1876]: kernel time sync status change 2001 Sep 11 16:18:26 saturn cpuspeed: Enabling ondemand cpu frequency scaling governor Sep 11 16:19:00 saturn cpuspeed: Disabling ondemand cpu frequency scaling governor Sep 11 16:19:25 saturn cpuspeed: Enabling ondemand cpu frequency scaling governor Sep 11 16:19:53 saturn cpuspeed: Disabling ondemand cpu frequency scaling governor Expected results: no errors in log Additional info: up to date Fedora 11 install AMD 810 quad core 64 bit 8 GB DDR3 RAM 5 * 500GB in software RAID-6 configuration ASUS M4A78T-E motherboard Linux saturn 2.6.30.5-43.fc11.x86_64.debug #1 SMP Thu Aug 27 21:21:23 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux
Kernel issue, not a cpuspeed package issue, reassigning.
Fixed in 2.6.30.7-55.rc1
kernel-2.6.30.8-64.fc11 has been submitted as an update for Fedora 11. http://admin.fedoraproject.org/updates/kernel-2.6.30.8-64.fc11
kernel-2.6.30.8-64.fc11 has been pushed to the Fedora 11 stable repository. If problems still persist, please make note of it in this bug report.