linux-trace-devel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH 1/3] tracing/timerlat: Notify IRQ new max latency only if stop tracing is set
@ 2022-05-10  9:45 Daniel Bristot de Oliveira
  2022-05-10  9:45 ` [PATCH 2/3] tracing/timerlat: Print stacktrace in the IRQ handler if needed Daniel Bristot de Oliveira
  2022-05-10  9:45 ` [PATCH 3/3] tracing/timerlat: Do not wakeup the thread if the trace stops at the IRQ Daniel Bristot de Oliveira
  0 siblings, 2 replies; 3+ messages in thread
From: Daniel Bristot de Oliveira @ 2022-05-10  9:45 UTC (permalink / raw)
  To: Steven Rostedt, linux-kernel, linux-trace-devel
  Cc: Daniel Bristot de Oliveira, Juri Lelli, Ingo Molnar, Clark Williams

Currently, the notification of a new max latency is sent from
timerlat's IRQ handler anytime a new max latency is found.

While this behavior is not wrong, the send IPI overhead itself
will increase the thread latency and that is not the desired
effect (tracing overhead).

Moreover, the thread will notify a new max latency again because
the thread latency as it is always higher than the IRQ latency
that woke it up.

The only case in which it is helpful to notify a new max latency
from IRQ is when stop tracing (for the IRQ) is set, as in this
case, the thread will not be dispatched.

Notify a new max latency from the IRQ handler only if stop tracing is
set for the IRQ handler.

Cc: Juri Lelli <juri.lelli@redhat.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Ingo Molnar <mingo@redhat.com>
Reported-by: Clark Williams <williams@redhat.com>
Fixes: a955d7eac177 ("trace: Add timerlat tracer")
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
---
 kernel/trace/trace_osnoise.c | 9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/trace_osnoise.c b/kernel/trace/trace_osnoise.c
index e9ae1f33a7f0..6494ca27ea6f 100644
--- a/kernel/trace/trace_osnoise.c
+++ b/kernel/trace/trace_osnoise.c
@@ -1578,11 +1578,12 @@ static enum hrtimer_restart timerlat_irq(struct hrtimer *timer)
 
 	trace_timerlat_sample(&s);
 
-	notify_new_max_latency(diff);
-
-	if (osnoise_data.stop_tracing)
-		if (time_to_us(diff) >= osnoise_data.stop_tracing)
+	if (osnoise_data.stop_tracing) {
+		if (time_to_us(diff) >= osnoise_data.stop_tracing) {
 			osnoise_stop_tracing();
+			notify_new_max_latency(diff);
+		}
+	}
 
 	wake_up_process(tlat->kthread);
 
-- 
2.32.0


^ permalink raw reply related	[flat|nested] 3+ messages in thread

* [PATCH 2/3] tracing/timerlat: Print stacktrace in the IRQ handler if needed
  2022-05-10  9:45 [PATCH 1/3] tracing/timerlat: Notify IRQ new max latency only if stop tracing is set Daniel Bristot de Oliveira
@ 2022-05-10  9:45 ` Daniel Bristot de Oliveira
  2022-05-10  9:45 ` [PATCH 3/3] tracing/timerlat: Do not wakeup the thread if the trace stops at the IRQ Daniel Bristot de Oliveira
  1 sibling, 0 replies; 3+ messages in thread
From: Daniel Bristot de Oliveira @ 2022-05-10  9:45 UTC (permalink / raw)
  To: Steven Rostedt, linux-kernel, linux-trace-devel
  Cc: Daniel Bristot de Oliveira, Juri Lelli, Ingo Molnar, Clark Williams

If print_stack and stop_tracing_us are set, and stop_tracing_us is hit
with latency higher than or equal to print_stack, print the
stack at the IRQ handler as it is useful to define the root cause for
the IRQ latency.

Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Ingo Molnar <mingo@redhat.com>
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
---
 Documentation/trace/timerlat-tracer.rst |  5 +++--
 kernel/trace/trace_osnoise.c            | 13 +++++++++++++
 2 files changed, 16 insertions(+), 2 deletions(-)

