2020-07-20 12:05:35

by Marco Elver

[permalink] [raw]
Subject: [PATCH tip/locking/core] kcsan: Improve IRQ state trace reporting

To improve the general usefulness of the IRQ state trace information
with KCSAN enabled, save and restore the trace information when entering
and exiting the KCSAN runtime as well as when generating a KCSAN report.

Without this, reporting the IRQ state trace (whether via a KCSAN report
or outside of KCSAN via a lockdep report) is rather useless due to
continuously being touched by KCSAN. This is because if KCSAN is
enabled, every instrumented memory access causes changes to IRQ state
tracking information (either by KCSAN disabling/enabling interrupts or
taking report_lock when generating a report).

Before "lockdep: Prepare for NMI IRQ state tracking", KCSAN avoided
touching the IRQ state trace via raw_local_irq_save/restore() and
lockdep_off/on().

Fixes: 248591f5d257 ("kcsan: Make KCSAN compatible with new IRQ state tracking")
Signed-off-by: Marco Elver <[email protected]>
---


Hi, Peter,

If this is reasonable, please take it into the branch that currently has
the series around "lockdep: Prepare for NMI IRQ state tracking"
(tip/locking/core?).

Thanks,
-- Marco


---
include/linux/sched.h | 13 +++++++++++++
kernel/kcsan/core.c | 39 +++++++++++++++++++++++++++++++++++++++
kernel/kcsan/kcsan.h | 7 +++++++
kernel/kcsan/report.c | 3 +++
4 files changed, 62 insertions(+)

diff --git a/include/linux/sched.h b/include/linux/sched.h
index 692e327d7455..ca5324b1657c 100644
--- a/include/linux/sched.h
+++ b/include/linux/sched.h
@@ -1199,6 +1199,19 @@ struct task_struct {
#endif
#ifdef CONFIG_KCSAN
struct kcsan_ctx kcsan_ctx;
+#ifdef CONFIG_TRACE_IRQFLAGS
+ struct {
+ unsigned int irq_events;
+ unsigned long hardirq_enable_ip;
+ unsigned long hardirq_disable_ip;
+ unsigned int hardirq_enable_event;
+ unsigned int hardirq_disable_event;
+ unsigned long softirq_disable_ip;
+ unsigned long softirq_enable_ip;
+ unsigned int softirq_disable_event;
+ unsigned int softirq_enable_event;
+ } kcsan_save_irqtrace;
+#endif
#endif

#ifdef CONFIG_FUNCTION_GRAPH_TRACER
diff --git a/kernel/kcsan/core.c b/kernel/kcsan/core.c
index 732623c30359..7e8347c14530 100644
--- a/kernel/kcsan/core.c
+++ b/kernel/kcsan/core.c
@@ -291,6 +291,36 @@ static inline unsigned int get_delay(void)
0);
}

