[RFC PATCH] trace: Account bottom half disabled sections.

[RFC PATCH] trace: Account bottom half disabled sections.

[Sebastian Andrzej Siewior]

Disabling only bottom halves via local_bh_disable() disables also
preemption but this remains invisible to tracing. On a CONFIG_PREEMPT
kernel one might wonder why there is no scheduling happening despite the
N flag in the trace. The reason might be a rcu_read_lock_bh() section.

Add a 'b' to the tracing output if in task context with disabled bottom
halves.

Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
---
 include/linux/trace_events.h | 1 +
 kernel/trace/trace.c         | 6 ++++--
 kernel/trace/trace_output.c  | 3 +++
 3 files changed, 8 insertions(+), 2 deletions(-)

diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h
index 2d167ac3452c5..a2af7e1156eac 100644
--- a/include/linux/trace_events.h
+++ b/include/linux/trace_events.h
@@ -172,6 +172,7 @@ enum trace_flag_type {
 	TRACE_FLAG_SOFTIRQ		= 0x10,
 	TRACE_FLAG_PREEMPT_RESCHED	= 0x20,
 	TRACE_FLAG_NMI			= 0x40,
+	TRACE_FLAG_BH_OFF		= 0x80,
 };
 
 #ifdef CONFIG_TRACE_IRQFLAGS_SUPPORT
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 88de94da596b1..dca48d556ee5a 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -2601,6 +2601,8 @@ unsigned int tracing_gen_ctx_irq_test(unsigned int irqs_status)
 		trace_flags |= TRACE_FLAG_HARDIRQ;
 	if (in_serving_softirq())
 		trace_flags |= TRACE_FLAG_SOFTIRQ;
+	if (softirq_count() >> (SOFTIRQ_SHIFT + 1))
+		trace_flags |= TRACE_FLAG_BH_OFF;
 
 	if (tif_need_resched())
 		trace_flags |= TRACE_FLAG_NEED_RESCHED;
@@ -4185,7 +4187,7 @@ static void print_lat_help_header(struct seq_file *m)
 	seq_puts(m, "#                    _------=> CPU#            \n"
 		    "#                   / _-----=> irqs-off        \n"
 		    "#                  | / _----=> need-resched    \n"
-		    "#                  || / _---=> hardirq/softirq \n"
+		    "#                  || / _---=> hardirq/softirq/BH-disables\n"
 		    "#                  ||| / _--=> preempt-depth   \n"
 		    "#                  |||| / _-=> migrate-disable \n"
 		    "#                  ||||| /     delay           \n"
@@ -4226,7 +4228,7 @@ static void print_func_help_header_irq(struct array_buffer *buf, struct seq_file
 
 	seq_printf(m, "#                            %.*s  _-----=> irqs-off\n", prec, space);
 	seq_printf(m, "#                            %.*s / _----=> need-resched\n", prec, space);
-	seq_printf(m, "#                            %.*s| / _---=> hardirq/softirq\n", prec, space);
+	seq_printf(m, "#                            %.*s| / _---=> hardirq/softirq/BH-disabled\n", prec, space);
 	seq_printf(m, "#                            %.*s|| / _--=> preempt-depth\n", prec, space);
 	seq_printf(m, "#                            %.*s||| / _-=> migrate-disable\n", prec, space);
 	seq_printf(m, "#                            %.*s|||| /     delay\n", prec, space);
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 3547e7176ff79..6be644d35ec30 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -445,11 +445,13 @@ int trace_print_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
 	char irqs_off;
 	int hardirq;
 	int softirq;
+	int bh_off;
 	int nmi;
 
 	nmi = entry->flags & TRACE_FLAG_NMI;
 	hardirq = entry->flags & TRACE_FLAG_HARDIRQ;
 	softirq = entry->flags & TRACE_FLAG_SOFTIRQ;
+	bh_off = entry->flags & TRACE_FLAG_BH_OFF;
 
 	irqs_off =
 		(entry->flags & TRACE_FLAG_IRQS_OFF) ? 'd' :
@@ -478,6 +480,7 @@ int trace_print_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
 		(hardirq && softirq) ? 'H' :
 		hardirq              ? 'h' :
 		softirq              ? 's' :
+		bh_off		     ? 'b' :
 		                       '.' ;
 
 	trace_seq_printf(s, "%c%c%c",
-- 
2.34.1

Re: [RFC PATCH] trace: Account bottom half disabled sections.

[Steven Rostedt]

On Fri, 10 Dec 2021 16:37:06 +0100
Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:

> Disabling only bottom halves via local_bh_disable() disables also
> preemption but this remains invisible to tracing. On a CONFIG_PREEMPT
> kernel one might wonder why there is no scheduling happening despite the
> N flag in the trace. The reason might be a rcu_read_lock_bh() section.
> 
> Add a 'b' to the tracing output if in task context with disabled bottom
> halves.
> 
> Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
>

Looks good to me. Care to resend without the RFC attached, and that will
make sure it gets into my scripts.

Thanks!

-- Steve

Re: [RFC PATCH] trace: Account bottom half disabled sections.

[Steven Rostedt]

On Fri, 10 Dec 2021 12:51:55 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> Looks good to me. Care to resend without the RFC attached, and that will
> make sure it gets into my scripts.

Also, please fix the subject. Precedence has, "tracing:" over "trace:", and
remove the ending period.

Thanks!

-- Steve