diff --git a/include/linux/sched/sysctl.h b/include/linux/sched/sysctl.h index d288478995f4..cd531a27bdf1 100644 --- a/include/linux/sched/sysctl.h +++ b/include/linux/sched/sysctl.h @@ -82,16 +82,6 @@ extern int sched_busy_hyst_handler(struct ctl_table *table, int write, void __user *buffer, size_t *lenp, loff_t *ppos); #endif -#if defined(CONFIG_PREEMPTIRQ_EVENTS) || defined(CONFIG_PREEMPT_TRACER) -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; -extern unsigned int sysctl_irqsoff_crash_sentinel_value; -extern unsigned int sysctl_irqsoff_crash_threshold_ns; -#endif - enum sched_tunable_scaling { SCHED_TUNABLESCALING_NONE, SCHED_TUNABLESCALING_LOG, diff --git a/include/trace/events/preemptirq.h b/include/trace/events/preemptirq.h index 4d8a539fce93..3f249e150c0c 100644 --- a/include/trace/events/preemptirq.h +++ b/include/trace/events/preemptirq.h @@ -62,73 +62,6 @@ DEFINE_EVENT(preemptirq_template, preempt_enable, #define trace_preempt_disable_rcuidle(...) #endif -TRACE_EVENT(irqs_disable, - - TP_PROTO(u64 delta, unsigned long caddr0, unsigned long caddr1, - unsigned long caddr2, unsigned long caddr3, - unsigned long caddr4), - - TP_ARGS(delta, caddr0, caddr1, caddr2, caddr3, caddr4), - - TP_STRUCT__entry( - __field(u64, delta) - __field(void*, caddr0) - __field(void*, caddr1) - __field(void*, caddr2) - __field(void*, caddr3) - __field(void*, caddr4) - ), - - TP_fast_assign( - __entry->delta = delta; - __entry->caddr0 = (void *)caddr0; - __entry->caddr1 = (void *)caddr1; - __entry->caddr2 = (void *)caddr2; - __entry->caddr3 = (void *)caddr3; - __entry->caddr4 = (void *)caddr4; - ), - - TP_printk("delta=%llu(ns) Callers:(%ps<-%ps<-%ps<-%ps<-%ps)", - __entry->delta, __entry->caddr0, - __entry->caddr1, __entry->caddr2, - __entry->caddr3, __entry->caddr4) -); - -TRACE_EVENT(sched_preempt_disable, - - TP_PROTO(u64 delta, bool irqs_disabled, unsigned long caddr0, - unsigned long caddr1, unsigned long caddr2, - unsigned long caddr3, unsigned long caddr4), - - TP_ARGS(delta, irqs_disabled, caddr0, caddr1, caddr2, caddr3, caddr4), - - TP_STRUCT__entry( - __field(u64, delta) - __field(bool, irqs_disabled) - __field(void*, caddr0) - __field(void*, caddr1) - __field(void*, caddr2) - __field(void*, caddr3) - __field(void*, caddr4) - ), - - TP_fast_assign( - __entry->delta = delta; - __entry->irqs_disabled = irqs_disabled; - __entry->caddr0 = (void *)caddr0; - __entry->caddr1 = (void *)caddr1; - __entry->caddr2 = (void *)caddr2; - __entry->caddr3 = (void *)caddr3; - __entry->caddr4 = (void *)caddr4; - ), - - TP_printk("delta=%llu(ns) irqs_d=%d Callers:(%ps<-%ps<-%ps<-%ps<-%ps)", - __entry->delta, __entry->irqs_disabled, - __entry->caddr0, __entry->caddr1, - __entry->caddr2, __entry->caddr3, - __entry->caddr4) -); - #endif /* _TRACE_PREEMPTIRQ_H */ #include diff --git a/include/trace/events/preemptirq_long.h b/include/trace/events/preemptirq_long.h new file mode 100644 index 000000000000..fa5d27cc8e8a --- /dev/null +++ b/include/trace/events/preemptirq_long.h @@ -0,0 +1,42 @@ +/* SPDX-License-Identifier: GPL-2.0-only */ +/* + * Copyright (c) 2020 The Linux Foundation. All rights reserved. + */ + +#undef TRACE_SYSTEM +#define TRACE_SYSTEM preemptirq_long + +#if !defined(_TRACE_PREEMPTIRQ_LONG_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_PREEMPTIRQ_LONG_H + +#include + +DECLARE_EVENT_CLASS(preemptirq_long_template, + + TP_PROTO(u64 delta), + + TP_ARGS(delta), + + TP_STRUCT__entry( + __field(u64, delta) + ), + + TP_fast_assign( + __entry->delta = delta; + ), + + TP_printk("delta=%llu(ns)", __entry->delta) +); + +DEFINE_EVENT(preemptirq_long_template, irq_disable_long, + TP_PROTO(u64 delta), + TP_ARGS(delta)); + +DEFINE_EVENT(preemptirq_long_template, preempt_disable_long, + TP_PROTO(u64 delta), + TP_ARGS(delta)); + +#endif /* _TRACE_PREEMPTIRQ_LONG_H */ + +/* This part must be outside protection */ +#include diff --git a/kernel/sysctl.c b/kernel/sysctl.c index 4ad247e545ec..ea162a9eb555 100644 --- a/kernel/sysctl.c +++ b/kernel/sysctl.c @@ -140,9 +140,6 @@ 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; -static unsigned int __maybe_unused one_million = 1000000; static int __maybe_unused max_kswapd_threads = MAX_KSWAPD_THREADS; #ifdef CONFIG_SCHED_WALT @@ -340,49 +337,6 @@ static struct ctl_table kern_table[] = { .mode = 0644, .proc_handler = proc_dointvec, }, -#if defined(CONFIG_PREEMPT_TRACER) && defined(CONFIG_PREEMPTIRQ_EVENTS) - { - .procname = "preemptoff_tracing_threshold_ns", - .data = &sysctl_preemptoff_tracing_threshold_ns, - .maxlen = sizeof(unsigned int), - .mode = 0644, - .proc_handler = proc_dointvec, - }, -#endif -#if defined(CONFIG_IRQSOFF_TRACER) && defined(CONFIG_PREEMPTIRQ_EVENTS) - { - .procname = "irqsoff_tracing_threshold_ns", - .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, - }, - { - .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 { .procname = "sched_user_hint", diff --git a/kernel/trace/Makefile b/kernel/trace/Makefile index b04b40bec355..f9f4512c617d 100644 --- a/kernel/trace/Makefile +++ b/kernel/trace/Makefile @@ -91,3 +91,5 @@ ifdef CONFIG_DEBUG_FS obj-$(CONFIG_IPC_LOGGING) += ipc_logging_debug.o endif libftrace-y := ftrace.o + +obj-$(CONFIG_PREEMPTIRQ_TRACEPOINTS) += preemptirq_long.o diff --git a/kernel/trace/preemptirq_long.c b/kernel/trace/preemptirq_long.c new file mode 100644 index 000000000000..6fa3df7a93c4 --- /dev/null +++ b/kernel/trace/preemptirq_long.c @@ -0,0 +1,165 @@ +// SPDX-License-Identifier: GPL-2.0-only +/* + * Copyright (c) 2020, The Linux Foundation. All rights reserved. + */ + +#include +#include +#include +#include +#include +#include + +#include +#include + +#define CREATE_TRACE_POINTS +#include + +#define IRQSOFF_SENTINEL 0x0fffDEAD + +static unsigned int sysctl_preemptoff_tracing_threshold_ns = 1000000; +static unsigned int sysctl_irqsoff_tracing_threshold_ns = 5000000; +static unsigned int sysctl_irqsoff_dmesg_output_enabled; +static unsigned int sysctl_irqsoff_crash_sentinel_value; +static unsigned int sysctl_irqsoff_crash_threshold_ns = 10000000; + +static unsigned int half_million = 500000; +static unsigned int one_hundred_million = 100000000; +static unsigned int one_million = 1000000; + +static DEFINE_PER_CPU(u64, irq_disabled_ts); +static DEFINE_PER_CPU(u64, preempt_disabled_ts); + +static void note_irq_disable(void *u1, unsigned long u2, unsigned long u3) +{ + if (is_idle_task(current)) + return; + + /* + * We just have to note down the time stamp here. We + * use stacktrace trigger feature to print the stacktrace. + */ + this_cpu_write(irq_disabled_ts, sched_clock()); +} + +static void test_irq_disable_long(void *u1, unsigned long u2, unsigned long u3) +{ + u64 ts = this_cpu_read(irq_disabled_ts); + + if (!ts) + return; + + this_cpu_write(irq_disabled_ts, 0); + ts = sched_clock() - ts; + + if (ts > sysctl_irqsoff_tracing_threshold_ns) { + trace_irq_disable_long(ts); + + if (sysctl_irqsoff_dmesg_output_enabled == IRQSOFF_SENTINEL) + printk_deferred("D=%llu C:(%ps<-%ps<-%ps<-%ps)\n", + ts, CALLER_ADDR2, CALLER_ADDR3, + CALLER_ADDR4, CALLER_ADDR5); + } + + if (sysctl_irqsoff_crash_sentinel_value == IRQSOFF_SENTINEL && + ts > sysctl_irqsoff_crash_threshold_ns) { + printk_deferred("delta=%llu(ns) > crash_threshold=%llu(ns) Task=%s\n", + ts, sysctl_irqsoff_crash_threshold_ns, + current->comm); + BUG_ON(1); + } +} + +static void note_preempt_disable(void *u1, unsigned long u2, unsigned long u3) +{ + this_cpu_write(preempt_disabled_ts, sched_clock()); +} + +static void test_preempt_disable_long(void *u1, unsigned long u2, + unsigned long u3) +{ + u64 ts = this_cpu_read(preempt_disabled_ts); + + if (!ts) + return; + + this_cpu_write(preempt_disabled_ts, 0); + ts = sched_clock() - ts; + + if (ts > sysctl_preemptoff_tracing_threshold_ns) + trace_preempt_disable_long(ts); +} + +static void note_context_switch(void *u1, bool u2, struct task_struct *u3, + struct task_struct *next) +{ + /* + * Discard false positives during context switch to idle. + */ + if (is_idle_task(next)) + this_cpu_write(preempt_disabled_ts, 0); +} + +static struct ctl_table preemptirq_long_table[] = { + { + .procname = "preemptoff_tracing_threshold_ns", + .data = &sysctl_preemptoff_tracing_threshold_ns, + .maxlen = sizeof(unsigned int), + .mode = 0644, + .proc_handler = proc_dointvec, + }, + { + .procname = "irqsoff_tracing_threshold_ns", + .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, + }, + { + .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, + }, + { } +}; + +static int preemptirq_long_init(void) +{ + if (!register_sysctl("preemptirq", preemptirq_long_table)) { + pr_err("Fail to register sysctl table\n"); + return -EPERM; + } + + register_trace_irq_disable(note_irq_disable, NULL); + register_trace_irq_enable(test_irq_disable_long, NULL); + + register_trace_preempt_disable(note_preempt_disable, NULL); + register_trace_preempt_enable(test_preempt_disable_long, NULL); + + register_trace_sched_switch(note_context_switch, NULL); + return 0; +} + +module_init(preemptirq_long_init); +MODULE_LICENSE("GPL v2"); diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c index f30ef80c9876..f61b23500da1 100644 --- a/kernel/trace/trace_irqsoff.c +++ b/kernel/trace/trace_irqsoff.c @@ -607,70 +607,12 @@ 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: 5ms - */ -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; - unsigned long caddr[5]; -}; - -static DEFINE_PER_CPU(struct irqsoff_store, the_irqsoff); -#endif /* CONFIG_PREEMPTIRQ_EVENTS */ - /* * We are only interested in hardirq on/off events: */ void tracer_hardirqs_on(unsigned long a0, unsigned long a1) { unsigned int pc = preempt_count(); -#ifdef CONFIG_PREEMPTIRQ_EVENTS - struct irqsoff_store *is; - u64 delta; - - lockdep_off(); - is = &per_cpu(the_irqsoff, raw_smp_processor_id()); - delta = sched_clock() - is->ts; - - if (!is_idle_task(current) && - delta > sysctl_irqsoff_tracing_threshold_ns) { - trace_irqs_disable(delta, is->caddr[0], is->caddr[1], - is->caddr[2], is->caddr[3], - is->caddr[4]); - 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]); - 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(); -#endif /* CONFIG_PREEMPTIRQ_EVENTS */ if (!preempt_trace(pc) && irq_trace()) stop_critical_timing(a0, a1, pc); @@ -680,19 +622,6 @@ NOKPROBE_SYMBOL(tracer_hardirqs_on); void tracer_hardirqs_off(unsigned long a0, unsigned long a1) { unsigned int pc = preempt_count(); -#ifdef CONFIG_PREEMPTIRQ_EVENTS - struct irqsoff_store *is; - - lockdep_off(); - is = &per_cpu(the_irqsoff, raw_smp_processor_id()); - is->ts = sched_clock(); - is->caddr[0] = CALLER_ADDR1; - is->caddr[1] = CALLER_ADDR2; - is->caddr[2] = CALLER_ADDR3; - is->caddr[3] = CALLER_ADDR4; - is->caddr[4] = CALLER_ADDR5; - lockdep_on(); -#endif /* CONFIG_PREEMPTIRQ_EVENTS */ if (!preempt_trace(pc) && irq_trace()) start_critical_timing(a0, a1, pc); @@ -733,57 +662,9 @@ static struct tracer irqsoff_tracer __read_mostly = #endif /* CONFIG_IRQSOFF_TRACER */ #ifdef CONFIG_PREEMPT_TRACER -#ifdef CONFIG_PREEMPTIRQ_EVENTS -/* - * preemptoff stack tracing threshold in ns. - * default: 1ms - */ -unsigned int sysctl_preemptoff_tracing_threshold_ns = 1000000UL; - -struct preempt_store { - u64 ts; - unsigned long caddr[5]; - bool irqs_disabled; - int pid; - unsigned long ncsw; -}; - -static DEFINE_PER_CPU(struct preempt_store, the_ps); -#endif /* CONFIG_PREEMPTIRQ_EVENTS */ - void tracer_preempt_on(unsigned long a0, unsigned long a1) { int pc = preempt_count(); -#ifdef CONFIG_PREEMPTIRQ_EVENTS - struct preempt_store *ps; - u64 delta = 0; - - lockdep_off(); - ps = &per_cpu(the_ps, raw_smp_processor_id()); - - /* - * schedule() calls __schedule() with preemption disabled. - * if we had entered idle and exiting idle now, we think - * preemption is disabled the whole time. Detect this by - * checking if the preemption is disabled across the same - * task. There is a possiblity that the same task is scheduled - * after idle. To rule out this possibility, compare the - * context switch count also. - */ - if (ps->ts && ps->pid == current->pid && (ps->ncsw == - current->nvcsw + current->nivcsw)) - delta = sched_clock() - ps->ts; - /* - * Trace preempt disable stack if preemption - * is disabled for more than the threshold. - */ - if (delta > sysctl_preemptoff_tracing_threshold_ns) - trace_sched_preempt_disable(delta, ps->irqs_disabled, - ps->caddr[0], ps->caddr[1], - ps->caddr[2], ps->caddr[3], ps->caddr[4]); - ps->ts = 0; - lockdep_on(); -#endif /* CONFIG_PREEMPTIRQ_EVENTS */ if (preempt_trace(pc) && !irq_trace()) stop_critical_timing(a0, a1, pc); @@ -792,22 +673,6 @@ void tracer_preempt_on(unsigned long a0, unsigned long a1) void tracer_preempt_off(unsigned long a0, unsigned long a1) { int pc = preempt_count(); -#ifdef CONFIG_PREEMPTIRQ_EVENTS - struct preempt_store *ps; - - lockdep_off(); - ps = &per_cpu(the_ps, raw_smp_processor_id()); - ps->ts = sched_clock(); - ps->caddr[0] = CALLER_ADDR1; - ps->caddr[1] = CALLER_ADDR2; - ps->caddr[2] = CALLER_ADDR3; - ps->caddr[3] = CALLER_ADDR4; - ps->caddr[4] = CALLER_ADDR5; - ps->irqs_disabled = irqs_disabled(); - ps->pid = current->pid; - ps->ncsw = current->nvcsw + current->nivcsw; - lockdep_on(); -#endif /* CONFIG_PREEMPTIRQ_EVENTS */ if (preempt_trace(pc) && !irq_trace()) start_critical_timing(a0, a1, pc);