"perf: interrupt took too long" messages even with perf_cpu_time_max_percent==0

DISCUSSION Markus Trippelsdorf 2 participants 6 messages Apr 2, 2016 – Apr 13, 2016 perf events

Share & tools

Markus Trippelsdorf

author

2016-04-02 09:32 UTC #0 lore raw

Current git kernel sometimes shows:

perf: interrupt took too long (71 > 52), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (103 > 88), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (130 > 128), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (175 > 162), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (219 > 218), lowering kernel.perf_event_max_sample_rate to 300
...

when running e.g. "perf top" even when /proc/sys/kernel/perf_cpu_time_max_percent is set to 0.

Signature · 1 line

Markus

Peter Zijlstra

maintainer

2016-04-02 11:00 UTC #1 lore raw

Quoted 11 lines · Markus Trippelsdorf

Current git kernel sometimes shows:
perf: interrupt took too long (71 > 52), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (103 > 88), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (130 > 128), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (175 > 162), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (219 > 218), lowering kernel.perf_event_max_sample_rate to 300
...
when running e.g. "perf top" even when /proc/sys/kernel/perf_cpu_time_max_percent is set to 0.

Ah, was 0 also meant to disable it?

Does the below help?

---
 kernel/events/core.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

kernel/events/core.c +2 -1

index 8c3b35f2a269..21ba024c9ed1 100644
@@ -412,7 +412,8 @@ int perf_cpu_time_max_percent_handler(struct ctl_table *table, int write,
 	if (ret || !write)
 		return ret;
 
-	if (sysctl_perf_cpu_time_max_percent == 100) {
+	if (sysctl_perf_cpu_time_max_percent == 100 ||
+	    sysctl_perf_cpu_time_max_percent == 0) {
 		printk(KERN_WARNING
 		       "perf: Dynamic interrupt throttling disabled, can hang your system!\n");
 		WRITE_ONCE(perf_sample_allowed_ns, 0);

Markus Trippelsdorf

author

2016-04-02 11:17 UTC #2 lore raw

Quoted 10 lines · Peter Zijlstra

Quoted 9 lines · Markus Trippelsdorf
Current git kernel sometimes shows:
perf: interrupt took too long (71 > 52), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (103 > 88), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (130 > 128), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (175 > 162), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (219 > 218), lowering kernel.perf_event_max_sample_rate to 300
...

Quoted 5 lines

Quoted 2 lines
when running e.g. "perf top" even when /proc/sys/kernel/perf_cpu_time_max_percent is set to 0.
Ah, was 0 also meant to disable it?

Yes. From Documentation/sysctl/kernel.txt:

perf_cpu_time_max_percent:

Hints to the kernel how much CPU time it should be allowed to use to handle perf sampling events. If the perf subsystem is informed that its samples are exceeding this limit, it will drop its sampling frequency to attempt to reduce its CPU usage.

Some perf sampling happens in NMIs. If these samples unexpectedly take too long to execute, the NMIs can become stacked up next to each other so much that nothing else is allowed to execute.

0: disable the mechanism. Do not monitor or correct perf's
sampling rate no matter how CPU time it takes.

1-100: attempt to throttle perf's sample rate to this
percentage of CPU. Note: the kernel calculates an "expected" length of each sample event. 100 here means 100% of that expected length. Even if this is set to 100, you may still see sample throttling if this length is exceeded. Set to 0 if you truly do not care how much CPU is consumed.

Quoted 1 line

Does the below help?

Thanks. I will test it later. But 91a612eea9a3 makes the assumption that only sysctl_perf_cpu_time_max_percent==100 disables the feature also in kernel/events/core.c.

--
Markus

Markus Trippelsdorf

author

2016-04-02 11:23 UTC #3 lore raw

Quoted 5 lines · Markus Trippelsdorf

Quoted 1 line
Does the below help?
Thanks. I will test it later. But 91a612eea9a3 makes the assumption that only sysctl_perf_cpu_time_max_percent==100 disables the feature also in kernel/events/core.c.

Please ignore the last sentence. It doesn't make sense.

Signature · 1 line

Markus

Peter Zijlstra

maintainer

2016-04-02 16:33 UTC #4 lore raw

In reply to Markus Trippelsdorf

Quoted 5 lines · Markus Trippelsdorf

Quoted 1 line · Peter Zijlstra
Ah, was 0 also meant to disable it?
Yes. From Documentation/sysctl/kernel.txt:

Oh wow, we have documentation on this! Learn something new every day :-)

Markus Trippelsdorf

author

2016-04-13 10:03 UTC #5 lore raw

In reply to Peter Zijlstra

Quoted 10 lines · Peter Zijlstra

Quoted 9 lines · Markus Trippelsdorf
Current git kernel sometimes shows:
perf: interrupt took too long (71 > 52), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (103 > 88), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (130 > 128), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (175 > 162), lowering kernel.perf_event_max_sample_rate to 300
perf: interrupt took too long (219 > 218), lowering kernel.perf_event_max_sample_rate to 300
...

Quoted 7 lines

Quoted 2 lines
when running e.g. "perf top" even when /proc/sys/kernel/perf_cpu_time_max_percent is set to 0.
Ah, was 0 also meant to disable it?
Does the below help?

Yes, it obviously fixes the issue.

Signature · 1 line

Markus