diff --git a/Documentation/trace/timerlat-tracer.rst b/Documentation/trace/timerlat-tracer.rst
index 64d1fe6e9b93..d643c95c01eb 100644
--- a/Documentation/trace/timerlat-tracer.rst
+++ b/Documentation/trace/timerlat-tracer.rst
@@ -74,8 +74,9 @@ directory. The timerlat configs are:
  - stop_tracing_total_us: stop the system tracing if a
    timer latency at the *thread* context is higher than the configured
    value happens. Writing 0 disables this option.
- - print_stack: save the stack of the IRQ occurrence, and print
-   it after the *thread context* event".
+ - print_stack: save the stack of the IRQ occurrence. The stack is printed
+   after the *thread context* event, or at the IRQ handler if *stop_tracing_us*
+   is hit.
 
 timerlat and osnoise
 ----------------------------
diff --git a/kernel/trace/trace_osnoise.c b/kernel/trace/trace_osnoise.c
index 6494ca27ea6f..9b204ee3c6f5 100644
--- a/kernel/trace/trace_osnoise.c
+++ b/kernel/trace/trace_osnoise.c
@@ -1580,6 +1580,19 @@ static enum hrtimer_restart timerlat_irq(struct hrtimer *timer)
 
 	if (osnoise_data.stop_tracing) {
 		if (time_to_us(diff) >= osnoise_data.stop_tracing) {
+
+			/*
+			 * At this point, if stop_tracing is set and <= print_stack,
+			 * print_stack is set and would be printed in the thread handler.
+			 *
+			 * Thus, print the stack trace as it is helpful to define the
+			 * root cause of an IRQ latency.
+			 */
+			if (osnoise_data.stop_tracing <= osnoise_data.print_stack) {
+				timerlat_save_stack(0);
+				timerlat_dump_stack(time_to_us(diff));
+			}
+
 			osnoise_stop_tracing();
 			notify_new_max_latency(diff);
 		}
-- 
2.32.0


^ permalink raw reply related	[flat|nested] 3+ messages in thread

* [PATCH 3/3] tracing/timerlat: Do not wakeup the thread if the trace stops at the IRQ
  2022-05-10  9:45 [PATCH 1/3] tracing/timerlat: Notify IRQ new max latency only if stop tracing is set Daniel Bristot de Oliveira
  2022-05-10  9:45 ` [PATCH 2/3] tracing/timerlat: Print stacktrace in the IRQ handler if needed Daniel Bristot de Oliveira
@ 2022-05-10  9:45 ` Daniel Bristot de Oliveira
  1 sibling, 0 replies; 3+ messages in thread
From: Daniel Bristot de Oliveira @ 2022-05-10  9:45 UTC (permalink / raw)
  To: Steven Rostedt, linux-kernel, linux-trace-devel
  Cc: Daniel Bristot de Oliveira, Juri Lelli, Ingo Molnar, Clark Williams

There is no need to wakeup the timerlat/ thread if stop tracing is hit
at the timerlat's IRQ handler.

Return before waking up timerlat's thread.

Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Ingo Molnar <mingo@redhat.com>
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
---
 kernel/trace/trace_osnoise.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/kernel/trace/trace_osnoise.c b/kernel/trace/trace_osnoise.c
index 9b204ee3c6f5..035ec8b84e12 100644
--- a/kernel/trace/trace_osnoise.c
+++ b/kernel/trace/trace_osnoise.c
@@ -1595,6 +1595,8 @@ static enum hrtimer_restart timerlat_irq(struct hrtimer *timer)
 
 			osnoise_stop_tracing();
 			notify_new_max_latency(diff);
+
+			return HRTIMER_NORESTART;
 		}
 	}
 
-- 
2.32.0


^ permalink raw reply related	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2022-05-10  9:45 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-05-10  9:45 [PATCH 1/3] tracing/timerlat: Notify IRQ new max latency only if stop tracing is set Daniel Bristot de Oliveira
2022-05-10  9:45 ` [PATCH 2/3] tracing/timerlat: Print stacktrace in the IRQ handler if needed Daniel Bristot de Oliveira
2022-05-10  9:45 ` [PATCH 3/3] tracing/timerlat: Do not wakeup the thread if the trace stops at the IRQ Daniel Bristot de Oliveira

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).