+void kcsan_save_irqtrace(struct task_struct *task)
+{
+#ifdef CONFIG_TRACE_IRQFLAGS
+ task->kcsan_save_irqtrace.irq_events = task->irq_events;
+ task->kcsan_save_irqtrace.hardirq_enable_ip = task->hardirq_enable_ip;
+ task->kcsan_save_irqtrace.hardirq_disable_ip = task->hardirq_disable_ip;
+ task->kcsan_save_irqtrace.hardirq_enable_event = task->hardirq_enable_event;
+ task->kcsan_save_irqtrace.hardirq_disable_event = task->hardirq_disable_event;
+ task->kcsan_save_irqtrace.softirq_disable_ip = task->softirq_disable_ip;
+ task->kcsan_save_irqtrace.softirq_enable_ip = task->softirq_enable_ip;
+ task->kcsan_save_irqtrace.softirq_disable_event = task->softirq_disable_event;
+ task->kcsan_save_irqtrace.softirq_enable_event = task->softirq_enable_event;
+#endif
+}
+
+void kcsan_restore_irqtrace(struct task_struct *task)
+{
+#ifdef CONFIG_TRACE_IRQFLAGS
+ task->irq_events = task->kcsan_save_irqtrace.irq_events;
+ task->hardirq_enable_ip = task->kcsan_save_irqtrace.hardirq_enable_ip;
+ task->hardirq_disable_ip = task->kcsan_save_irqtrace.hardirq_disable_ip;
+ task->hardirq_enable_event = task->kcsan_save_irqtrace.hardirq_enable_event;
+ task->hardirq_disable_event = task->kcsan_save_irqtrace.hardirq_disable_event;
+ task->softirq_disable_ip = task->kcsan_save_irqtrace.softirq_disable_ip;
+ task->softirq_enable_ip = task->kcsan_save_irqtrace.softirq_enable_ip;
+ task->softirq_disable_event = task->kcsan_save_irqtrace.softirq_disable_event;
+ task->softirq_enable_event = task->kcsan_save_irqtrace.softirq_enable_event;
+#endif
+}
+
/*
* Pull everything together: check_access() below contains the performance
* critical operations; the fast-path (including check_access) functions should
@@ -336,9 +366,11 @@ static noinline void kcsan_found_watchpoint(const volatile void *ptr,
flags = user_access_save();

if (consumed) {
+ kcsan_save_irqtrace(current);
kcsan_report(ptr, size, type, KCSAN_VALUE_CHANGE_MAYBE,
KCSAN_REPORT_CONSUMED_WATCHPOINT,
watchpoint - watchpoints);
+ kcsan_restore_irqtrace(current);
} else {
/*
* The other thread may not print any diagnostics, as it has
@@ -396,6 +428,12 @@ kcsan_setup_watchpoint(const volatile void *ptr, size_t size, int type)
goto out;
}

+ /*
+ * Save and restore the IRQ state trace touched by KCSAN, since KCSAN's
+ * runtime is entered for every memory access, and potentially useful
+ * information is lost if dirtied by KCSAN.
+ */
+ kcsan_save_irqtrace(current);
if (!kcsan_interrupt_watcher)
local_irq_save(irq_flags);

@@ -539,6 +577,7 @@ kcsan_setup_watchpoint(const volatile void *ptr, size_t size, int type)
out_unlock:
if (!kcsan_interrupt_watcher)
local_irq_restore(irq_flags);
+ kcsan_restore_irqtrace(current);
out:
user_access_restore(ua_flags);
}
diff --git a/kernel/kcsan/kcsan.h b/kernel/kcsan/kcsan.h
index 763d6d08d94b..29480010dc30 100644
--- a/kernel/kcsan/kcsan.h
+++ b/kernel/kcsan/kcsan.h
@@ -9,6 +9,7 @@
#define _KERNEL_KCSAN_KCSAN_H

#include <linux/kcsan.h>
+#include <linux/sched.h>

/* The number of adjacent watchpoints to check. */
#define KCSAN_CHECK_ADJACENT 1
@@ -22,6 +23,12 @@ extern unsigned int kcsan_udelay_interrupt;
*/
extern bool kcsan_enabled;

+/*
+ * Save/restore IRQ flags state trace dirtied by KCSAN.
+ */
+void kcsan_save_irqtrace(struct task_struct *task);
+void kcsan_restore_irqtrace(struct task_struct *task);
+
/*
* Initialize debugfs file.
*/
diff --git a/kernel/kcsan/report.c b/kernel/kcsan/report.c
index 6b2fb1a6d8cd..9d07e175de0f 100644
--- a/kernel/kcsan/report.c
+++ b/kernel/kcsan/report.c
@@ -308,6 +308,9 @@ static void print_verbose_info(struct task_struct *task)
if (!task)
return;

+ /* Restore IRQ state trace for printing. */
+ kcsan_restore_irqtrace(task);
+
pr_err("\n");
debug_show_held_locks(task);
print_irqtrace_events(task);
--
2.28.0.rc0.105.gf9edc3c819-goog


2020-07-28 10:46:29

by Marco Elver

[permalink] [raw]
Subject: Re: [PATCH tip/locking/core] kcsan: Improve IRQ state trace reporting

