Skip to contentSkip to conversation

Request for assistance - excessive kworker CPU wakeups

DISCUSSION David H. Durgee 2 participants 5 messages Dec 9, 2011 – Jan 26, 2012

lore
Share & tools
lore
#0 lore raw

I recently purchased a Lenovo IdeaPad Z560, model 09143YU, and as I am not a Windows fan I installed Linux Mint 11 Katya x64 to use instead of the supplied W7. I was encountering a known hang and had to upgrade to a later kernel, so I am now using the 2.6.38-11-generic #50-Ubuntu SMP Mon Sep 12 21:17:25 UTC 2011 x86_64 kernel.

I had my first occasion to use the laptop for an extended period for the first time over the Thanksgiving holiday and I found it needed to be tuned. I downloaded powertop and used it to discover where my problems were. After addressing excessive i915 interrupts due to DRI the next most frequent cause of CPU wakeups is a kworker on the system. A search lead to a post by Tejun, indicating the need to trace such issues. Running the trace showed that 1933 of 2748 events were of the form:

<idle>-0 [000] 22005.355346: workqueue_queue_work: work struct=ffff8800bb411188 function=do_dbs_timer workqueue=ffff88012b5d2c00 req_cpu=0 cpu=0

Tejun indicated that this is a workitem used by cpufreq and likely caused by something else hitting the CPU frequently. So how do I diagnose this further and isolate the cause for correction?

If you would like a summary of this, download this spreadsheet:

http://home.comcast.net/%7Eddurgee/Tracelog.ods

If you would like to inspect the trace log itself:

http://home.comcast.net/%7Eddurgee/tracelog.zip

Dave

#1 lore raw
Quoted 22 lines · David H. Durgee

I recently purchased a Lenovo IdeaPad Z560, model 09143YU, and as I am not a Windows fan I installed Linux Mint 11 Katya x64 to use instead of the supplied W7.  I was encountering a known hang and had to upgrade to a later kernel, so I am now using the 2.6.38-11-generic #50-Ubuntu SMP Mon Sep 12 21:17:25 UTC 2011 x86_64 kernel.

I had my first occasion to use the laptop for an extended period for the first time over the Thanksgiving holiday and I found it needed to be tuned. I downloaded powertop and used it to discover where my problems were. After addressing excessive i915 interrupts due to DRI the next most frequent cause of CPU wakeups is a kworker on the system.  A search lead to a post by Tejun, indicating the need to trace such issues. Running the trace showed that 1933 of 2748 events were of the form:

<idle>-0     [000] 22005.355346: workqueue_queue_work: work struct=ffff8800bb411188 function=do_dbs_timer workqueue=ffff88012b5d2c00 req_cpu=0 cpu=0

Tejun indicated that this is a workitem used by cpufreq and likely caused by something else hitting the CPU frequently.  So how do I diagnose this further and isolate the cause for correction?

Quoted 8 lines

If you would like a summary of this, download this spreadsheet:

http://home.comcast.net/%7Eddurgee/Tracelog.ods

If you would like to inspect the trace log itself:

http://home.comcast.net/%7Eddurgee/tracelog.zip

Hi Dave,

I don't know the cpufreq code that well, but it seem that this workqueue is schedule periodically. You
can examine the sampling rate via /sys:

$ grep "" /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate*

Just curious, are you running nohz:

$ dmesg | grep -i nohz

Regards,
Mandeep

Quoted 6 lines

Dave
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

#2 lore raw
Quoted 37 lines · Mandeep Singh Baines
Quoted 22 lines · David H. Durgee

I recently purchased a Lenovo IdeaPad Z560, model 09143YU, and as I am not a Windows fan I installed Linux Mint 11 Katya x64 to use instead of the supplied W7. I was encountering a known hang and had to upgrade to a later kernel, so I am now using the 2.6.38-11-generic #50-Ubuntu SMP Mon Sep 12 21:17:25 UTC 2011 x86_64 kernel.

