Messages in this thread | | | From | Rei Yamamoto <> | Subject | Re: [PATCH] hrtimer: CPU and entry_time is added to a warning message in hrtimer_interrupt() | Date | Fri, 9 Sep 2022 14:22:11 +0900 |
| |
Hi, Thomas Gleixner.
On Fri, 24 Jun 2022 16:00:11, Rei Yamamoto wrote: > A warning message in hrtimer_interrupt() is output up to 5 times > by default, and CPU and entry_time are also shown. > These changes are helpful that the function spending a lot of time is clear > by using ftrace: > ----- > dmesg > : > [ 1462.836971] start repro_hrtimer_interrupt > [ 1462.836976] test_handler = test_handler [repro] 0xffff9788f7bb3048 > : > [ 1462.879117] hrtimer: CPU 7, entry_time = 1462807264840, interrupt took > 60048886 ns ^^^^^ ^^^^^^^^^^^^^ > > cat /sys/kernel/debug/tracing/trace > : > <idle>-0 [007] d.h1. 1462.838075: hrtimer_expire_entry: > ^^^^^ > hrtimer=0000000041fcee42 function=test_handler [repro] now=1462807264840 > ^^^^^^^^^^^^^ > ----- > > Signed-off-by: Rei Yamamoto <yamamoto.rei@jp.fujitsu.com> > --- > include/linux/hrtimer.h | 1 + > kernel/sysctl.c | 10 ++++++++++ > kernel/time/hrtimer.c | 16 +++++++++++++++- > 3 files changed, 26 insertions(+), 1 deletion(-) > > diff --git a/include/linux/hrtimer.h b/include/linux/hrtimer.h > index 0ee140176f10..1a6e03b3015b 100644 > --- a/include/linux/hrtimer.h > +++ b/include/linux/hrtimer.h > @@ -317,6 +317,7 @@ static inline int hrtimer_is_hres_active(struct hrtimer *timer) > struct clock_event_device; > > extern void hrtimer_interrupt(struct clock_event_device *dev); > +extern int sysctl_hrtimer_interrupt_warnings; > > extern unsigned int hrtimer_resolution; > > diff --git a/kernel/sysctl.c b/kernel/sysctl.c > index e52b6e372c60..b0420d60cec9 100644 > --- a/kernel/sysctl.c > +++ b/kernel/sysctl.c > @@ -64,6 +64,7 @@ > #include <linux/mount.h> > #include <linux/userfaultfd_k.h> > #include <linux/pid.h> > +#include <linux/hrtimer.h> > > #include "../lib/kstrtox.h" > > @@ -2038,6 +2039,15 @@ static struct ctl_table kern_table[] = { > .extra1 = SYSCTL_ONE, > .extra2 = SYSCTL_INT_MAX, > }, > +#endif > +#ifdef CONFIG_HIGH_RES_TIMERS > + { > + .procname = "hrtimer_interrupt_warnings", > + .data = &sysctl_hrtimer_interrupt_warnings, > + .maxlen = sizeof(int), > + .mode = 0644, > + .proc_handler = proc_dointvec, > + }, > #endif > { } > }; > diff --git a/kernel/time/hrtimer.c b/kernel/time/hrtimer.c > index 0ea8702eb516..19adcbcf92e4 100644 > --- a/kernel/time/hrtimer.c > +++ b/kernel/time/hrtimer.c > @@ -1773,6 +1773,7 @@ static __latent_entropy void hrtimer_run_softirq(struct softirq_action *h) > } > > #ifdef CONFIG_HIGH_RES_TIMERS > +int sysctl_hrtimer_interrupt_warnings = 5; > > /* > * High resolution timer interrupt > @@ -1866,7 +1867,20 @@ void hrtimer_interrupt(struct clock_event_device *dev) > else > expires_next = ktime_add(now, delta); > tick_program_event(expires_next, 1); > - pr_warn_once("hrtimer: interrupt took %llu ns\n", ktime_to_ns(delta)); > + > + /* > + * If a message is output many times, the delayed funciton > + * may be identified by resetting sysctl_hrtimer_interrupt_warnings > + * and enabling ftrace. > + */ > + if (sysctl_hrtimer_interrupt_warnings) { > + if (sysctl_hrtimer_interrupt_warnings > 0) > + sysctl_hrtimer_interrupt_warnings--; > + pr_warn("hrtimer: CPU %d, entry_time = %llu, " > + "interrupt took %llu ns\n", > + cpu_base->cpu, entry_time, > + ktime_to_ns(delta)); > + } > } > > /* called with interrupts disabled */
Could you pick this patch up?
Thanks, Rei
| |