On Mon, 20 Jul 2020 at 14:03, Marco Elver <[email protected]> wrote:
>
> To improve the general usefulness of the IRQ state trace information
> with KCSAN enabled, save and restore the trace information when entering
> and exiting the KCSAN runtime as well as when generating a KCSAN report.
>
> Without this, reporting the IRQ state trace (whether via a KCSAN report
> or outside of KCSAN via a lockdep report) is rather useless due to
> continuously being touched by KCSAN. This is because if KCSAN is
> enabled, every instrumented memory access causes changes to IRQ state
> tracking information (either by KCSAN disabling/enabling interrupts or
> taking report_lock when generating a report).
>
> Before "lockdep: Prepare for NMI IRQ state tracking", KCSAN avoided
> touching the IRQ state trace via raw_local_irq_save/restore() and
> lockdep_off/on().
>
> Fixes: 248591f5d257 ("kcsan: Make KCSAN compatible with new IRQ state tracking")
> Signed-off-by: Marco Elver <[email protected]>
> ---
>
>
> Hi, Peter,
>
> If this is reasonable, please take it into the branch that currently has
> the series around "lockdep: Prepare for NMI IRQ state tracking"
> (tip/locking/core?).

Just in case -- checking this one wasn't lost.

Many thanks,
-- Marco