I had my first occasion to use the laptop for an extended period for the first time over the Thanksgiving holiday and I found it needed to be tuned.
I downloaded powertop and used it to discover where my problems were. After addressing excessive i915 interrupts due to DRI the next most
frequent cause of CPU wakeups is a kworker on the system. A search lead to a post by Tejun, indicating the need to trace such issues. Running the trace showed that 1933 of 2748 events were of the form:

<idle>-0 [000] 22005.355346: workqueue_queue_work: work
struct=ffff8800bb411188 function=do_dbs_timer workqueue=ffff88012b5d2c00 req_cpu=0 cpu=0

Tejun indicated that this is a workitem used by cpufreq and likely caused by something else hitting the CPU frequently. So how do I diagnose this further and isolate the cause for correction?

Quoted 8 lines

If you would like a summary of this, download this spreadsheet:

http://home.comcast.net/%7Eddurgee/Tracelog.ods

If you would like to inspect the trace log itself:

http://home.comcast.net/%7Eddurgee/tracelog.zip

Hi Dave,

I don't know the cpufreq code that well, but it seem that this workqueue is schedule periodically. You
can examine the sampling rate via /sys:

Quoted 8 lines
$ grep "" /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate*

Just curious, are you running nohz:

$ dmesg | grep -i nohz

Regards,
Mandeep

dhdurgee@DHD-Z560 ~/Downloads $ grep "" /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate* /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate:10000 /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate_max:4294967295 /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate_min:10000 dhdurgee@DHD-Z560 ~/Downloads $ dmesg | grep -i nohz
dhdurgee@DHD-Z560 ~/Downloads $

Does this explain what I am seeing? Does this square with the observations in my spreadsheet? Does this suggest a means of reducing these excessive wakeups? Is there more information I can provide to suggest a course of action?

Dave

#3 lore raw
Quoted 54 lines · David H. Durgee
Quoted 37 lines · Mandeep Singh Baines
Quoted 22 lines · David H. Durgee

I recently purchased a Lenovo IdeaPad Z560, model 09143YU, and as I am not a Windows fan I installed Linux Mint 11 Katya x64 to use instead of the supplied W7. I was encountering a known hang and had to upgrade to a later kernel, so I am now using the 2.6.38-11-generic #50-Ubuntu SMP Mon Sep 12 21:17:25 UTC 2011 x86_64 kernel.

I had my first occasion to use the laptop for an extended period for the first time over the Thanksgiving holiday and I found it needed to be tuned.
I downloaded powertop and used it to discover where my problems were. After addressing excessive i915 interrupts due to DRI the next most
frequent cause of CPU wakeups is a kworker on the system. A search lead to a post by Tejun, indicating the need to trace such issues. Running the trace showed that 1933 of 2748 events were of the form:

<idle>-0 [000] 22005.355346: workqueue_queue_work: work
struct=ffff8800bb411188 function=do_dbs_timer workqueue=ffff88012b5d2c00 req_cpu=0 cpu=0

Tejun indicated that this is a workitem used by cpufreq and likely caused by something else hitting the CPU frequently. So how do I diagnose this further and isolate the cause for correction?

Quoted 8 lines

If you would like a summary of this, download this spreadsheet:

http://home.comcast.net/%7Eddurgee/Tracelog.ods

If you would like to inspect the trace log itself:

http://home.comcast.net/%7Eddurgee/tracelog.zip

Hi Dave,

I don't know the cpufreq code that well, but it seem that this workqueue is schedule periodically. You
can examine the sampling rate via /sys:

Quoted 8 lines
$ grep "" /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate*

Just curious, are you running nohz:

$ dmesg | grep -i nohz

Regards,
Mandeep

dhdurgee@DHD-Z560 ~/Downloads $ grep "" /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate* /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate:10000 /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate_max:4294967295 /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate_min:10000 dhdurgee@DHD-Z560 ~/Downloads $ dmesg | grep -i nohz dhdurgee@DHD-Z560 ~/Downloads $

