From dc28abd85186f16dafa247ef87c1958e23b7f59c Mon Sep 17 00:00:00 2001 From: Sai Harshini Nimmala Date: Wed, 26 Feb 2020 12:30:22 -0800 Subject: [PATCH 1/2] trace: Toggle irqsoff tracing to dmesg Allow tracing irqsoff to dmesg based on userspace tunable. Change-Id: I36ca46c787d25ec08a6d050eed4ce0a23db26a1a Signed-off-by: Sai Harshini Nimmala --- include/linux/sched/sysctl.h | 1 + kernel/sysctl.c | 11 +++++++++++ kernel/trace/trace_irqsoff.c | 16 +++++++++++++--- 3 files changed, 25 insertions(+), 3 deletions(-) diff --git a/include/linux/sched/sysctl.h b/include/linux/sched/sysctl.h index c0aad38a993d..5c7974b7f27d 100644 --- a/include/linux/sched/sysctl.h +++ b/include/linux/sched/sysctl.h @@ -82,6 +82,7 @@ extern unsigned int sysctl_preemptoff_tracing_threshold_ns; #endif #if defined(CONFIG_PREEMPTIRQ_EVENTS) && defined(CONFIG_IRQSOFF_TRACER) extern unsigned int sysctl_irqsoff_tracing_threshold_ns; +extern unsigned int sysctl_irqsoff_dmesg_output_enabled; #endif enum sched_tunable_scaling { diff --git a/kernel/sysctl.c b/kernel/sysctl.c index 45380ac22a51..4deb2310c63b 100644 --- a/kernel/sysctl.c +++ b/kernel/sysctl.c @@ -141,6 +141,8 @@ static int ten_thousand = 10000; #ifdef CONFIG_PERF_EVENTS static int six_hundred_forty_kb = 640 * 1024; #endif +static unsigned int __maybe_unused half_million = 500000; +static unsigned int __maybe_unused one_hundred_million = 100000000; #ifdef CONFIG_SCHED_WALT static int neg_three = -3; static int three = 3; @@ -355,6 +357,15 @@ static struct ctl_table kern_table[] = { .data = &sysctl_irqsoff_tracing_threshold_ns, .maxlen = sizeof(unsigned int), .mode = 0644, + .proc_handler = proc_douintvec_minmax, + .extra1 = &half_million, + .extra2 = &one_hundred_million, + }, + { + .procname = "irqsoff_dmesg_output_enabled", + .data = &sysctl_irqsoff_dmesg_output_enabled, + .maxlen = sizeof(unsigned int), + .mode = 0644, .proc_handler = proc_dointvec, }, #endif diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c index bd251354be5d..46b6b1ae6257 100644 --- a/kernel/trace/trace_irqsoff.c +++ b/kernel/trace/trace_irqsoff.c @@ -608,11 +608,16 @@ static void irqsoff_tracer_stop(struct trace_array *tr) #ifdef CONFIG_IRQSOFF_TRACER #ifdef CONFIG_PREEMPTIRQ_EVENTS +#define IRQSOFF_SENTINEL 0x0fffDEAD /* * irqsoff stack tracing threshold in ns. - * default: 1ms + * default: 5ms */ -unsigned int sysctl_irqsoff_tracing_threshold_ns = 1000000UL; +unsigned int sysctl_irqsoff_tracing_threshold_ns = 5000000UL; +/* + * Enable irqsoff tracing to dmesg + */ +unsigned int sysctl_irqsoff_dmesg_output_enabled; struct irqsoff_store { u64 ts; @@ -637,9 +642,14 @@ void tracer_hardirqs_on(unsigned long a0, unsigned long a1) delta = sched_clock() - is->ts; if (!is_idle_task(current) && - delta > sysctl_irqsoff_tracing_threshold_ns) + delta > sysctl_irqsoff_tracing_threshold_ns) { trace_irqs_disable(delta, is->caddr[0], is->caddr[1], is->caddr[2], is->caddr[3]); + if (sysctl_irqsoff_dmesg_output_enabled == IRQSOFF_SENTINEL) + printk_deferred(KERN_ERR "D=%llu C:(%ps<-%ps<-%ps<-%ps)\n", + delta, is->caddr[0], is->caddr[1], + is->caddr[2], is->caddr[3]); + } is->ts = 0; lockdep_on(); #endif /* CONFIG_PREEMPTIRQ_EVENTS */ From 2c6c2435c885733e2fcf933767c46972bf0a6660 Mon Sep 17 00:00:00 2001 From: Sai Harshini Nimmala Date: Fri, 28 Feb 2020 15:05:43 -0800 Subject: [PATCH 2/2] trace: Add warning threshold for irqsoff time Trigger a crash when hardirqs_off time period crosses the warning threshold. Change-Id: Ifa96a51cd27a154ee2c207c82f1a145a80558c76 Signed-off-by: Sai Harshini Nimmala --- include/linux/sched/sysctl.h | 2 ++ kernel/sysctl.c | 17 +++++++++++++++++ kernel/trace/trace_irqsoff.c | 16 ++++++++++++++++ 3 files changed, 35 insertions(+) diff --git a/include/linux/sched/sysctl.h b/include/linux/sched/sysctl.h index 5c7974b7f27d..a5f514d5a891 100644 --- a/include/linux/sched/sysctl.h +++ b/include/linux/sched/sysctl.h @@ -83,6 +83,8 @@ extern unsigned int sysctl_preemptoff_tracing_threshold_ns; #if defined(CONFIG_PREEMPTIRQ_EVENTS) && defined(CONFIG_IRQSOFF_TRACER) extern unsigned int sysctl_irqsoff_tracing_threshold_ns; extern unsigned int sysctl_irqsoff_dmesg_output_enabled; +extern unsigned int sysctl_irqsoff_crash_sentinel_value; +extern unsigned int sysctl_irqsoff_crash_threshold_ns; #endif enum sched_tunable_scaling { diff --git a/kernel/sysctl.c b/kernel/sysctl.c index 4deb2310c63b..38fc40877530 100644 --- a/kernel/sysctl.c +++ b/kernel/sysctl.c @@ -143,6 +143,7 @@ static int six_hundred_forty_kb = 640 * 1024; #endif static unsigned int __maybe_unused half_million = 500000; static unsigned int __maybe_unused one_hundred_million = 100000000; +static unsigned int __maybe_unused one_million = 1000000; #ifdef CONFIG_SCHED_WALT static int neg_three = -3; static int three = 3; @@ -368,6 +369,22 @@ static struct ctl_table kern_table[] = { .mode = 0644, .proc_handler = proc_dointvec, }, + { + .procname = "irqsoff_crash_sentinel_value", + .data = &sysctl_irqsoff_crash_sentinel_value, + .maxlen = sizeof(unsigned int), + .mode = 0644, + .proc_handler = proc_dointvec, + }, + { + .procname = "irqsoff_crash_threshold_ns", + .data = &sysctl_irqsoff_crash_threshold_ns, + .maxlen = sizeof(unsigned int), + .mode = 0644, + .proc_handler = proc_douintvec_minmax, + .extra1 = &one_million, + .extra2 = &one_hundred_million, + }, #endif #ifdef CONFIG_SCHED_WALT { diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c index 46b6b1ae6257..9f8456001101 100644 --- a/kernel/trace/trace_irqsoff.c +++ b/kernel/trace/trace_irqsoff.c @@ -618,6 +618,14 @@ unsigned int sysctl_irqsoff_tracing_threshold_ns = 5000000UL; * Enable irqsoff tracing to dmesg */ unsigned int sysctl_irqsoff_dmesg_output_enabled; +/* + * Sentinel value to prevent unnecessary irqsoff crash + */ +unsigned int sysctl_irqsoff_crash_sentinel_value; +/* + * Irqsoff warning threshold to trigger crash + */ +unsigned int sysctl_irqsoff_crash_threshold_ns = 10000000UL; struct irqsoff_store { u64 ts; @@ -649,6 +657,14 @@ void tracer_hardirqs_on(unsigned long a0, unsigned long a1) printk_deferred(KERN_ERR "D=%llu C:(%ps<-%ps<-%ps<-%ps)\n", delta, is->caddr[0], is->caddr[1], is->caddr[2], is->caddr[3]); + if (sysctl_irqsoff_crash_sentinel_value == IRQSOFF_SENTINEL && + delta > sysctl_irqsoff_crash_threshold_ns) { + printk_deferred(KERN_ERR + "delta=%llu(ns) > crash_threshold=%llu(ns) Task=%s\n", + delta, sysctl_irqsoff_crash_threshold_ns, + current->comm); + BUG_ON(1); + } } is->ts = 0; lockdep_on();