[PATCH RFC ftrace/core] tracing: Directly call tracer and lockdep probes

From: Joel Fernandes (Google)
Date: Wed Aug 08 2018 - 18:00:56 EST


From: Steven Rostedt <rostedt@xxxxxxxxxxx>

Due to various problems with using tracepoints as probes for IRQ
enable/disable and preempt enable/disable: such as using SRCU in NMI
context and other issues with the irqsoff/preemptoff tracer, directly
call the lockdep and irqsoff tracer probes for now. This keeps all the
other benefits and clean ups of the patch being partially reverted.

Based on Steve's original Partial revert patch. I added directly calling
irqsoff tracer probes as well.

Fixes: c3bc8fd637a9 ("tracing: Centralize preemptirq tracepoints and unify their usage")
Signed-off-by: Joel Fernandes (Google) <joel@xxxxxxxxxxxxxxxxx>
---
Steve, I expanded your partial revert such that it fixes the remaining
issues as well while keeping the clean ups and benefits of my original
patch. Its based on the latest ftrace/core. I'm still testing it, but it
works so far. What do you think? I feel like it could still be a step
forward for this merge window.
Also you could drop "tracepoint: Make rcuidle tracepoint callers use
SRCU" since its not needed anymore for this merge window.

Tests passing so far:
- ftrace startup tests
- locking api self-tests
- manually tested preemptoff and irqsoff tracers
- manually tested preempt/irq disable and enable events
- boot tested without warnings

include/linux/irqflags.h | 4 ++
include/linux/lockdep.h | 2 -
init/main.c | 2 -
kernel/locking/lockdep.c | 14 +------
kernel/trace/trace.h | 16 ++++++++
kernel/trace/trace_irqsoff.c | 26 ++-----------
kernel/trace/trace_preemptirq.c | 66 ++++++++++++++++++++++++---------
7 files changed, 75 insertions(+), 55 deletions(-)

diff --git a/include/linux/irqflags.h b/include/linux/irqflags.h
index 50edb9cbbd26..19a90ac7c87d 100644
--- a/include/linux/irqflags.h
+++ b/include/linux/irqflags.h
@@ -19,9 +19,13 @@
#ifdef CONFIG_PROVE_LOCKING
extern void trace_softirqs_on(unsigned long ip);
extern void trace_softirqs_off(unsigned long ip);
+ extern void lockdep_hardirqs_on(unsigned long ip);
+ extern void lockdep_hardirqs_off(unsigned long ip);
#else
# define trace_softirqs_on(ip) do { } while (0)
# define trace_softirqs_off(ip) do { } while (0)
+# define lockdep_hardirqs_on(ip) do { } while (0)
+# define lockdep_hardirqs_off(ip) do { } while (0)
#endif

#ifdef CONFIG_TRACE_IRQFLAGS
diff --git a/include/linux/lockdep.h b/include/linux/lockdep.h
index a8113357ceeb..b0d0b51c4d85 100644
--- a/include/linux/lockdep.h
+++ b/include/linux/lockdep.h
@@ -267,7 +267,6 @@ struct held_lock {
* Initialization, self-test and debugging-output methods:
*/
extern void lockdep_init(void);
-extern void lockdep_init_early(void);
extern void lockdep_reset(void);
extern void lockdep_reset_lock(struct lockdep_map *lock);
extern void lockdep_free_key_range(void *start, unsigned long size);
@@ -408,7 +407,6 @@ static inline void lockdep_on(void)
# define lock_set_class(l, n, k, s, i) do { } while (0)
# define lock_set_subclass(l, s, i) do { } while (0)
# define lockdep_init() do { } while (0)
-# define lockdep_init_early() do { } while (0)
# define lockdep_init_map(lock, name, key, sub) \
do { (void)(name); (void)(key); } while (0)
# define lockdep_set_class(lock, key) do { (void)(key); } while (0)
diff --git a/init/main.c b/init/main.c
index 44fe43be84c1..5d42e577643a 100644
--- a/init/main.c
+++ b/init/main.c
@@ -649,8 +649,6 @@ asmlinkage __visible void __init start_kernel(void)
call_function_init();
WARN(!irqs_disabled(), "Interrupts were enabled early\n");

- lockdep_init_early();
-
early_boot_irqs_disabled = false;
local_irq_enable();

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 03bfaeb9f4e6..e406c5fdb41e 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -2840,8 +2840,7 @@ static void __trace_hardirqs_on_caller(unsigned long ip)
debug_atomic_inc(hardirqs_on_events);
}

