Bug 120291 - swapper causes many timer wakeups
Summary: swapper causes many timer wakeups
Status: NEW
Alias: None
Product: Memory Management
Classification: Unclassified
Component: Other (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Andrew Morton
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-06-14 21:44 UTC by Gunter Königsmann
Modified: 2016-06-15 05:18 UTC (History)
1 user (show)

See Also:
Kernel Version: 4.7.0-040700rc2
Subsystem:
Regression: Yes
Bisected commit-id:


Attachments

Description Gunter Königsmann 2016-06-14 21:44:11 UTC
On my computer even after a "sudo swapoff -a" two swapper processes (2-core cpu/hyperThreading) are the leading cause for timer wakeups:

I did a

echo 1 >/proc/timer_stats

followed by a

cat /proc/timer_stats

The result on my ubuntu/yakkety box was:

Sample period: 724.882 s
Collection: active
 61205, 0 swapper/0 tick_nohz_restart (tick_sched_timer)
 54814, 0 swapper/2 tick_nohz_restart (tick_sched_timer)
 24337, 7 rcu_preempt rcu_gp_kthread (process_timeout)
 9297, 0 swapper/2 __tick_nohz_idle_enter (tick_sched_timer)
  948, 3958 gnome-terminal- schedule_hrtimeout_range_clock (hrtimer_wakeup)
 61256, 0 swapper/3 tick_nohz_restart (tick_sched_timer)
 56990, 0 swapper/1 tick_nohz_restart (tick_sched_timer)
 6351, 2151 compiz schedule_hrtimeout_range_clock (hrtimer_wakeup)
 2299, 112 systemd-udevd gen6_read32 (intel_uncore_fw_release_timer)

/proc/cpuinfo tells me:
processor	: 0
vendor_id	: GenuineIntel
cpu family	: 6
model		: 58
model name	: Intel(R) Core(TM) i7-3517U CPU @ 1.90GHz
stepping	: 9
microcode	: 0x15
cpu MHz		: 964.781
cache size	: 4096 KB
physical id	: 0
siblings	: 4
core id		: 0
cpu cores	: 2
apicid		: 0
initial apicid	: 0
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm epb tpr_shadow vnmi flexpriority ept vpid fsgsbase smep erms xsaveopt dtherm ida arat pln pts
bugs		:
bogomips	: 4788.68
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual
power management:

processor	: 1
vendor_id	: GenuineIntel
cpu family	: 6
model		: 58
model name	: Intel(R) Core(TM) i7-3517U CPU @ 1.90GHz
stepping	: 9
microcode	: 0x15
cpu MHz		: 910.406
cache size	: 4096 KB
physical id	: 0
siblings	: 4
core id		: 0
cpu cores	: 2
apicid		: 1
initial apicid	: 1
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm epb tpr_shadow vnmi flexpriority ept vpid fsgsbase smep erms xsaveopt dtherm ida arat pln pts
bugs		:
bogomips	: 4796.59
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual
power management:

processor	: 2
vendor_id	: GenuineIntel
cpu family	: 6
model		: 58
model name	: Intel(R) Core(TM) i7-3517U CPU @ 1.90GHz
stepping	: 9
microcode	: 0x15
cpu MHz		: 960.656
cache size	: 4096 KB
physical id	: 0
siblings	: 4
core id		: 1
cpu cores	: 2
apicid		: 2
initial apicid	: 2
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm epb tpr_shadow vnmi flexpriority ept vpid fsgsbase smep erms xsaveopt dtherm ida arat pln pts
bugs		:
bogomips	: 4794.03
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual
power management:

processor	: 3
vendor_id	: GenuineIntel
cpu family	: 6
model		: 58
model name	: Intel(R) Core(TM) i7-3517U CPU @ 1.90GHz
stepping	: 9
microcode	: 0x15
cpu MHz		: 846.656
cache size	: 4096 KB
physical id	: 0
siblings	: 4
core id		: 1
cpu cores	: 2
apicid		: 3
initial apicid	: 3
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm epb tpr_shadow vnmi flexpriority ept vpid fsgsbase smep erms xsaveopt dtherm ida arat pln pts
bugs		:
bogomips	: 4794.25
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual
power management:


4.6.0-040600 and earlier doesn't trigger this problem; 4.7.0-040700rc1 won't boot on my computer so I couldn't test if the problem has been reproducible there, too.

Keywords: Regression, swapper, timer wakeups
Comment 1 Andrew Morton 2016-06-14 21:55:08 UTC
(switched to email.  Please respond via emailed reply-to-all, not via the
bugzilla web interface).

On Tue, 14 Jun 2016 21:44:11 +0000 bugzilla-daemon@bugzilla.kernel.org wrote:

> https://bugzilla.kernel.org/show_bug.cgi?id=120291
> 
>             Bug ID: 120291
>            Summary: swapper causes many timer wakeups
>            Product: Memory Management
>            Version: 2.5
>     Kernel Version: 4.7.0-040700rc2
>           Hardware: All
>                 OS: Linux
>               Tree: Mainline
>             Status: NEW
>           Severity: normal
>           Priority: P1
>          Component: Other
>           Assignee: akpm@linux-foundation.org
>           Reporter: gunter@peterpall.de
>         Regression: No
> 
> On my computer even after a "sudo swapoff -a" two swapper processes (2-core
> cpu/hyperThreading) are the leading cause for timer wakeups:
> 
> I did a
> 
> echo 1 >/proc/timer_stats
> 
> followed by a
> 
> cat /proc/timer_stats
> 
> The result on my ubuntu/yakkety box was:
> 
> Sample period: 724.882 s
> Collection: active
>  61205, 0 swapper/0 tick_nohz_restart (tick_sched_timer)
>  54814, 0 swapper/2 tick_nohz_restart (tick_sched_timer)
>  24337, 7 rcu_preempt rcu_gp_kthread (process_timeout)
>  9297, 0 swapper/2 __tick_nohz_idle_enter (tick_sched_timer)
>   948, 3958 gnome-terminal- schedule_hrtimeout_range_clock (hrtimer_wakeup)
>  61256, 0 swapper/3 tick_nohz_restart (tick_sched_timer)
>  56990, 0 swapper/1 tick_nohz_restart (tick_sched_timer)
>  6351, 2151 compiz schedule_hrtimeout_range_clock (hrtimer_wakeup)
>  2299, 112 systemd-udevd gen6_read32 (intel_uncore_fw_release_timer)

I assume these wakeups are being attributed to swapper because that's
the task which runs when nothing else is running, so it is frequently
the task which gets interrupted to perform timer activity.

Arguably that's a bit bogus, but I guess it's OK as long as one
understands that "swapper" translates to "idle".

What's interesting is that you saw a large change between 4.6 and 4.7. 
Possibly due to a scheduler change?  (tick_sched_timer).

> /proc/cpuinfo tells me:
> processor    : 0
> vendor_id    : GenuineIntel
> cpu family    : 6
> model        : 58
> model name    : Intel(R) Core(TM) i7-3517U CPU @ 1.90GHz
> stepping    : 9
> microcode    : 0x15
> cpu MHz        : 964.781
> cache size    : 4096 KB
> physical id    : 0
> siblings    : 4
> core id        : 0
> cpu cores    : 2
> apicid        : 0
> initial apicid    : 0
> fpu        : yes
> fpu_exception    : yes
> cpuid level    : 13
> wp        : yes
> flags        : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov
> pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp
> lm
> constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc
> aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3
> cx16
> xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx
> f16c rdrand lahf_lm epb tpr_shadow vnmi flexpriority ept vpid fsgsbase smep
> erms xsaveopt dtherm ida arat pln pts
> bugs        :
> bogomips    : 4788.68
> clflush size    : 64
> cache_alignment    : 64
> address sizes    : 36 bits physical, 48 bits virtual
> power management:
> 
> processor    : 1
> vendor_id    : GenuineIntel
> cpu family    : 6
> model        : 58
> model name    : Intel(R) Core(TM) i7-3517U CPU @ 1.90GHz
> stepping    : 9
> microcode    : 0x15
> cpu MHz        : 910.406
> cache size    : 4096 KB
> physical id    : 0
> siblings    : 4
> core id        : 0
> cpu cores    : 2
> apicid        : 1
> initial apicid    : 1
> fpu        : yes
> fpu_exception    : yes
> cpuid level    : 13
> wp        : yes
> flags        : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov
> pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp
> lm
> constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc
> aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3
> cx16
> xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx
> f16c rdrand lahf_lm epb tpr_shadow vnmi flexpriority ept vpid fsgsbase smep
> erms xsaveopt dtherm ida arat pln pts
> bugs        :
> bogomips    : 4796.59
> clflush size    : 64
> cache_alignment    : 64
> address sizes    : 36 bits physical, 48 bits virtual
> power management:
> 
> processor    : 2
> vendor_id    : GenuineIntel
> cpu family    : 6
> model        : 58
> model name    : Intel(R) Core(TM) i7-3517U CPU @ 1.90GHz
> stepping    : 9
> microcode    : 0x15
> cpu MHz        : 960.656
> cache size    : 4096 KB
> physical id    : 0
> siblings    : 4
> core id        : 1
> cpu cores    : 2
> apicid        : 2
> initial apicid    : 2
> fpu        : yes
> fpu_exception    : yes
> cpuid level    : 13
> wp        : yes
> flags        : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov
> pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp
> lm
> constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc
> aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3
> cx16
> xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx
> f16c rdrand lahf_lm epb tpr_shadow vnmi flexpriority ept vpid fsgsbase smep
> erms xsaveopt dtherm ida arat pln pts
> bugs        :
> bogomips    : 4794.03
> clflush size    : 64
> cache_alignment    : 64
> address sizes    : 36 bits physical, 48 bits virtual
> power management:
> 
> processor    : 3
> vendor_id    : GenuineIntel
> cpu family    : 6
> model        : 58
> model name    : Intel(R) Core(TM) i7-3517U CPU @ 1.90GHz
> stepping    : 9
> microcode    : 0x15
> cpu MHz        : 846.656
> cache size    : 4096 KB
> physical id    : 0
> siblings    : 4
> core id        : 1
> cpu cores    : 2
> apicid        : 3
> initial apicid    : 3
> fpu        : yes
> fpu_exception    : yes
> cpuid level    : 13
> wp        : yes
> flags        : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov
> pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp
> lm
> constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc
> aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3
> cx16
> xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx
> f16c rdrand lahf_lm epb tpr_shadow vnmi flexpriority ept vpid fsgsbase smep
> erms xsaveopt dtherm ida arat pln pts
> bugs        :
> bogomips    : 4794.25
> clflush size    : 64
> cache_alignment    : 64
> address sizes    : 36 bits physical, 48 bits virtual
> power management:
> 
> 
> 4.6.0-040600 and earlier doesn't trigger this problem; 4.7.0-040700rc1 won't
> boot on my computer so I couldn't test if the problem has been reproducible
> there, too.
> 
> Keywords: Regression, swapper, timer wakeups
> 
> -- 
> You are receiving this mail because:
> You are the assignee for the bug.
Comment 2 Gunter Königsmann 2016-06-15 05:18:13 UTC
Thanks a lot for answering this fast and complete.

...and it seems that I have to deeply apologize: If the swapper is just
kind of an idle task and it being listed in /proc_timer_stats doesn't
mean swap management actually to be the cause of the CPU wakeup I've
completely misinterpreted the system's logs.

Also even if I did a handful of measurements before reporting the bug
the high wakeup rate seems to have coincided with the kernel version,
but not to have been caused by it => I beg you to close my bug as
"invalid". To prove that I was wrong today powertop says:

4.6.0:

The battery reports a discharge rate of 8.96 W
The estimated remaining time is 3 hours, 54 minutes

Summary: 123,8 wakeups/second,  2,9 GPU ops/seconds, 0,0 VFS ops/sec and
3,0% CP

                Usage       Events/s    Category       Description
            100,0%                      Device         Audio codec
hwC0D3: Intel
            100,0%                      Device         Audio codec
hwC0D0: Realt
              1,0 ms/s      32,0        Timer          tick_sched_timer
            284,4 µs/s      17,9        Process        [rcu_preempt]
              2,5 ms/s       9,8        Process        compiz
            199,3 µs/s      10,6        kWork          ieee80211_iface_work
              2,6 ms/s       8,9        Process
/usr/lib/firefox/firefox
             75,7 µs/s       6,3        Process        [rcu_sched]
              1,2 ms/s       4,0        Interrupt      [6] tasklet(softirq)
              1,1 ms/s       2,7        Process
/usr/lib/gnome-terminal/g
              1,5 ms/s       2,6        Process        cairo-dock
            524,0 µs/s       2,8        Process        powertop
            404,0 µs/s       2,5        Process
/usr/lib/thunderbird/thun
             35,5 µs/s       2,5        Interrupt      [28] i915

4.7.0:
The battery reports a discharge rate of 9.86 W
The estimated remaining time is 3 hours, 17 minutes

Summary: 123,0 wakeups/second,  9,5 GPU ops/seconds, 0,0 VFS ops/sec and
2,1% CP

                Usage       Events/s    Category       Description
            100,0%                      Device         Audio codec
hwC0D3: Intel
            100,0%                      Device         Audio codec
hwC0D0: Realt
              0,9 ms/s      34,0        Timer          tick_sched_timer
              5,4 ms/s      16,2        Process        cairo-dock
              2,9 ms/s      16,0        Process        compiz
            228,4 µs/s      15,7        Process        [rcu_preempt]
            178,5 µs/s       9,8        kWork          ieee80211_iface_work
            109,7 µs/s       7,5        Interrupt      [28] i915
             79,8 µs/s       6,8        Process        [rcu_sched]
              0,8 ms/s       2,8        Process        powertop
              2,0 ms/s       2,0        Process
/usr/lib/xorg/Xorg -core
              0,8 ms/s       1,7        Interrupt      [6] tasklet(softirq)
            108,6 µs/s       1,8        Process        /usr/bin/redshift
-v -t65
             17,4 µs/s       1,8        kWork          blk_delay_work


Sorry to have added to your workload and keep up your good work!

Kind regards,

   Gunter.

Note You need to log in before you can comment on or make changes to this bug.