> ---
> include/linux/sched.h | 13 +++++++++++++
> kernel/kcsan/core.c | 39 +++++++++++++++++++++++++++++++++++++++
> kernel/kcsan/kcsan.h | 7 +++++++
> kernel/kcsan/report.c | 3 +++
> 4 files changed, 62 insertions(+)
>
> diff --git a/include/linux/sched.h b/include/linux/sched.h
> index 692e327d7455..ca5324b1657c 100644
> --- a/include/linux/sched.h
> +++ b/include/linux/sched.h
> @@ -1199,6 +1199,19 @@ struct task_struct {
> #endif
> #ifdef CONFIG_KCSAN
> struct kcsan_ctx kcsan_ctx;
> +#ifdef CONFIG_TRACE_IRQFLAGS
> + struct {
> + unsigned int irq_events;
> + unsigned long hardirq_enable_ip;
> + unsigned long hardirq_disable_ip;
> + unsigned int hardirq_enable_event;
> + unsigned int hardirq_disable_event;
> + unsigned long softirq_disable_ip;
> + unsigned long softirq_enable_ip;
> + unsigned int softirq_disable_event;
> + unsigned int softirq_enable_event;
> + } kcsan_save_irqtrace;
> +#endif
> #endif
>
> #ifdef CONFIG_FUNCTION_GRAPH_TRACER
> diff --git a/kernel/kcsan/core.c b/kernel/kcsan/core.c
> index 732623c30359..7e8347c14530 100644
> --- a/kernel/kcsan/core.c
> +++ b/kernel/kcsan/core.c
> @@ -291,6 +291,36 @@ static inline unsigned int get_delay(void)
> 0);
> }
>
> +void kcsan_save_irqtrace(struct task_struct *task)
> +{
> +#ifdef CONFIG_TRACE_IRQFLAGS
> + task->kcsan_save_irqtrace.irq_events = task->irq_events;
> + task->kcsan_save_irqtrace.hardirq_enable_ip = task->hardirq_enable_ip;
> + task->kcsan_save_irqtrace.hardirq_disable_ip = task->hardirq_disable_ip;
> + task->kcsan_save_irqtrace.hardirq_enable_event = task->hardirq_enable_event;
> + task->kcsan_save_irqtrace.hardirq_disable_event = task->hardirq_disable_event;
> + task->kcsan_save_irqtrace.softirq_disable_ip = task->softirq_disable_ip;
> + task->kcsan_save_irqtrace.softirq_enable_ip = task->softirq_enable_ip;
> + task->kcsan_save_irqtrace.softirq_disable_event = task->softirq_disable_event;
> + task->kcsan_save_irqtrace.softirq_enable_event = task->softirq_enable_event;
> +#endif
> +}
> +
> +void kcsan_restore_irqtrace(struct task_struct *task)
> +{
> +#ifdef CONFIG_TRACE_IRQFLAGS
> + task->irq_events = task->kcsan_save_irqtrace.irq_events;
> + task->hardirq_enable_ip = task->kcsan_save_irqtrace.hardirq_enable_ip;
> + task->hardirq_disable_ip = task->kcsan_save_irqtrace.hardirq_disable_ip;
> + task->hardirq_enable_event = task->kcsan_save_irqtrace.hardirq_enable_event;
> + task->hardirq_disable_event = task->kcsan_save_irqtrace.hardirq_disable_event;
> + task->softirq_disable_ip = task->kcsan_save_irqtrace.softirq_disable_ip;
> + task->softirq_enable_ip = task->kcsan_save_irqtrace.softirq_enable_ip;
> + task->softirq_disable_event = task->kcsan_save_irqtrace.softirq_disable_event;
> + task->softirq_enable_event = task->kcsan_save_irqtrace.softirq_enable_event;
> +#endif
> +}
> +
> /*
> * Pull everything together: check_access() below contains the performance
> * critical operations; the fast-path (including check_access) functions should
> @@ -336,9 +366,11 @@ static noinline void kcsan_found_watchpoint(const volatile void *ptr,
> flags = user_access_save();
>
> if (consumed) {
> + kcsan_save_irqtrace(current);
> kcsan_report(ptr, size, type, KCSAN_VALUE_CHANGE_MAYBE,
> KCSAN_REPORT_CONSUMED_WATCHPOINT,
> watchpoint - watchpoints);
> + kcsan_restore_irqtrace(current);
> } else {
> /*
> * The other thread may not print any diagnostics, as it has
> @@ -396,6 +428,12 @@ kcsan_setup_watchpoint(const volatile void *ptr, size_t size, int type)
> goto out;
> }
>
> + /*
> + * Save and restore the IRQ state trace touched by KCSAN, since KCSAN's
> + * runtime is entered for every memory access, and potentially useful
> + * information is lost if dirtied by KCSAN.
> + */
> + kcsan_save_irqtrace(current);
> if (!kcsan_interrupt_watcher)
> local_irq_save(irq_flags);
>
> @@ -539,6 +577,7 @@ kcsan_setup_watchpoint(const volatile void *ptr, size_t size, int type)
> out_unlock:
> if (!kcsan_interrupt_watcher)
> local_irq_restore(irq_flags);
> + kcsan_restore_irqtrace(current);
> out:
> user_access_restore(ua_flags);
> }
> diff --git a/kernel/kcsan/kcsan.h b/kernel/kcsan/kcsan.h
> index 763d6d08d94b..29480010dc30 100644
> --- a/kernel/kcsan/kcsan.h
> +++ b/kernel/kcsan/kcsan.h
> @@ -9,6 +9,7 @@
> #define _KERNEL_KCSAN_KCSAN_H
>
> #include <linux/kcsan.h>
> +#include <linux/sched.h>
>
> /* The number of adjacent watchpoints to check. */
> #define KCSAN_CHECK_ADJACENT 1
> @@ -22,6 +23,12 @@ extern unsigned int kcsan_udelay_interrupt;
> */
> extern bool kcsan_enabled;
>
> +/*
> + * Save/restore IRQ flags state trace dirtied by KCSAN.
> + */
> +void kcsan_save_irqtrace(struct task_struct *task);
> +void kcsan_restore_irqtrace(struct task_struct *task);
> +
> /*
> * Initialize debugfs file.
> */
> diff --git a/kernel/kcsan/report.c b/kernel/kcsan/report.c
> index 6b2fb1a6d8cd..9d07e175de0f 100644
> --- a/kernel/kcsan/report.c
> +++ b/kernel/kcsan/report.c
> @@ -308,6 +308,9 @@ static void print_verbose_info(struct task_struct *task)
> if (!task)
> return;
>
> + /* Restore IRQ state trace for printing. */
> + kcsan_restore_irqtrace(task);
> +
> pr_err("\n");
> debug_show_held_locks(task);
> print_irqtrace_events(task);
> --
> 2.28.0.rc0.105.gf9edc3c819-goog
>

2020-07-28 11:31:58

by Ingo Molnar

[permalink] [raw]
Subject: Re: [PATCH tip/locking/core] kcsan: Improve IRQ state trace reporting