-static void lockdep_hardirqs_on(void *none, unsigned long ignore,
- unsigned long ip)
+void lockdep_hardirqs_on(unsigned long ip)
{
if (unlikely(!debug_locks || current->lockdep_recursion))
return;
@@ -2885,8 +2884,7 @@ static void lockdep_hardirqs_on(void *none, unsigned long ignore,
/*
* Hardirqs were disabled:
*/
-static void lockdep_hardirqs_off(void *none, unsigned long ignore,
- unsigned long ip)
+void lockdep_hardirqs_off(unsigned long ip)
{
struct task_struct *curr = current;

@@ -4315,14 +4313,6 @@ void lockdep_reset_lock(struct lockdep_map *lock)
raw_local_irq_restore(flags);
}

-void __init lockdep_init_early(void)
-{
-#ifdef CONFIG_PROVE_LOCKING
- register_trace_prio_irq_disable(lockdep_hardirqs_off, NULL, INT_MAX);
- register_trace_prio_irq_enable(lockdep_hardirqs_on, NULL, INT_MIN);
-#endif
-}
-
void __init lockdep_init(void)
{
printk("Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar\n");
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index e1c8a1d6f240..74db16fe1fab 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -1829,4 +1829,20 @@ static inline int tracing_alloc_snapshot_instance(struct trace_array *tr)

extern struct trace_iterator *tracepoint_print_iter;

+#ifdef CONFIG_IRQSOFF_TRACER
+void tracer_hardirqs_on(void *none, unsigned long a0, unsigned long a1);
+void tracer_hardirqs_off(void *none, unsigned long a0, unsigned long a1);
+#else
+void tracer_hardirqs_on(void *none, unsigned long a0, unsigned long a1) { }
+void tracer_hardirqs_off(void *none, unsigned long a0, unsigned long a1) { }
+#endif
+
+#ifdef CONFIG_PREEMPT_TRACER
+void tracer_preempt_on(void *none, unsigned long a0, unsigned long a1);
+void tracer_preempt_off(void *none, unsigned long a0, unsigned long a1);
+#else
+void tracer_preempt_on(void *none, unsigned long a0, unsigned long a1) { }
+void tracer_preempt_off(void *none, unsigned long a0, unsigned long a1) { }
+#endif
+
#endif /* _LINUX_KERNEL_TRACE_H */
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index 770cd30cda40..d61d42e431e9 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -601,13 +601,13 @@ static void irqsoff_tracer_stop(struct trace_array *tr)
/*
* We are only interested in hardirq on/off events:
*/
-static void tracer_hardirqs_on(void *none, unsigned long a0, unsigned long a1)
+void tracer_hardirqs_on(void *none, unsigned long a0, unsigned long a1)
{
if (!preempt_trace() && irq_trace())
stop_critical_timing(a0, a1);
}

-static void tracer_hardirqs_off(void *none, unsigned long a0, unsigned long a1)
+void tracer_hardirqs_off(void *none, unsigned long a0, unsigned long a1)
{
if (!preempt_trace() && irq_trace())
start_critical_timing(a0, a1);
@@ -617,15 +617,11 @@ static int irqsoff_tracer_init(struct trace_array *tr)
{
trace_type = TRACER_IRQS_OFF;

- register_trace_irq_disable(tracer_hardirqs_off, NULL);
- register_trace_irq_enable(tracer_hardirqs_on, NULL);
return __irqsoff_tracer_init(tr);
}

static void irqsoff_tracer_reset(struct trace_array *tr)
{
- unregister_trace_irq_disable(tracer_hardirqs_off, NULL);
- unregister_trace_irq_enable(tracer_hardirqs_on, NULL);
__irqsoff_tracer_reset(tr);
}

@@ -651,13 +647,13 @@ static struct tracer irqsoff_tracer __read_mostly =
#endif /* CONFIG_IRQSOFF_TRACER */

#ifdef CONFIG_PREEMPT_TRACER
-static void tracer_preempt_on(void *none, unsigned long a0, unsigned long a1)
+void tracer_preempt_on(void *none, unsigned long a0, unsigned long a1)
{
if (preempt_trace() && !irq_trace())
stop_critical_timing(a0, a1);
}

-static void tracer_preempt_off(void *none, unsigned long a0, unsigned long a1)
+void tracer_preempt_off(void *none, unsigned long a0, unsigned long a1)
{
if (preempt_trace() && !irq_trace())
start_critical_timing(a0, a1);
@@ -667,15 +663,11 @@ static int preemptoff_tracer_init(struct trace_array *tr)
{
trace_type = TRACER_PREEMPT_OFF;

- register_trace_preempt_disable(tracer_preempt_off, NULL);
- register_trace_preempt_enable(tracer_preempt_on, NULL);
return __irqsoff_tracer_init(tr);
}

static void preemptoff_tracer_reset(struct trace_array *tr)
{
- unregister_trace_preempt_disable(tracer_preempt_off, NULL);
- unregister_trace_preempt_enable(tracer_preempt_on, NULL);
__irqsoff_tracer_reset(tr);
}

@@ -706,21 +698,11 @@ static int preemptirqsoff_tracer_init(struct trace_array *tr)
{
trace_type = TRACER_IRQS_OFF | TRACER_PREEMPT_OFF;

- register_trace_irq_disable(tracer_hardirqs_off, NULL);
- register_trace_irq_enable(tracer_hardirqs_on, NULL);
- register_trace_preempt_disable(tracer_preempt_off, NULL);
- register_trace_preempt_enable(tracer_preempt_on, NULL);
-
return __irqsoff_tracer_init(tr);
}

static void preemptirqsoff_tracer_reset(struct trace_array *tr)
{
- unregister_trace_irq_disable(tracer_hardirqs_off, NULL);
- unregister_trace_irq_enable(tracer_hardirqs_on, NULL);
- unregister_trace_preempt_disable(tracer_preempt_off, NULL);
- unregister_trace_preempt_enable(tracer_preempt_on, NULL);
-
__irqsoff_tracer_reset(tr);
}

diff --git a/kernel/trace/trace_preemptirq.c b/kernel/trace/trace_preemptirq.c
index e76b78bf258e..bd5654e9f886 100644
--- a/kernel/trace/trace_preemptirq.c
+++ b/kernel/trace/trace_preemptirq.c
@@ -9,6 +9,7 @@
#include <linux/uaccess.h>
#include <linux/module.h>
#include <linux/ftrace.h>
+#include "trace.h"

#define CREATE_TRACE_POINTS
#include <trace/events/preemptirq.h>
@@ -19,54 +20,85 @@ static DEFINE_PER_CPU(int, tracing_irq_cpu);

void trace_hardirqs_on(void)
{
- if (!this_cpu_read(tracing_irq_cpu))
- return;
+ if (this_cpu_read(tracing_irq_cpu)) {
+ trace_irq_enable_rcuidle(CALLER_ADDR0, CALLER_ADDR1);

- trace_irq_enable_rcuidle(CALLER_ADDR0, CALLER_ADDR1);
- this_cpu_write(tracing_irq_cpu, 0);
+ /* irqsoff tracer */
+ tracer_hardirqs_on(NULL /* unused */, CALLER_ADDR0, CALLER_ADDR1);
+
+ this_cpu_write(tracing_irq_cpu, 0);
+ }
+
+ /* Call last so future IRQ state is noted last */
+ lockdep_hardirqs_on(CALLER_ADDR0);
}
EXPORT_SYMBOL(trace_hardirqs_on);

void trace_hardirqs_off(void)
{
- if (this_cpu_read(tracing_irq_cpu))
- return;
+ /* Call first so IRQ state is updated */
+ lockdep_hardirqs_off(CALLER_ADDR0);
+
+ if (!this_cpu_read(tracing_irq_cpu)) {
+ /* prevent recursion */
+ this_cpu_write(tracing_irq_cpu, 1);

- this_cpu_write(tracing_irq_cpu, 1);
- trace_irq_disable_rcuidle(CALLER_ADDR0, CALLER_ADDR1);
+ trace_irq_disable_rcuidle(CALLER_ADDR0, CALLER_ADDR1);
+
+ /* irqsoff tracer */
+ tracer_hardirqs_off(NULL /* unused */, CALLER_ADDR0, CALLER_ADDR1);
+ }
}
EXPORT_SYMBOL(trace_hardirqs_off);

__visible void trace_hardirqs_on_caller(unsigned long caller_addr)
{
- if (!this_cpu_read(tracing_irq_cpu))
- return;
+ if (this_cpu_read(tracing_irq_cpu)) {
+ trace_irq_enable_rcuidle(CALLER_ADDR0, caller_addr);
+
+ /* irqsoff tracer */
+ tracer_hardirqs_on(NULL /* unused */, CALLER_ADDR0, caller_addr);
+
+ this_cpu_write(tracing_irq_cpu, 0);
+ }

- trace_irq_enable_rcuidle(CALLER_ADDR0, caller_addr);
- this_cpu_write(tracing_irq_cpu, 0);
+ /* Call last so future IRQ state is noted last */
+ lockdep_hardirqs_on(CALLER_ADDR0);
}
EXPORT_SYMBOL(trace_hardirqs_on_caller);

__visible void trace_hardirqs_off_caller(unsigned long caller_addr)
{
- if (this_cpu_read(tracing_irq_cpu))
- return;
+ /* Call first so IRQ state is updated */
+ lockdep_hardirqs_off(CALLER_ADDR0);

- this_cpu_write(tracing_irq_cpu, 1);
- trace_irq_disable_rcuidle(CALLER_ADDR0, caller_addr);
+ if (!this_cpu_read(tracing_irq_cpu)) {
+ /* prevent recursion */
+ this_cpu_write(tracing_irq_cpu, 1);
+
+ trace_irq_disable_rcuidle(CALLER_ADDR0, CALLER_ADDR1);
+
+ /* irqsoff tracer */
+ tracer_hardirqs_off(NULL /* unused */, CALLER_ADDR0, CALLER_ADDR1);
+ }
}
EXPORT_SYMBOL(trace_hardirqs_off_caller);
#endif /* CONFIG_TRACE_IRQFLAGS */

#ifdef CONFIG_TRACE_PREEMPT_TOGGLE
-
void trace_preempt_on(unsigned long a0, unsigned long a1)
{
trace_preempt_enable_rcuidle(a0, a1);
+
+ /* preemptoff tracer */
+ tracer_preempt_on(NULL /* unused */, a0, a1);
}

void trace_preempt_off(unsigned long a0, unsigned long a1)
{
trace_preempt_disable_rcuidle(a0, a1);
+
+ /* preemptoff tracer */
+ tracer_preempt_off(NULL /* unused */, a0, a1);
}
#endif
--
2.18.0.597.ga71716f1ad-goog