Quoted 5 lines

Does this explain what I am seeing? Does this square with the observations in my spreadsheet? Does this suggest a means of reducing these excessive wakeups? Is there more information I can provide to suggest a course of action?

IIUC, you should be seeing 100 such events per second * number of CPUs. Is that what you are seeing? You could reduce this by changing HZ. Maybe change to CONFIG_HZ_100 in your .config from CONFIG_HZ_1000. That should reduce the number of events by a factor of 10.

Regards,
Mandeep

Quoted 1 line

Dave

#4 lore raw
Quoted 60 lines · Mandeep Singh Baines
Quoted 54 lines · David H. Durgee
Quoted 37 lines · Mandeep Singh Baines
Quoted 22 lines · David H. Durgee

I recently purchased a Lenovo IdeaPad Z560, model 09143YU, and as I am not a Windows fan I installed Linux Mint 11 Katya x64 to use instead of the supplied W7. I was encountering a known hang and had to upgrade to a later kernel, so I am now using the 2.6.38-11-generic #50-Ubuntu SMP Mon Sep 12 21:17:25 UTC 2011 x86_64 kernel.

I had my first occasion to use the laptop for an extended period for the first time over the Thanksgiving holiday and I found it needed to be tuned.
I downloaded powertop and used it to discover where my problems were. After addressing excessive i915 interrupts due to DRI the next most
frequent cause of CPU wakeups is a kworker on the system. A search lead to a post by Tejun, indicating the need to trace such issues. Running the trace showed that 1933 of 2748 events were of the form:

<idle>-0 [000] 22005.355346: workqueue_queue_work: work
struct=ffff8800bb411188 function=do_dbs_timer workqueue=ffff88012b5d2c00 req_cpu=0 cpu=0

Tejun indicated that this is a workitem used by cpufreq and likely caused by something else hitting the CPU frequently. So how do I diagnose this further and isolate the cause for correction?

Quoted 8 lines

If you would like a summary of this, download this spreadsheet:

http://home.comcast.net/%7Eddurgee/Tracelog.ods

If you would like to inspect the trace log itself:

http://home.comcast.net/%7Eddurgee/tracelog.zip

Hi Dave,

I don't know the cpufreq code that well, but it seem that this workqueue is schedule periodically. You
can examine the sampling rate via /sys:

Quoted 8 lines
$ grep "" /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate*

Just curious, are you running nohz:

$ dmesg | grep -i nohz

Regards,
Mandeep

dhdurgee@DHD-Z560 ~/Downloads $ grep "" /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate* /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate:10000 /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate_max:4294967295 /sys/devices/system/cpu/cpufreq/ondemand/sampling_rate_min:10000 dhdurgee@DHD-Z560 ~/Downloads $ dmesg | grep -i nohz dhdurgee@DHD-Z560 ~/Downloads $

Quoted 5 lines

Does this explain what I am seeing? Does this square with the observations in my spreadsheet? Does this suggest a means of reducing these excessive wakeups? Is there more information I can provide to suggest a course of action?

Quoted 7 lines

IIUC, you should be seeing 100 such events per second * number of CPUs. Is that what you are seeing? You could reduce this by changing HZ. Maybe change to CONFIG_HZ_100 in your .config from CONFIG_HZ_1000. That should reduce the number of events by a factor of 10.

Regards,
Mandeep

Looking at /boot/config-2.6.38-11-generic I see the following:

CONFIG_HZ_100=y
# CONFIG_HZ_250 is not set
# CONFIG_HZ_300 is not set
# CONFIG_HZ_1000 is not set
CONFIG_HZ=100

So it appears that this is already set. Looking at the raw data I collected and summarized I see 22005.355346 in the first record and 22031.110816 in the last record. Am I correct in interpreting this to mean that 25.76 seconds elapsed while data was collected? During the collection I saw 1,993 total idle do_dbs_timer calls. I saw a total of 2,754 wakeups for all events. You can get the details from the files I referenced.

Dave