* Marco Elver <[email protected]> wrote:

> To improve the general usefulness of the IRQ state trace information
> with KCSAN enabled, save and restore the trace information when entering
> and exiting the KCSAN runtime as well as when generating a KCSAN report.
>
> Without this, reporting the IRQ state trace (whether via a KCSAN report
> or outside of KCSAN via a lockdep report) is rather useless due to
> continuously being touched by KCSAN. This is because if KCSAN is
> enabled, every instrumented memory access causes changes to IRQ state
> tracking information (either by KCSAN disabling/enabling interrupts or
> taking report_lock when generating a report).
>
> Before "lockdep: Prepare for NMI IRQ state tracking", KCSAN avoided
> touching the IRQ state trace via raw_local_irq_save/restore() and
> lockdep_off/on().
>
> Fixes: 248591f5d257 ("kcsan: Make KCSAN compatible with new IRQ state tracking")
> Signed-off-by: Marco Elver <[email protected]>
> ---
>
>
> Hi, Peter,
>
> If this is reasonable, please take it into the branch that currently has
> the series around "lockdep: Prepare for NMI IRQ state tracking"
> (tip/locking/core?).
>
> Thanks,
> -- Marco
>
>
> ---
> include/linux/sched.h | 13 +++++++++++++
> kernel/kcsan/core.c | 39 +++++++++++++++++++++++++++++++++++++++
> kernel/kcsan/kcsan.h | 7 +++++++
> kernel/kcsan/report.c | 3 +++
> 4 files changed, 62 insertions(+)
>
> diff --git a/include/linux/sched.h b/include/linux/sched.h
> index 692e327d7455..ca5324b1657c 100644
> --- a/include/linux/sched.h
> +++ b/include/linux/sched.h
> @@ -1199,6 +1199,19 @@ struct task_struct {
> #endif
> #ifdef CONFIG_KCSAN
> struct kcsan_ctx kcsan_ctx;
> +#ifdef CONFIG_TRACE_IRQFLAGS
> + struct {
> + unsigned int irq_events;
> + unsigned long hardirq_enable_ip;
> + unsigned long hardirq_disable_ip;
> + unsigned int hardirq_enable_event;
> + unsigned int hardirq_disable_event;
> + unsigned long softirq_disable_ip;
> + unsigned long softirq_enable_ip;
> + unsigned int softirq_disable_event;
> + unsigned int softirq_enable_event;
> + } kcsan_save_irqtrace;
> +#endif
> #endif
>
> #ifdef CONFIG_FUNCTION_GRAPH_TRACER
> diff --git a/kernel/kcsan/core.c b/kernel/kcsan/core.c
> index 732623c30359..7e8347c14530 100644
> --- a/kernel/kcsan/core.c
> +++ b/kernel/kcsan/core.c
> @@ -291,6 +291,36 @@ static inline unsigned int get_delay(void)
> 0);
> }
>
> +void kcsan_save_irqtrace(struct task_struct *task)
> +{
> +#ifdef CONFIG_TRACE_IRQFLAGS
> + task->kcsan_save_irqtrace.irq_events = task->irq_events;
> + task->kcsan_save_irqtrace.hardirq_enable_ip = task->hardirq_enable_ip;
> + task->kcsan_save_irqtrace.hardirq_disable_ip = task->hardirq_disable_ip;
> + task->kcsan_save_irqtrace.hardirq_enable_event = task->hardirq_enable_event;
> + task->kcsan_save_irqtrace.hardirq_disable_event = task->hardirq_disable_event;
> + task->kcsan_save_irqtrace.softirq_disable_ip = task->softirq_disable_ip;
> + task->kcsan_save_irqtrace.softirq_enable_ip = task->softirq_enable_ip;
> + task->kcsan_save_irqtrace.softirq_disable_event = task->softirq_disable_event;
> + task->kcsan_save_irqtrace.softirq_enable_event = task->softirq_enable_event;
> +#endif
> +}
> +
> +void kcsan_restore_irqtrace(struct task_struct *task)
> +{
> +#ifdef CONFIG_TRACE_IRQFLAGS
> + task->irq_events = task->kcsan_save_irqtrace.irq_events;
> + task->hardirq_enable_ip = task->kcsan_save_irqtrace.hardirq_enable_ip;
> + task->hardirq_disable_ip = task->kcsan_save_irqtrace.hardirq_disable_ip;
> + task->hardirq_enable_event = task->kcsan_save_irqtrace.hardirq_enable_event;
> + task->hardirq_disable_event = task->kcsan_save_irqtrace.hardirq_disable_event;
> + task->softirq_disable_ip = task->kcsan_save_irqtrace.softirq_disable_ip;
> + task->softirq_enable_ip = task->kcsan_save_irqtrace.softirq_enable_ip;
> + task->softirq_disable_event = task->kcsan_save_irqtrace.softirq_disable_event;
> + task->softirq_enable_event = task->kcsan_save_irqtrace.softirq_enable_event;
> +#endif

Please, make such type of assignment blocks cleaner by using a local
helper variable, and by aligning the right side vertically as well.

Also, would it make sense to unify the layout between the fields in
task struct and the new one you introduced? That would allow a simple
structure copy.

Thanks,

Ingo

2020-07-28 15:16:17

by Marco Elver

[permalink] [raw]
Subject: Re: [PATCH tip/locking/core] kcsan: Improve IRQ state trace reporting

On Tue, 28 Jul 2020 at 13:30, Ingo Molnar <[email protected]> wrote:
>
>
> * Marco Elver <[email protected]> wrote:
>
> > To improve the general usefulness of the IRQ state trace information
> > with KCSAN enabled, save and restore the trace information when entering
> > and exiting the KCSAN runtime as well as when generating a KCSAN report.
> >
> > Without this, reporting the IRQ state trace (whether via a KCSAN report
> > or outside of KCSAN via a lockdep report) is rather useless due to
> > continuously being touched by KCSAN. This is because if KCSAN is
> > enabled, every instrumented memory access causes changes to IRQ state
> > tracking information (either by KCSAN disabling/enabling interrupts or
> > taking report_lock when generating a report).
> >
> > Before "lockdep: Prepare for NMI IRQ state tracking", KCSAN avoided
> > touching the IRQ state trace via raw_local_irq_save/restore() and
> > lockdep_off/on().
> >
> > Fixes: 248591f5d257 ("kcsan: Make KCSAN compatible with new IRQ state tracking")
> > Signed-off-by: Marco Elver <[email protected]>
> > ---
[...]
> > +void kcsan_restore_irqtrace(struct task_struct *task)
> > +{
> > +#ifdef CONFIG_TRACE_IRQFLAGS
> > + task->irq_events = task->kcsan_save_irqtrace.irq_events;
> > + task->hardirq_enable_ip = task->kcsan_save_irqtrace.hardirq_enable_ip;
> > + task->hardirq_disable_ip = task->kcsan_save_irqtrace.hardirq_disable_ip;
> > + task->hardirq_enable_event = task->kcsan_save_irqtrace.hardirq_enable_event;
> > + task->hardirq_disable_event = task->kcsan_save_irqtrace.hardirq_disable_event;
> > + task->softirq_disable_ip = task->kcsan_save_irqtrace.softirq_disable_ip;
> > + task->softirq_enable_ip = task->kcsan_save_irqtrace.softirq_enable_ip;
> > + task->softirq_disable_event = task->kcsan_save_irqtrace.softirq_disable_event;
> > + task->softirq_enable_event = task->kcsan_save_irqtrace.softirq_enable_event;
> > +#endif
>
> Please, make such type of assignment blocks cleaner by using a local
> helper variable, and by aligning the right side vertically as well.
>
> Also, would it make sense to unify the layout between the fields in
> task struct and the new one you introduced? That would allow a simple
> structure copy.

Makes sense, thanks for the suggestion. I think we could introduce a
new struct 'irqtrace_events'. I currently have something that adds
this struct in <linux/irqtrace.h>. AFAIK it also adds readability
improvements on initialization and use of the fields. I'll send a v2
with 2 patches.

Thanks,
-- Marco