rpms/rtla
7
0
Fork 0
Code Issues Pull Requests Releases Activity

Update to rtla in linux-6.6.0

Browse Source 
Resolves: RHEL-10081
Signed-off-by: John Kacur <jkacur@redhat.com>
This commit is contained in:
John Kacur 2023-12-18 15:47:40 -05:00
parent 98ad82c784
commit 56f401026c
15 changed files with 44 additions and 2709 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
.gitignore vendored
View File

@ -1,2 +1,3 @@
SOURCES/rtla-5.14.0.tar.bz2 SOURCES/rtla-5.14.0.tar.bz2
/rtla-5.14.0.tar.bz2 /rtla-5.14.0.tar.bz2
/rtla-6.6.0.tar.bz2

151
Documentation-rtla-Add-hwnoise-man-page.patch
View File

@ -1,151 +0,0 @@
From 5dc3750e747f93f9bb7987da3d47a8ab4a5a181e Mon Sep 17 00:00:00 2001
From: Daniel Bristot de Oliveira <bristot@kernel.org>
Date: Tue, 7 Feb 2023 22:48:51 +0100
Subject: [PATCH] Documentation/rtla: Add hwnoise man page
Add a man page for the new rtla hwnoise tool, mostly based in the
rtla osnoise top.
Link: https://lkml.kernel.org/r/27088e0f42a6129e9b75f789d78adff4171f2e79.1675805361.git.bristot@kernel.org
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Reviewed-by: Bagas Sanjaya <bagasdotme@gmail.com>
Cc: Daniel Bristot de Oliveira <bristot@kernel.org>
Cc: Juri Lelli <juri.lelli@redhat.com>
Cc: Clark Williams <williams@redhat.com>
Cc: Jonathan Corbet <corbet@lwn.net>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
index.rst | 1 +
rtla-hwnoise.rst | 107 +++++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 108 insertions(+)
create mode 100644 Documentation/tools/rtla/rtla-hwnoise.rst
diff --git a/Documentation/index.rst b/Documentation/index.rst
index 840f0bf3e803..05d2652e4072 100644
--- a/Documentation/index.rst
+++ b/Documentation/index.rst
@@ -17,6 +17,7 @@ behavior on specific hardware.
rtla-timerlat
rtla-timerlat-hist
rtla-timerlat-top
+ rtla-hwnoise
.. only:: subproject and html
diff --git a/Documentation/rtla-hwnoise.rst b/Documentation/rtla-hwnoise.rst
new file mode 100644
index 000000000000..fb1c52bbc00b
--- /dev/null
+++ b/Documentation/rtla-hwnoise.rst
@@ -0,0 +1,107 @@
+.. SPDX-License-Identifier: GPL-2.0
+
+============
+rtla-hwnoise
+============
+------------------------------------------
+Detect and quantify hardware-related noise
+------------------------------------------
+
+:Manual section: 1
+
+SYNOPSIS
+========
+
+**rtla hwnoise** [*OPTIONS*]
+
+DESCRIPTION
+===========
+
+**rtla hwnoise** collects the periodic summary from the *osnoise* tracer
+running with *interrupts disabled*. By disabling interrupts, and the scheduling
+of threads as a consequence, only non-maskable interrupts and hardware-related
+noise is allowed.
+
+The tool also allows the configurations of the *osnoise* tracer and the
+collection of the tracer output.
+
+OPTIONS
+=======
+.. include:: common_osnoise_options.rst
+
+.. include:: common_top_options.rst
+
+.. include:: common_options.rst
+
+EXAMPLE
+=======
+In the example below, the **rtla hwnoise** tool is set to run on CPUs *1-7*
+on a system with 8 cores/16 threads with hyper-threading enabled.
+
+The tool is set to detect any noise higher than *one microsecond*,
+to run for *ten minutes*, displaying a summary of the report at the
+end of the session::
+
+ # rtla hwnoise -c 1-7 -T 1 -d 10m -q
+ Hardware-related Noise
+ duration: 0 00:10:00 | time is in us
+ CPU Period Runtime Noise % CPU Aval Max Noise Max Single HW NMI
+ 1 #599 599000000 138 99.99997 3 3 4 74
+ 2 #599 599000000 85 99.99998 3 3 4 75
+ 3 #599 599000000 86 99.99998 4 3 6 75
+ 4 #599 599000000 81 99.99998 4 4 2 75
+ 5 #599 599000000 85 99.99998 2 2 2 75
+ 6 #599 599000000 76 99.99998 2 2 0 75
+ 7 #599 599000000 77 99.99998 3 3 0 75
+
+
+The first column shows the *CPU*, and the second column shows how many
+*Periods* the tool ran during the session. The *Runtime* is the time
+the tool effectively runs on the CPU. The *Noise* column is the sum of
+all noise that the tool observed, and the *% CPU Aval* is the relation
+between the *Runtime* and *Noise*.
+
+The *Max Noise* column is the maximum hardware noise the tool detected in a
+single period, and the *Max Single* is the maximum single noise seen.
+
+The *HW* and *NMI* columns show the total number of *hardware* and *NMI* noise
+occurrence observed by the tool.
+
+For example, *CPU 3* ran *599* periods of *1 second Runtime*. The CPU received
+*86 us* of noise during the entire execution, leaving *99.99997 %* of CPU time
+for the application. In the worst single period, the CPU caused *4 us* of
+noise to the application, but it was certainly caused by more than one single
+noise, as the *Max Single* noise was of *3 us*. The CPU has *HW noise,* at a
+rate of *six occurrences*/*ten minutes*. The CPU also has *NMIs*, at a higher
+frequency: around *seven per second*.
+
+The tool should report *0* hardware-related noise in the ideal situation.
+For example, by disabling hyper-threading to remove the hardware noise,
+and disabling the TSC watchdog to remove the NMI (it is possible to identify
+this using tracing options of **rtla hwnoise**), it was possible to reach
+the ideal situation in the same hardware::
+
+ # rtla hwnoise -c 1-7 -T 1 -d 10m -q
+ Hardware-related Noise
+ duration: 0 00:10:00 | time is in us
+ CPU Period Runtime Noise % CPU Aval Max Noise Max Single HW NMI
+ 1 #599 599000000 0 100.00000 0 0 0 0
+ 2 #599 599000000 0 100.00000 0 0 0 0
+ 3 #599 599000000 0 100.00000 0 0 0 0
+ 4 #599 599000000 0 100.00000 0 0 0 0
+ 5 #599 599000000 0 100.00000 0 0 0 0
+ 6 #599 599000000 0 100.00000 0 0 0 0
+ 7 #599 599000000 0 100.00000 0 0 0 0
+
+SEE ALSO
+========
+
+**rtla-osnoise**\(1)
+
+Osnoise tracer documentation: <https://www.kernel.org/doc/html/latest/trace/osnoise-tracer.html>
+
+AUTHOR
+======
+Written by Daniel Bristot de Oliveira <bristot@kernel.org>
+
+.. include:: common_appendix.rst
--
2.40.1

216
Documentation-rtla-Add-timerlat-top-auto-analysis-op.patch
View File

@ -1,216 +0,0 @@
From ce6cc6f70cad4d703ddfe99d74f33990617c0a3c Mon Sep 17 00:00:00 2001
From: Daniel Bristot de Oliveira <bristot@kernel.org>
Date: Tue, 31 Jan 2023 16:38:55 +0100
Subject: [PATCH] Documentation/rtla: Add timerlat-top auto-analysis options
Add the new options to the man page, as well as updating the
example to include the new output.
Link: https://lkml.kernel.org/r/a3f5fb49432a55c3323b18725fc6e702f16ccc79.1675179318.git.bristot@kernel.org
Cc: Daniel Bristot de Oliveira <bristot@kernel.org>
Cc: Jonathan Corbet <corbet@lwn.net>
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
common_timerlat_aa.rst | 7 ++
rtla-timerlat-top.rst | 164 ++++++++++++++++++-----------------------
2 files changed, 80 insertions(+), 91 deletions(-)
create mode 100644 Documentation/tools/rtla/common_timerlat_aa.rst
diff --git a/Documentation/common_timerlat_aa.rst b/Documentation/common_timerlat_aa.rst
new file mode 100644
index 000000000000..077029e6b289
--- /dev/null
+++ b/Documentation/common_timerlat_aa.rst
@@ -0,0 +1,7 @@
+**--dump-tasks**
+
+ prints the task running on all CPUs if stop conditions are met (depends on !--no-aa)
+
+**--no-aa**
+
+ disable auto-analysis, reducing rtla timerlat cpu usage
diff --git a/Documentation/rtla-timerlat-top.rst b/Documentation/rtla-timerlat-top.rst
index 7c4e4b109493..73799c1150ad 100644
--- a/Documentation/rtla-timerlat-top.rst
+++ b/Documentation/rtla-timerlat-top.rst
@@ -30,102 +30,84 @@ OPTIONS
.. include:: common_options.rst
+.. include:: common_timerlat_aa.rst
+
EXAMPLE
=======
-In the example below, the *timerlat* tracer is set to capture the stack trace at
-the IRQ handler, printing it to the buffer if the *Thread* timer latency is
-higher than *30 us*. It is also set to stop the session if a *Thread* timer
-latency higher than *30 us* is hit. Finally, it is set to save the trace
-buffer if the stop condition is hit::
+In the example below, the timerlat tracer is dispatched in cpus *1-23* in the
+automatic trace mode, instructing the tracer to stop if a *40 us* latency or
+higher is found::
- [root@alien ~]# rtla timerlat top -s 30 -T 30 -t
- Timer Latency
- 0 00:00:59 | IRQ Timer Latency (us) | Thread Timer Latency (us)
+ # timerlat -a 40 -c 1-23 -q
+ Timer Latency
+ 0 00:00:12 | IRQ Timer Latency (us) | Thread Timer Latency (us)
CPU COUNT | cur min avg max | cur min avg max
- 0 #58634 | 1 0 1 10 | 11 2 10 23
- 1 #58634 | 1 0 1 9 | 12 2 9 23
- 2 #58634 | 0 0 1 11 | 10 2 9 23
- 3 #58634 | 1 0 1 11 | 11 2 9 24
- 4 #58634 | 1 0 1 10 | 11 2 9 26
- 5 #58634 | 1 0 1 8 | 10 2 9 25
- 6 #58634 | 12 0 1 12 | 30 2 10 30 <--- CPU with spike
- 7 #58634 | 1 0 1 9 | 11 2 9 23
- 8 #58633 | 1 0 1 9 | 11 2 9 26
- 9 #58633 | 1 0 1 9 | 10 2 9 26
- 10 #58633 | 1 0 1 13 | 11 2 9 28
- 11 #58633 | 1 0 1 13 | 12 2 9 24
- 12 #58633 | 1 0 1 8 | 10 2 9 23
- 13 #58633 | 1 0 1 10 | 10 2 9 22
- 14 #58633 | 1 0 1 18 | 12 2 9 27
- 15 #58633 | 1 0 1 10 | 11 2 9 28
- 16 #58633 | 0 0 1 11 | 7 2 9 26
- 17 #58633 | 1 0 1 13 | 10 2 9 24
- 18 #58633 | 1 0 1 9 | 13 2 9 22
- 19 #58633 | 1 0 1 10 | 11 2 9 23
- 20 #58633 | 1 0 1 12 | 11 2 9 28
- 21 #58633 | 1 0 1 14 | 11 2 9 24
- 22 #58633 | 1 0 1 8 | 11 2 9 22
- 23 #58633 | 1 0 1 10 | 11 2 9 27
- timerlat hit stop tracing
- saving trace to timerlat_trace.txt
- [root@alien bristot]# tail -60 timerlat_trace.txt
- [...]
- timerlat/5-79755 [005] ....... 426.271226: #58634 context thread timer_latency 10823 ns
- sh-109404 [006] dnLh213 426.271247: #58634 context irq timer_latency 12505 ns
- sh-109404 [006] dNLh313 426.271258: irq_noise: local_timer:236 start 426.271245463 duration 12553 ns
- sh-109404 [006] d...313 426.271263: thread_noise: sh:109404 start 426.271245853 duration 4769 ns
- timerlat/6-79756 [006] ....... 426.271264: #58634 context thread timer_latency 30328 ns
- timerlat/6-79756 [006] ....1.. 426.271265: <stack trace>
- => timerlat_irq
- => __hrtimer_run_queues
- => hrtimer_interrupt
- => __sysvec_apic_timer_interrupt
- => sysvec_apic_timer_interrupt
- => asm_sysvec_apic_timer_interrupt
- => _raw_spin_unlock_irqrestore <---- spinlock that disabled interrupt.
- => try_to_wake_up
- => autoremove_wake_function
- => __wake_up_common
- => __wake_up_common_lock
- => ep_poll_callback
- => __wake_up_common
- => __wake_up_common_lock
- => fsnotify_add_event
- => inotify_handle_inode_event
- => fsnotify
- => __fsnotify_parent
- => __fput
- => task_work_run
- => exit_to_user_mode_prepare
- => syscall_exit_to_user_mode
- => do_syscall_64
- => entry_SYSCALL_64_after_hwframe
- => 0x7265000001378c
- => 0x10000cea7
- => 0x25a00000204a
- => 0x12e302d00000000
- => 0x19b51010901b6
- => 0x283ce00726500
- => 0x61ea308872
- => 0x00000fe3
- bash-109109 [007] d..h... 426.271265: #58634 context irq timer_latency 1211 ns
- timerlat/6-79756 [006] ....... 426.271267: timerlat_main: stop tracing hit on cpu 6
-
-In the trace, it is possible the notice that the *IRQ* timer latency was
-already high, accounting *12505 ns*. The IRQ delay was caused by the
-*bash-109109* process that disabled IRQs in the wake-up path
-(*_try_to_wake_up()* function). The duration of the IRQ handler that woke
-up the timerlat thread, informed with the **osnoise:irq_noise** event, was
-also high and added more *12553 ns* to the Thread latency. Finally, the
-**osnoise:thread_noise** added by the currently running thread (including
-the scheduling overhead) added more *4769 ns*. Summing up these values,
-the *Thread* timer latency accounted for *30328 ns*.
-
-The primary reason for this high value is the wake-up path that was hit
-twice during this case: when the *bash-109109* was waking up a thread
-and then when the *timerlat* thread was awakened. This information can
-then be used as the starting point of a more fine-grained analysis.
+ 1 #12322 | 0 0 1 15 | 10 3 9 31
+ 2 #12322 | 3 0 1 12 | 10 3 9 23
+ 3 #12322 | 1 0 1 21 | 8 2 8 34
+ 4 #12322 | 1 0 1 17 | 10 2 11 33
+ 5 #12322 | 0 0 1 12 | 8 3 8 25
+ 6 #12322 | 1 0 1 14 | 16 3 11 35
+ 7 #12322 | 0 0 1 14 | 9 2 8 29
+ 8 #12322 | 1 0 1 22 | 9 3 9 34
+ 9 #12322 | 0 0 1 14 | 8 2 8 24
+ 10 #12322 | 1 0 0 12 | 9 3 8 24
+ 11 #12322 | 0 0 0 15 | 6 2 7 29
+ 12 #12321 | 1 0 0 13 | 5 3 8 23
+ 13 #12319 | 0 0 1 14 | 9 3 9 26
+ 14 #12321 | 1 0 0 13 | 6 2 8 24
+ 15 #12321 | 1 0 1 15 | 12 3 11 27
+ 16 #12318 | 0 0 1 13 | 7 3 10 24
+ 17 #12319 | 0 0 1 13 | 11 3 9 25
+ 18 #12318 | 0 0 0 12 | 8 2 8 20
+ 19 #12319 | 0 0 1 18 | 10 2 9 28
+ 20 #12317 | 0 0 0 20 | 9 3 8 34
+ 21 #12318 | 0 0 0 13 | 8 3 8 28
+ 22 #12319 | 0 0 1 11 | 8 3 10 22
+ 23 #12320 | 28 0 1 28 | 41 3 11 41
+ rtla timerlat hit stop tracing
+ ## CPU 23 hit stop tracing, analyzing it ##
+ IRQ handler delay: 27.49 us (65.52 %)
+ IRQ latency: 28.13 us
+ Timerlat IRQ duration: 9.59 us (22.85 %)
+ Blocking thread: 3.79 us (9.03 %)
+ objtool:49256 3.79 us
+ Blocking thread stacktrace
+ -> timerlat_irq
+ -> __hrtimer_run_queues
+ -> hrtimer_interrupt
+ -> __sysvec_apic_timer_interrupt
+ -> sysvec_apic_timer_interrupt
+ -> asm_sysvec_apic_timer_interrupt
+ -> _raw_spin_unlock_irqrestore
+ -> cgroup_rstat_flush_locked
+ -> cgroup_rstat_flush_irqsafe
+ -> mem_cgroup_flush_stats
+ -> mem_cgroup_wb_stats
+ -> balance_dirty_pages
+ -> balance_dirty_pages_ratelimited_flags
+ -> btrfs_buffered_write
+ -> btrfs_do_write_iter
+ -> vfs_write
+ -> __x64_sys_pwrite64
+ -> do_syscall_64
+ -> entry_SYSCALL_64_after_hwframe
+ ------------------------------------------------------------------------
+ Thread latency: 41.96 us (100%)
+
+ The system has exit from idle latency!
+ Max timerlat IRQ latency from idle: 17.48 us in cpu 4
+ Saving trace to timerlat_trace.txt
+
+In this case, the major factor was the delay suffered by the *IRQ handler*
+that handles **timerlat** wakeup: *65.52%*. This can be caused by the
+current thread masking interrupts, which can be seen in the blocking
+thread stacktrace: the current thread (*objtool:49256*) disabled interrupts
+via *raw spin lock* operations inside mem cgroup, while doing write
+syscall in a btrfs file system.
+
+The raw trace is saved in the **timerlat_trace.txt** file for further analysis.
Note that **rtla timerlat** was dispatched without changing *timerlat* tracer
threads' priority. That is generally not needed because these threads hava
--
2.40.1

37
Documentation-rtla-Correct-command-line-example.patch
View File

@ -1,37 +0,0 @@
From 877d95dcfd0a56102d4b97a9691115f5fb5e9ea3 Mon Sep 17 00:00:00 2001
From: Pierre Gondois <pierre.gondois@arm.com>
Date: Thu, 6 Oct 2022 10:44:09 +0200
Subject: [PATCH] Documentation: rtla: Correct command line example
The '-t/-T' parameters seem to have been swapped:
-t/--trace[=file]: save the stopped trace
to [file|timerlat_trace.txt]
-T/--thread us: stop trace if the thread latency
is higher than the argument in us
Swap them back.
Signed-off-by: Pierre Gondois <pierre.gondois@arm.com>
Acked-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Link: https://lore.kernel.org/r/20221006084409.3882542-1-pierre.gondois@arm.com
Signed-off-by: Jonathan Corbet <corbet@lwn.net>
---
Documentation/tools/rtla/rtla-timerlat-top.rst | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/Documentation/tools/rtla/rtla-timerlat-top.rst b/Documentation/tools/rtla/rtla-timerlat-top.rst
index 1c321de1c171..7c4e4b109493 100644
--- a/Documentation/rtla-timerlat-top.rst
+++ b/Documentation/rtla-timerlat-top.rst
@@ -39,7 +39,7 @@ higher than *30 us*. It is also set to stop the session if a *Thread* timer
latency higher than *30 us* is hit. Finally, it is set to save the trace
buffer if the stop condition is hit::
- [root@alien ~]# rtla timerlat top -s 30 -t 30 -T
+ [root@alien ~]# rtla timerlat top -s 30 -T 30 -t
Timer Latency
0 00:00:59 | IRQ Timer Latency (us) | Thread Timer Latency (us)
CPU COUNT | cur min avg max | cur min avg max
--
2.40.0

477
rtla-Add-hwnoise-tool.patch
View File

@ -1,477 +0,0 @@
From 1f428356c38dcbe49fd2f1c488b41e88720ead92 Mon Sep 17 00:00:00 2001
From: Daniel Bristot de Oliveira <bristot@kernel.org>
Date: Tue, 7 Feb 2023 22:48:50 +0100
Subject: [PATCH 5/8] rtla: Add hwnoise tool
The hwnoise tool is a special mode for the osnoise top tool.
hwnoise dispatches the osnoise tracer and displays a summary of the noise.
The difference is that it runs the tracer with the OSNOISE_IRQ_DISABLE
option set, thus only allowing only hardware-related noise, resulting in
a simplified output. hwnoise has the same features of osnoise.
An example of the tool's output:
# rtla hwnoise -c 1-11 -T 1 -d 10m -q
Hardware-related Noise
duration: 0 00:10:00 | time is in us
CPU Period Runtime Noise % CPU Aval Max Noise Max Single HW NMI
1 #599 599000000 138 99.99997 3 3 4 74
2 #599 599000000 85 99.99998 3 3 4 75
3 #599 599000000 86 99.99998 4 3 6 75
4 #599 599000000 81 99.99998 4 4 2 75
5 #599 599000000 85 99.99998 2 2 2 75
Link: https://lkml.kernel.org/r/2d6f49a6f3a4f8b51b2c806458b1cff71ad4d014.1675805361.git.bristot@kernel.org
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Cc: Daniel Bristot de Oliveira <bristot@kernel.org>
Cc: Juri Lelli <juri.lelli@redhat.com>
Cc: Clark Williams <williams@redhat.com>
Cc: Bagas Sanjaya <bagasdotme@gmail.com>
Cc: Jonathan Corbet <corbet@lwn.net>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
Makefile | 2 +
src/osnoise.c | 117 ++++++++++++++++++++++++++++++++++++++++++++++
src/osnoise.h | 7 +++
src/osnoise_top.c | 84 ++++++++++++++++++++++++++-------
src/rtla.c | 4 ++
5 files changed, 198 insertions(+), 16 deletions(-)
diff --git a/Makefile b/Makefile
index 22e28b76f800..2456a399eb9a 100644
--- a/Makefile
+++ b/Makefile
@@ -119,6 +119,8 @@ install: doc_install
$(STRIP) $(DESTDIR)$(BINDIR)/rtla
@test ! -f $(DESTDIR)$(BINDIR)/osnoise || rm $(DESTDIR)$(BINDIR)/osnoise
ln -s rtla $(DESTDIR)$(BINDIR)/osnoise
+ @test ! -f $(DESTDIR)$(BINDIR)/hwnoise || rm $(DESTDIR)$(BINDIR)/hwnoise
+ ln -s rtla $(DESTDIR)$(BINDIR)/hwnoise
@test ! -f $(DESTDIR)$(BINDIR)/timerlat || rm $(DESTDIR)$(BINDIR)/timerlat
ln -s rtla $(DESTDIR)$(BINDIR)/timerlat
diff --git a/src/osnoise.c b/src/osnoise.c
index 4dee343909b1..3ca7a3853943 100644
--- a/src/osnoise.c
+++ b/src/osnoise.c
@@ -734,6 +734,113 @@ void osnoise_put_tracing_thresh(struct osnoise_context *context)
context->orig_tracing_thresh = OSNOISE_OPTION_INIT_VAL;
}
+static int osnoise_options_get_option(char *option)
+{
+ char *options = tracefs_instance_file_read(NULL, "osnoise/options", NULL);
+ char no_option[128];
+ int retval = 0;
+ char *opt;
+
+ if (!options)
+ return OSNOISE_OPTION_INIT_VAL;
+
+ /*
+ * Check first if the option is disabled.
+ */
+ snprintf(no_option, sizeof(no_option), "NO_%s", option);
+
+ opt = strstr(options, no_option);
+ if (opt)
+ goto out_free;
+
+ /*
+ * Now that it is not disabled, if the string is there, it is
+ * enabled. If the string is not there, the option does not exist.
+ */
+ opt = strstr(options, option);
+ if (opt)
+ retval = 1;
+ else
+ retval = OSNOISE_OPTION_INIT_VAL;
+
+out_free:
+ free(options);
+ return retval;
+}
+
+static int osnoise_options_set_option(char *option, bool onoff)
+{
+ char no_option[128];
+
+ if (onoff)
+ return tracefs_instance_file_write(NULL, "osnoise/options", option);
+
+ snprintf(no_option, sizeof(no_option), "NO_%s", option);
+
+ return tracefs_instance_file_write(NULL, "osnoise/options", no_option);
+}
+
+static int osnoise_get_irq_disable(struct osnoise_context *context)
+{
+ if (context->opt_irq_disable != OSNOISE_OPTION_INIT_VAL)
+ return context->opt_irq_disable;
+
+ if (context->orig_opt_irq_disable != OSNOISE_OPTION_INIT_VAL)
+ return context->orig_opt_irq_disable;
+
+ context->orig_opt_irq_disable = osnoise_options_get_option("OSNOISE_IRQ_DISABLE");
+
+ return context->orig_opt_irq_disable;
+}
+
+int osnoise_set_irq_disable(struct osnoise_context *context, bool onoff)
+{
+ int opt_irq_disable = osnoise_get_irq_disable(context);
+ int retval;
+
+ if (opt_irq_disable == OSNOISE_OPTION_INIT_VAL)
+ return -1;
+
+ if (opt_irq_disable == onoff)
+ return 0;
+
+ retval = osnoise_options_set_option("OSNOISE_IRQ_DISABLE", onoff);
+ if (retval < 0)
+ return -1;
+
+ context->opt_irq_disable = onoff;
+
+ return 0;
+}
+
+static void osnoise_restore_irq_disable(struct osnoise_context *context)
+{
+ int retval;
+
+ if (context->orig_opt_irq_disable == OSNOISE_OPTION_INIT_VAL)
+ return;
+
+ if (context->orig_opt_irq_disable == context->opt_irq_disable)
+ goto out_done;
+
+ retval = osnoise_options_set_option("OSNOISE_IRQ_DISABLE", context->orig_opt_irq_disable);
+ if (retval < 0)
+ err_msg("Could not restore original OSNOISE_IRQ_DISABLE option\n");
+
+out_done:
+ context->orig_opt_irq_disable = OSNOISE_OPTION_INIT_VAL;
+}
+
+static void osnoise_put_irq_disable(struct osnoise_context *context)
+{
+ osnoise_restore_irq_disable(context);
+
+ if (context->orig_opt_irq_disable == OSNOISE_OPTION_INIT_VAL)
+ return;
+
+ context->orig_opt_irq_disable = OSNOISE_OPTION_INIT_VAL;
+}
+
/*
* enable_osnoise - enable osnoise tracer in the trace_instance
*/
@@ -798,6 +905,9 @@ struct osnoise_context *osnoise_context_alloc(void)
context->orig_tracing_thresh = OSNOISE_OPTION_INIT_VAL;
context->tracing_thresh = OSNOISE_OPTION_INIT_VAL;
+ context->orig_opt_irq_disable = OSNOISE_OPTION_INIT_VAL;
+ context->opt_irq_disable = OSNOISE_OPTION_INIT_VAL;
+
osnoise_get_context(context);
return context;
@@ -824,6 +934,7 @@ void osnoise_put_context(struct osnoise_context *context)
osnoise_put_timerlat_period_us(context);
osnoise_put_print_stack(context);
osnoise_put_tracing_thresh(context);
+ osnoise_put_irq_disable(context);
free(context);
}
@@ -958,3 +1069,9 @@ int osnoise_main(int argc, char *argv[])
osnoise_usage(1);
exit(1);
}
+
+int hwnoise_main(int argc, char *argv[])
+{
+ osnoise_top_main(argc, argv);
+ exit(0);
+}
diff --git a/src/osnoise.h b/src/osnoise.h
index 04a4384cc544..4dcf22ccd704 100644
--- a/src/osnoise.h
+++ b/src/osnoise.h
@@ -38,6 +38,10 @@ struct osnoise_context {
/* -1 as init value because 0 is disabled */
long long orig_print_stack;
long long print_stack;
+
+ /* -1 as init value because 0 is off */
+ int orig_opt_irq_disable;
+ int opt_irq_disable;
};
/*
@@ -79,6 +83,8 @@ void osnoise_restore_print_stack(struct osnoise_context *context);
int osnoise_set_print_stack(struct osnoise_context *context,
long long print_stack);
+int osnoise_set_irq_disable(struct osnoise_context *context, bool onoff);
+
/*
* osnoise_tool - osnoise based tool definition.
*/
@@ -97,3 +103,4 @@ struct osnoise_tool *osnoise_init_trace_tool(char *tracer);
int osnoise_hist_main(int argc, char *argv[]);
int osnoise_top_main(int argc, char **argv);
int osnoise_main(int argc, char **argv);
+int hwnoise_main(int argc, char **argv);
diff --git a/src/osnoise_top.c b/src/osnoise_top.c
index 76479bfb2922..562f2e4b18c5 100644
--- a/src/osnoise_top.c
+++ b/src/osnoise_top.c
@@ -14,6 +14,11 @@
#include "osnoise.h"
#include "utils.h"
+enum osnoise_mode {
+ MODE_OSNOISE = 0,
+ MODE_HWNOISE
+};
+
/*
* osnoise top parameters
*/
@@ -32,6 +37,7 @@ struct osnoise_top_params {
int set_sched;
struct sched_attr sched_param;
struct trace_events *events;
+ enum osnoise_mode mode;
};
struct osnoise_top_cpu {
@@ -143,15 +149,23 @@ osnoise_top_handler(struct trace_seq *s, struct tep_record *record,
*/
static void osnoise_top_header(struct osnoise_tool *top)
{
+ struct osnoise_top_params *params = top->params;
struct trace_seq *s = top->trace.seq;
char duration[26];
get_duration(top->start_time, duration, sizeof(duration));
trace_seq_printf(s, "\033[2;37;40m");
- trace_seq_printf(s, " Operating System Noise");
- trace_seq_printf(s, " ");
- trace_seq_printf(s, " ");
+ trace_seq_printf(s, " ");
+
+ if (params->mode == MODE_OSNOISE) {
+ trace_seq_printf(s, "Operating System Noise");
+ trace_seq_printf(s, " ");
+ } else if (params->mode == MODE_HWNOISE) {
+ trace_seq_printf(s, "Hardware-related Noise");
+ }
+
+ trace_seq_printf(s, " ");
trace_seq_printf(s, "\033[0;0;0m");
trace_seq_printf(s, "\n");
@@ -162,7 +176,14 @@ static void osnoise_top_header(struct osnoise_tool *top)
trace_seq_printf(s, " Noise ");
trace_seq_printf(s, " %% CPU Aval ");
trace_seq_printf(s, " Max Noise Max Single ");
- trace_seq_printf(s, " HW NMI IRQ Softirq Thread");
+ trace_seq_printf(s, " HW NMI");
+
+ if (params->mode == MODE_HWNOISE)
+ goto eol;
+
+ trace_seq_printf(s, " IRQ Softirq Thread");
+
+eol:
trace_seq_printf(s, "\033[0;0;0m");
trace_seq_printf(s, "\n");
}
@@ -181,6 +202,7 @@ static void clear_terminal(struct trace_seq *seq)
*/
static void osnoise_top_print(struct osnoise_tool *tool, int cpu)
{
+ struct osnoise_top_params *params = tool->params;
struct trace_seq *s = tool->trace.seq;
struct osnoise_top_cpu *cpu_data;
struct osnoise_top_data *data;
@@ -205,6 +227,12 @@ static void osnoise_top_print(struct osnoise_tool *tool, int cpu)
trace_seq_printf(s, "%12llu ", cpu_data->hw_count);
trace_seq_printf(s, "%12llu ", cpu_data->nmi_count);
+
+ if (params->mode == MODE_HWNOISE) {
+ trace_seq_printf(s, "\n");
+ return;
+ }
+
trace_seq_printf(s, "%12llu ", cpu_data->irq_count);
trace_seq_printf(s, "%12llu ", cpu_data->softirq_count);
trace_seq_printf(s, "%12llu\n", cpu_data->thread_count);
@@ -241,12 +269,12 @@ osnoise_print_stats(struct osnoise_top_params *params, struct osnoise_tool *top)
/*
* osnoise_top_usage - prints osnoise top usage message
*/
-void osnoise_top_usage(char *usage)
+static void osnoise_top_usage(struct osnoise_top_params *params, char *usage)
{
int i;
static const char * const msg[] = {
- " usage: rtla osnoise [top] [-h] [-q] [-D] [-d s] [-a us] [-p us] [-r us] [-s us] [-S us] \\",
+ " [-h] [-q] [-D] [-d s] [-a us] [-p us] [-r us] [-s us] [-S us] \\",
" [-T us] [-t[=file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] \\",
" [-c cpu-list] [-P priority]",
"",
@@ -277,9 +305,22 @@ void osnoise_top_usage(char *usage)
if (usage)
fprintf(stderr, "%s\n", usage);
- fprintf(stderr, "rtla osnoise top: a per-cpu summary of the OS noise (version %s)\n",
+ if (params->mode == MODE_OSNOISE) {
+ fprintf(stderr,
+ "rtla osnoise top: a per-cpu summary of the OS noise (version %s)\n",
VERSION);
+ fprintf(stderr, " usage: rtla osnoise [top]");
+ }
+
+ if (params->mode == MODE_HWNOISE) {
+ fprintf(stderr,
+ "rtla hwnoise: a summary of hardware-related noise (version %s)\n",
+ VERSION);
+
+ fprintf(stderr, " usage: rtla hwnoise");
+ }
+
for (i = 0; msg[i]; i++)
fprintf(stderr, "%s\n", msg[i]);
exit(1);
@@ -299,6 +340,9 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
if (!params)
exit(1);
+ if (strcmp(argv[0], "hwnoise") == 0)
+ params->mode = MODE_HWNOISE;
+
while (1) {
static struct option long_options[] = {
{"auto", required_argument, 0, 'a'},
@@ -345,7 +389,7 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
case 'c':
retval = parse_cpu_list(optarg, &params->monitored_cpus);
if (retval)
- osnoise_top_usage("\nInvalid -c cpu list\n");
+ osnoise_top_usage(params, "\nInvalid -c cpu list\n");
params->cpus = optarg;
break;
case 'D':
@@ -354,7 +398,7 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
case 'd':
params->duration = parse_seconds_duration(optarg);
if (!params->duration)
- osnoise_top_usage("Invalid -D duration\n");
+ osnoise_top_usage(params, "Invalid -D duration\n");
break;
case 'e':
tevent = trace_event_alloc(optarg);
@@ -370,17 +414,17 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
break;
case 'h':
case '?':
- osnoise_top_usage(NULL);
+ osnoise_top_usage(params, NULL);
break;
case 'p':
params->period = get_llong_from_str(optarg);
if (params->period > 10000000)
- osnoise_top_usage("Period longer than 10 s\n");
+ osnoise_top_usage(params, "Period longer than 10 s\n");
break;
case 'P':
retval = parse_prio(optarg, &params->sched_param);
if (retval == -1)
- osnoise_top_usage("Invalid -P priority");
+ osnoise_top_usage(params, "Invalid -P priority");
params->set_sched = 1;
break;
case 'q':
@@ -389,7 +433,7 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
case 'r':
params->runtime = get_llong_from_str(optarg);
if (params->runtime < 100)
- osnoise_top_usage("Runtime shorter than 100 us\n");
+ osnoise_top_usage(params, "Runtime shorter than 100 us\n");
break;
case 's':
params->stop_us = get_llong_from_str(optarg);
@@ -415,7 +459,7 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
exit(EXIT_FAILURE);
}
} else {
- osnoise_top_usage("--trigger requires a previous -e\n");
+ osnoise_top_usage(params, "--trigger requires a previous -e\n");
}
break;
case '1': /* filter */
@@ -426,11 +470,11 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
exit(EXIT_FAILURE);
}
} else {
- osnoise_top_usage("--filter requires a previous -e\n");
+ osnoise_top_usage(params, "--filter requires a previous -e\n");
}
break;
default:
- osnoise_top_usage("Invalid option");
+ osnoise_top_usage(params, "Invalid option");
}
}
@@ -495,6 +539,14 @@ osnoise_top_apply_config(struct osnoise_tool *tool, struct osnoise_top_params *p
}
}
+ if (params->mode == MODE_HWNOISE) {
+ retval = osnoise_set_irq_disable(tool->context, 1);
+ if (retval) {
+ err_msg("Failed to set OSNOISE_IRQ_DISABLE option\n");
+ goto out_err;
+ }
+ }
+
return 0;
out_err:
diff --git a/src/rtla.c b/src/rtla.c
index 52e8f1825281..7635c70123ab 100644
--- a/src/rtla.c
+++ b/src/rtla.c
@@ -26,6 +26,7 @@ static void rtla_usage(int err)
"",
" commands:",
" osnoise - gives information about the operating system noise (osnoise)",
+ " hwnoise - gives information about hardware-related noise",
" timerlat - measures the timer irq and thread latency",
"",
NULL,
@@ -47,6 +48,9 @@ int run_command(int argc, char **argv, int start_position)
if (strcmp(argv[start_position], "osnoise") == 0) {
osnoise_main(argc-start_position, &argv[start_position]);
goto ran;
+ } else if (strcmp(argv[start_position], "hwnoise") == 0) {
+ hwnoise_main(argc-start_position, &argv[start_position]);
+ goto ran;
} else if (strcmp(argv[start_position], "timerlat") == 0) {
timerlat_main(argc-start_position, &argv[start_position]);
goto ran;
--
2.40.1

155
rtla-Fix-exit-status-when-returning-from-calls-to-usage.patch
View File

@ -1,155 +0,0 @@
From 4c6874374859d89aa6a75019bb0a913369e472c9 Mon Sep 17 00:00:00 2001
From: John Kacur <jkacur@redhat.com>
Date: Mon, 7 Nov 2022 09:43:13 -0500
Subject: [PATCH] rtla: Fix exit status when returning from calls to usage()
rtla_usage(), osnoise_usage() and timerlat_usage() all exit with an
error status.
However when these are called from help, they should exit with a
non-error status.
Fix this by passing the exit status to the functions.
Note, although we remove the subsequent call to exit after calling
usage, we leave it in at the end of a function to suppress the compiler
warning "control reaches end of a non-void function".
Link: https://lkml.kernel.org/r/20221107144313.22470-1-jkacur@redhat.com
Signed-off-by: John Kacur <jkacur@redhat.com>
Acked-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
src/osnoise.c | 9 ++++-----
src/rtla.c | 12 +++++-------
src/timerlat.c | 9 ++++-----
3 files changed, 13 insertions(+), 17 deletions(-)
diff --git a/src/osnoise.c b/src/osnoise.c
index b8ec6c15bccb..4dee343909b1 100644
--- a/src/osnoise.c
+++ b/src/osnoise.c
@@ -903,7 +903,7 @@ struct osnoise_tool *osnoise_init_trace_tool(char *tracer)
return NULL;
}
-static void osnoise_usage(void)
+static void osnoise_usage(int err)
{
int i;
@@ -923,7 +923,7 @@ static void osnoise_usage(void)
for (i = 0; msg[i]; i++)
fprintf(stderr, "%s\n", msg[i]);
- exit(1);
+ exit(err);
}
int osnoise_main(int argc, char *argv[])
@@ -941,8 +941,7 @@ int osnoise_main(int argc, char *argv[])
}
if ((strcmp(argv[1], "-h") == 0) || (strcmp(argv[1], "--help") == 0)) {
- osnoise_usage();
- exit(0);
+ osnoise_usage(0);
} else if (strncmp(argv[1], "-", 1) == 0) {
/* the user skipped the tool, call the default one */
osnoise_top_main(argc, argv);
@@ -956,6 +955,6 @@ int osnoise_main(int argc, char *argv[])
}
usage:
- osnoise_usage();
+ osnoise_usage(1);
exit(1);
}
diff --git a/src/rtla.c b/src/rtla.c
index 09bd21b8af81..52e8f1825281 100644
--- a/src/rtla.c
+++ b/src/rtla.c
@@ -14,7 +14,7 @@
/*
* rtla_usage - print rtla usage
*/
-static void rtla_usage(void)
+static void rtla_usage(int err)
{
int i;
@@ -33,7 +33,7 @@ static void rtla_usage(void)
for (i = 0; msg[i]; i++)
fprintf(stderr, "%s\n", msg[i]);
- exit(1);
+ exit(err);
}
/*
@@ -70,11 +70,9 @@ int main(int argc, char *argv[])
goto usage;
if (strcmp(argv[1], "-h") == 0) {
- rtla_usage();
- exit(0);
+ rtla_usage(0);
} else if (strcmp(argv[1], "--help") == 0) {
- rtla_usage();
- exit(0);
+ rtla_usage(0);
}
retval = run_command(argc, argv, 1);
@@ -82,6 +80,6 @@ int main(int argc, char *argv[])
exit(0);
usage:
- rtla_usage();
+ rtla_usage(1);
exit(1);
}
diff --git a/src/timerlat.c b/src/timerlat.c
index 97abbf494fee..21cdcc5c4a29 100644
--- a/src/timerlat.c
+++ b/src/timerlat.c
@@ -14,7 +14,7 @@
#include "timerlat.h"
-static void timerlat_usage(void)
+static void timerlat_usage(int err)
{
int i;
@@ -34,7 +34,7 @@ static void timerlat_usage(void)
for (i = 0; msg[i]; i++)
fprintf(stderr, "%s\n", msg[i]);
- exit(1);
+ exit(err);
}
int timerlat_main(int argc, char *argv[])
@@ -52,8 +52,7 @@ int timerlat_main(int argc, char *argv[])
}
if ((strcmp(argv[1], "-h") == 0) || (strcmp(argv[1], "--help") == 0)) {
- timerlat_usage();
- exit(0);
+ timerlat_usage(0);
} else if (strncmp(argv[1], "-", 1) == 0) {
/* the user skipped the tool, call the default one */
timerlat_top_main(argc, argv);
@@ -67,6 +66,6 @@ int timerlat_main(int argc, char *argv[])
}
usage:
- timerlat_usage();
+ timerlat_usage(1);
exit(1);
}
--
2.39.0

34
rtla-Fix-uninitialized-variable-found.patch Normal file
View File

@ -0,0 +1,34 @@
From 696444a544ecd6d62c1edc89516b376cefb28929 Mon Sep 17 00:00:00 2001
From: Colin Ian King <colin.i.king@gmail.com>
Date: Thu, 27 Jul 2023 16:01:17 +0100
Subject: [PATCH] rtla: Fix uninitialized variable found
Variable found is not being initialized, in the case where the desired
mount is not found the variable contains garbage. Fix this by initializing
it to zero.
Link: https://lore.kernel.org/all/20230727150117.627730-1-colin.i.king@gmail.com/
Fixes: a957cbc02531 ("rtla: Add -C cgroup support")
Signed-off-by: Colin Ian King <colin.i.king@gmail.com>
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
---
src/utils.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/src/utils.c b/src/utils.c
index 623a38908ed5..c769d7b3842c 100644
--- a/src/utils.c
+++ b/src/utils.c
@@ -538,7 +538,7 @@ static const int find_mount(const char *fs, char *mp, int sizeof_mp)
{
char mount_point[MAX_PATH];
char type[100];
- int found;
+ int found = 0;
FILE *fp;
fp = fopen("/proc/mounts", "r");
--
2.42.0

1056
rtla-timerlat-Add-auto-analysis-core.patch
View File

File diff suppressed because it is too large Load Diff

164
rtla-timerlat-Add-auto-analysis-only-option.patch
View File

@ -1,164 +0,0 @@
From 9fa48a2477de747b644c778a1e35d679cabcd917 Mon Sep 17 00:00:00 2001
From: Daniel Bristot de Oliveira <bristot@kernel.org>
Date: Wed, 29 Mar 2023 18:23:32 +0200
Subject: [PATCH 7/8] rtla/timerlat: Add auto-analysis only option
Parsing and formating timerlat data might consume a reasonable
amount of CPU time on very large systems, or when timerlat
has a too short period.
Add an option to run timerlat with auto-analysis enabled while
skipping the statistics parsing. In this mode, rtla timerlat
periodically checks if the tracing is on, going to sleep waiting
for the stop tracing condition to stop tracing, or for the
tracing session to finish.
If the stop tracing condition is hit, the tool prints the auto
analysis. Otherwise, the tool prints the max observed latency and
exit. The max observed latency is captured via tracing_max_latency.
Link: https://lore.kernel.org/linux-trace-devel/4dc514d1d5dc353c537a466a9b5af44c266b6da2.1680106912.git.bristot@kernel.org
Cc: Jonathan Corbet <corbet@lwn.net>
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
src/timerlat_top.c | 49 +++++++++++++++++++++++++++++++++++++++++-----
1 file changed, 44 insertions(+), 5 deletions(-)
diff --git a/src/timerlat_top.c b/src/timerlat_top.c
index eea5b3357e27..92c658c64f28 100644
--- a/src/timerlat_top.c
+++ b/src/timerlat_top.c
@@ -33,6 +33,7 @@ struct timerlat_top_params {
int set_sched;
int dma_latency;
int no_aa;
+ int aa_only;
int dump_tasks;
struct sched_attr sched_param;
struct trace_events *events;
@@ -142,10 +143,12 @@ timerlat_top_handler(struct trace_seq *s, struct tep_record *record,
top = container_of(trace, struct osnoise_tool, trace);
params = top->params;
- tep_get_field_val(s, event, "context", record, &thread, 1);
- tep_get_field_val(s, event, "timer_latency", record, &latency, 1);
+ if (!params->aa_only) {
+ tep_get_field_val(s, event, "context", record, &thread, 1);
+ tep_get_field_val(s, event, "timer_latency", record, &latency, 1);
- timerlat_top_update(top, cpu, thread, latency);
+ timerlat_top_update(top, cpu, thread, latency);
+ }
if (!params->no_aa)
timerlat_aa_handler(s, record, event, context);
@@ -250,6 +253,9 @@ timerlat_print_stats(struct timerlat_top_params *params, struct osnoise_tool *to
static int nr_cpus = -1;
int i;
+ if (params->aa_only)
+ return;
+
if (nr_cpus == -1)
nr_cpus = sysconf(_SC_NPROCESSORS_CONF);
@@ -279,10 +285,11 @@ static void timerlat_top_usage(char *usage)
"",
" usage: rtla timerlat [top] [-h] [-q] [-a us] [-d s] [-D] [-n] [-p us] [-i us] [-T us] [-s us] \\",
" [[-t[=file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] \\",
- " [-P priority] [--dma-latency us]",
+ " [-P priority] [--dma-latency us] [--aa-only us]",
"",
" -h/--help: print this menu",
" -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit",
+ " --aa-only us: stop if <us> latency is hit, only printing the auto analysis (reduces CPU usage)",
" -p/--period us: timerlat period in us",
" -i/--irq us: stop trace if the irq latency is higher than the argument in us",
" -T/--thread us: stop trace if the thread latency is higher than the argument in us",
@@ -362,13 +369,14 @@ static struct timerlat_top_params
{"dma-latency", required_argument, 0, '2'},
{"no-aa", no_argument, 0, '3'},
{"dump-tasks", no_argument, 0, '4'},
+ {"aa-only", required_argument, 0, '5'},
{0, 0, 0, 0}
};
/* getopt_long stores the option index here. */
int option_index = 0;
- c = getopt_long(argc, argv, "a:c:d:De:hi:np:P:qs:t::T:0:1:2:34",
+ c = getopt_long(argc, argv, "a:c:d:De:hi:np:P:qs:t::T:0:1:2:345:",
long_options, &option_index);
/* detect the end of the options. */
@@ -389,6 +397,20 @@ static struct timerlat_top_params
/* set trace */
params->trace_output = "timerlat_trace.txt";
break;
+ case '5':
+ /* it is here because it is similar to -a */
+ auto_thresh = get_llong_from_str(optarg);
+
+ /* set thread stop to auto_thresh */
+ params->stop_total_us = auto_thresh;
+ params->stop_us = auto_thresh;
+
+ /* get stack trace */
+ params->print_stack = auto_thresh;
+
+ /* set aa_only to avoid parsing the trace */
+ params->aa_only = 1;
+ break;
case 'c':
retval = parse_cpu_list(optarg, &params->monitored_cpus);
if (retval)
@@ -503,6 +525,9 @@ static struct timerlat_top_params
if (!params->stop_us && !params->stop_total_us)
params->no_aa = 1;
+ if (params->no_aa && params->aa_only)
+ timerlat_top_usage("--no-aa and --aa-only are mutually exclusive!");
+
return params;
}
@@ -634,6 +659,7 @@ int timerlat_top_main(int argc, char *argv[])
struct trace_instance *trace;
int dma_latency_fd = -1;
int return_value = 1;
+ char *max_lat;
int retval;
params = timerlat_top_parse_args(argc, argv);
@@ -700,6 +726,9 @@ int timerlat_top_main(int argc, char *argv[])
while (!stop_tracing) {
sleep(params->sleep_time);
+ if (params->aa_only && !trace_is_off(&top->trace, &record->trace))
+ continue;
+
retval = tracefs_iterate_raw_events(trace->tep,
trace->inst,
NULL,
@@ -733,6 +762,16 @@ int timerlat_top_main(int argc, char *argv[])
printf(" Saving trace to %s\n", params->trace_output);
save_trace_to_file(record->trace.inst, params->trace_output);
}
+ } else if (params->aa_only) {
+ /*
+ * If the trace did not stop with --aa-only, at least print the
+ * max known latency.
+ */
+ max_lat = tracefs_instance_file_read(trace->inst, "tracing_max_latency", NULL);
+ if (max_lat) {
+ printf(" Max latency was %s\n", max_lat);
+ free(max_lat);
+ }
}
out_top:
--
2.40.1

293
rtla-timerlat-Add-auto-analysis-support-to-timerlat.patch
View File

@ -1,293 +0,0 @@
From 5def33df84d2326ebf5f29ae9ddc702a4593c337 Mon Sep 17 00:00:00 2001
From: Daniel Bristot de Oliveira <bristot@kernel.org>
Date: Tue, 31 Jan 2023 16:38:54 +0100
Subject: [PATCH 4/8] rtla/timerlat: Add auto-analysis support to timerlat top
Currently, timerlat top displays the timerlat tracer latency results, saving
the intuitive timerlat trace for the developer to analyze.
This patch goes a step forward in the automaton of the scheduling latency
analysis by providing a summary of the root cause of a latency higher than
the passed "stop tracing" parameter if the trace stops.
The output is intuitive enough for non-expert users to have a general idea
of the root cause by looking at each factor's contribution percentage while
keeping the technical detail in the output for more expert users to start
an in dept debug or to correlate a root cause with an existing one.
The terminology is in line with recent industry and academic publications
to facilitate the understanding of both audiences.
Here is one example of tool output:
----------------------------------------- %< -----------------------------------------------------
# taskset -c 0 timerlat -a 40 -c 1-23 -q
Timer Latency
0 00:00:12 | IRQ Timer Latency (us) | Thread Timer Latency (us)
CPU COUNT | cur min avg max | cur min avg max
1 #12322 | 0 0 1 15 | 10 3 9 31
2 #12322 | 3 0 1 12 | 10 3 9 23
3 #12322 | 1 0 1 21 | 8 2 8 34
4 #12322 | 1 0 1 17 | 10 2 11 33
5 #12322 | 0 0 1 12 | 8 3 8 25
6 #12322 | 1 0 1 14 | 16 3 11 35
7 #12322 | 0 0 1 14 | 9 2 8 29
8 #12322 | 1 0 1 22 | 9 3 9 34
9 #12322 | 0 0 1 14 | 8 2 8 24
10 #12322 | 1 0 0 12 | 9 3 8 24
11 #12322 | 0 0 0 15 | 6 2 7 29
12 #12321 | 1 0 0 13 | 5 3 8 23
13 #12319 | 0 0 1 14 | 9 3 9 26
14 #12321 | 1 0 0 13 | 6 2 8 24
15 #12321 | 1 0 1 15 | 12 3 11 27
16 #12318 | 0 0 1 13 | 7 3 10 24
17 #12319 | 0 0 1 13 | 11 3 9 25
18 #12318 | 0 0 0 12 | 8 2 8 20
19 #12319 | 0 0 1 18 | 10 2 9 28
20 #12317 | 0 0 0 20 | 9 3 8 34
21 #12318 | 0 0 0 13 | 8 3 8 28
22 #12319 | 0 0 1 11 | 8 3 10 22
23 #12320 | 28 0 1 28 | 41 3 11 41
rtla timerlat hit stop tracing
## CPU 23 hit stop tracing, analyzing it ##
IRQ handler delay: 27.49 us (65.52 %)
IRQ latency: 28.13 us
Timerlat IRQ duration: 9.59 us (22.85 %)
Blocking thread: 3.79 us (9.03 %)
objtool:49256 3.79 us
Blocking thread stacktrace
-> timerlat_irq
-> __hrtimer_run_queues
-> hrtimer_interrupt
-> __sysvec_apic_timer_interrupt
-> sysvec_apic_timer_interrupt
-> asm_sysvec_apic_timer_interrupt
-> _raw_spin_unlock_irqrestore
-> cgroup_rstat_flush_locked
-> cgroup_rstat_flush_irqsafe
-> mem_cgroup_flush_stats
-> mem_cgroup_wb_stats
-> balance_dirty_pages
-> balance_dirty_pages_ratelimited_flags
-> btrfs_buffered_write
-> btrfs_do_write_iter
-> vfs_write
-> __x64_sys_pwrite64
-> do_syscall_64
-> entry_SYSCALL_64_after_hwframe
------------------------------------------------------------------------
Thread latency: 41.96 us (100%)
The system has exit from idle latency!
Max timerlat IRQ latency from idle: 17.48 us in cpu 4
Saving trace to timerlat_trace.txt
----------------------------------------- >% -----------------------------------------------------
In this case, the major factor was the delay suffered by the IRQ handler
that handles timerlat wakeup: 65.52 %. This can be caused by the
current thread masking interrupts, which can be seen in the blocking
thread stacktrace: the current thread (objtool:49256) disabled interrupts
via raw spin lock operations inside mem cgroup, while doing write
syscall in a btrfs file system.
A simple search for the function name on Google shows that this is
a legit case for disabling the interrupts:
cgroup: Use irqsave in cgroup_rstat_flush_locked()
lore.kernel.org/linux-mm/20220301122143.1521823-2-bigeasy@linutronix.de/
The output also prints other reasons for the latency root cause, such as:
- an IRQ that happened before the IRQ handler that caused delays
- The interference from NMI, IRQ, Softirq, and Threads
The details about how these factors affect the scheduling latency
can be found here:
https://bristot.me/demystifying-the-real-time-linux-latency/
Link: https://lkml.kernel.org/r/3d45f40e630317f51ac6d678e2d96d310e495729.1675179318.git.bristot@kernel.org
Cc: Daniel Bristot de Oliveira <bristot@kernel.org>
Cc: Jonathan Corbet <corbet@lwn.net>
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
src/timerlat_top.c | 46 ++++++++++++++++++++++++++++++++++++++++++++--
1 file changed, 44 insertions(+), 2 deletions(-)
diff --git a/src/timerlat_top.c b/src/timerlat_top.c
index 334271935222..eea5b3357e27 100644
--- a/src/timerlat_top.c
+++ b/src/timerlat_top.c
@@ -10,10 +10,12 @@
#include <unistd.h>
#include <stdio.h>
#include <time.h>
+#include <errno.h>
#include "utils.h"
#include "osnoise.h"
#include "timerlat.h"
+#include "timerlat_aa.h"
struct timerlat_top_params {
char *cpus;
@@ -30,6 +32,8 @@ struct timerlat_top_params {
int quiet;
int set_sched;
int dma_latency;
+ int no_aa;
+ int dump_tasks;
struct sched_attr sched_param;
struct trace_events *events;
};
@@ -130,17 +134,22 @@ timerlat_top_handler(struct trace_seq *s, struct tep_record *record,
struct tep_event *event, void *context)
{
struct trace_instance *trace = context;
+ struct timerlat_top_params *params;
unsigned long long latency, thread;
struct osnoise_tool *top;
int cpu = record->cpu;
top = container_of(trace, struct osnoise_tool, trace);
+ params = top->params;
tep_get_field_val(s, event, "context", record, &thread, 1);
tep_get_field_val(s, event, "timer_latency", record, &latency, 1);
timerlat_top_update(top, cpu, thread, latency);
+ if (!params->no_aa)
+ timerlat_aa_handler(s, record, event, context);
+
return 0;
}
@@ -281,11 +290,13 @@ static void timerlat_top_usage(char *usage)
" -c/--cpus cpus: run the tracer only on the given cpus",
" -d/--duration time[m|h|d]: duration of the session in seconds",
" -D/--debug: print debug info",
+ " --dump-tasks: prints the task running on all CPUs if stop conditions are met (depends on !--no-aa)",
" -t/--trace[=file]: save the stopped trace to [file|timerlat_trace.txt]",
" -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed",
" --filter <command>: enable a trace event filter to the previous -e event",
" --trigger <command>: enable a trace event trigger to the previous -e event",
" -n/--nano: display data in nanoseconds",
+ " --no-aa: disable auto-analysis, reducing rtla timerlat cpu usage",
" -q/--quiet print only a summary at the end",
" --dma-latency us: set /dev/cpu_dma_latency latency <us> to reduce exit from idle latency",
" -P/--priority o:prio|r:prio|f:prio|d:runtime:period : set scheduling parameters",
@@ -349,13 +360,15 @@ static struct timerlat_top_params
{"trigger", required_argument, 0, '0'},
{"filter", required_argument, 0, '1'},
{"dma-latency", required_argument, 0, '2'},
+ {"no-aa", no_argument, 0, '3'},
+ {"dump-tasks", no_argument, 0, '4'},
{0, 0, 0, 0}
};
/* getopt_long stores the option index here. */
int option_index = 0;
- c = getopt_long(argc, argv, "a:c:d:De:hi:np:P:qs:t::T:0:1:2:",
+ c = getopt_long(argc, argv, "a:c:d:De:hi:np:P:qs:t::T:0:1:2:34",
long_options, &option_index);
/* detect the end of the options. */
@@ -368,13 +381,13 @@ static struct timerlat_top_params
/* set thread stop to auto_thresh */
params->stop_total_us = auto_thresh;
+ params->stop_us = auto_thresh;
/* get stack trace */
params->print_stack = auto_thresh;
/* set trace */
params->trace_output = "timerlat_trace.txt";
-
break;
case 'c':
retval = parse_cpu_list(optarg, &params->monitored_cpus);
@@ -437,6 +450,7 @@ static struct timerlat_top_params
params->trace_output = &optarg[1];
else
params->trace_output = "timerlat_trace.txt";
+
break;
case '0': /* trigger */
if (params->events) {
@@ -467,6 +481,12 @@ static struct timerlat_top_params
exit(EXIT_FAILURE);
}
break;
+ case '3': /* no-aa */
+ params->no_aa = 1;
+ break;
+ case '4':
+ params->dump_tasks = 1;
+ break;
default:
timerlat_top_usage("Invalid option");
}
@@ -477,6 +497,12 @@ static struct timerlat_top_params
exit(EXIT_FAILURE);
}
+ /*
+ * Auto analysis only happens if stop tracing, thus:
+ */
+ if (!params->stop_us && !params->stop_total_us)
+ params->no_aa = 1;
+
return params;
}
@@ -547,6 +573,7 @@ static struct osnoise_tool
{
struct osnoise_tool *top;
int nr_cpus;
+ int retval;
nr_cpus = sysconf(_SC_NPROCESSORS_CONF);
@@ -563,6 +590,16 @@ static struct osnoise_tool
tep_register_event_handler(top->trace.tep, -1, "ftrace", "timerlat",
timerlat_top_handler, top);
+ /*
+ * If no auto analysis, we are ready.
+ */
+ if (params->no_aa)
+ return top;
+
+ retval = timerlat_aa_init(top, nr_cpus, params->dump_tasks);
+ if (retval)
+ goto out_err;
+
return top;
out_err:
@@ -688,6 +725,10 @@ int timerlat_top_main(int argc, char *argv[])
if (trace_is_off(&top->trace, &record->trace)) {
printf("rtla timerlat hit stop tracing\n");
+
+ if (!params->no_aa)
+ timerlat_auto_analysis(params->stop_us, params->stop_total_us);
+
if (params->trace_output) {
printf(" Saving trace to %s\n", params->trace_output);
save_trace_to_file(record->trace.inst, params->trace_output);
@@ -701,6 +742,7 @@ int timerlat_top_main(int argc, char *argv[])
params->events = NULL;
out_free:
timerlat_free_top(top->data);
+ timerlat_aa_destroy();
osnoise_destroy_tool(record);
osnoise_destroy_tool(top);
free(params);
--
2.40.1

48
rtla-timerlat-Fix-Previous-IRQ-auto-analysis-line.patch
View File

@ -1,48 +0,0 @@
From 82253a271aae9271fcf0aaa5e0ecc6dd38fb872b Mon Sep 17 00:00:00 2001
From: Daniel Bristot de Oliveira <bristot@kernel.org>
Date: Fri, 24 Mar 2023 20:26:42 +0100
Subject: [PATCH 8/8] rtla/timerlat: Fix "Previous IRQ" auto analysis' line
The "Previous IRQ interference" line is misaligned and without
a \n, breaking the tool's output:
## CPU 12 hit stop tracing, analyzing it ##
Previous IRQ interference: up to 2.22 us IRQ handler delay: 18.06 us (0.00 %)
IRQ latency: 18.52 us
Timerlat IRQ duration: 4.41 us (0.00 %)
Blocking thread: 216.93 us (0.03 %)
Fix the output:
## CPU 7 hit stop tracing, analyzing it ##
Previous IRQ interference: up to 8.93 us
IRQ handler delay: 0.98 us (0.00 %)
IRQ latency: 2.95 us
Timerlat IRQ duration: 11.26 us (0.03 %)
Link: https://lore.kernel.org/linux-trace-devel/8b5819077f15ccf24745c9bf3205451e16ee32d9.1679685525.git.bristot@kernel.org
Fixes: 27e348b221f6 ("rtla/timerlat: Add auto-analysis core")
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
src/timerlat_aa.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/src/timerlat_aa.c b/src/timerlat_aa.c
index ec4e0f4b0e6c..1843fff66da5 100644
--- a/src/timerlat_aa.c
+++ b/src/timerlat_aa.c
@@ -548,7 +548,7 @@ static void timerlat_thread_analysis(struct timerlat_aa_data *taa_data, int cpu,
exp_irq_ts = taa_data->timer_irq_start_time - taa_data->timer_irq_start_delay;
if (exp_irq_ts < taa_data->prev_irq_timstamp + taa_data->prev_irq_duration)
- printf(" Previous IRQ interference: \t up to %9.2f us",
+ printf(" Previous IRQ interference: \t\t up to %9.2f us\n",
ns_to_usf(taa_data->prev_irq_duration));
/*
--
2.40.1

32
rtla.spec
View File

@ -1,6 +1,6 @@
Name: rtla Name: rtla
Version: 5.14.0 Version: 6.6.0
Release: 8%{?dist} Release: 1%{?dist}
Summary: Real-Time Linux Analysis tools Summary: Real-Time Linux Analysis tools
License: GPLv2 License: GPLv2
@ -8,7 +8,7 @@ URL: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
# The Source0 rtla-5.14.0.tar.bz2 file was created from git # The Source0 rtla-5.14.0.tar.bz2 file was created from git
# tag kernel-5.14.0-204.el9 # tag kernel-5.14.0-204.el9
# and from the tools/tracing/rtla directory issuing make tarball # and from the tools/tracing/rtla directory issuing make tarball
Source0: rtla-5.14.0.tar.bz2 Source0: rtla-6.6.0.tar.bz2
BuildRequires: gcc BuildRequires: gcc
BuildRequires: python3-docutils BuildRequires: python3-docutils
@ -18,17 +18,7 @@ Requires: libtraceevent >= 1.5.3
Requires: libtracefs >= 1.3.1 Requires: libtracefs >= 1.3.1
# Patches # Patches
Patch1: rtla-Fix-exit-status-when-returning-from-calls-to-usage.patch Patch01: rtla-Fix-uninitialized-variable-found.patch
Patch2: Documentation-rtla-Correct-command-line-example.patch
Patch3: tools-tracing-rtla-osnoise_hist-use-total-duration-f.patch
Patch4: tools-tracing-rtla-osnoise_hist-display-average-with.patch
Patch5: rtla-timerlat-Add-auto-analysis-core.patch
Patch6: rtla-timerlat-Add-auto-analysis-support-to-timerlat.patch
Patch7: rtla-timerlat-Add-auto-analysis-only-option.patch
Patch8: rtla-timerlat-Fix-Previous-IRQ-auto-analysis-line.patch
Patch9: Documentation-rtla-Add-timerlat-top-auto-analysis-op.patch
Patch10: rtla-Add-hwnoise-tool.patch
Patch11: Documentation-rtla-Add-hwnoise-man-page.patch
%description %description
The rtla meta-tool includes a set of commands that aims to analyze The rtla meta-tool includes a set of commands that aims to analyze
@ -40,16 +30,6 @@ about the properties and root causes of unexpected results.
%prep %prep
%setup -q -n %{name}-%{version} %setup -q -n %{name}-%{version}
%patch1 -p1 %patch1 -p1
%patch2 -p1
%patch3 -p1
%patch4 -p1
%patch5 -p1
%patch6 -p1
%patch7 -p1
%patch8 -p1
%patch9 -p1
%patch10 -p1
%patch11 -p1
%build %build
@ -86,6 +66,10 @@ make DESTDIR=%{buildroot} -C Documentation install
%changelog %changelog
* Mon Dec 18 2023 John Kacur <jkacur@redhat.com> - 6.6.0-1
Update to rtla in linux-6.6.0
Resolves: RHEL-10081
* Fri Jul 14 2023 John Kacur <jkacur@redhat.com> - 5.14.0-8 * Fri Jul 14 2023 John Kacur <jkacur@redhat.com> - 5.14.0-8
- Add rtla hwnoise - Add rtla hwnoise
Resolves: bz2175295 Resolves: bz2175295

2
sources
View File

@ -1 +1 @@
SHA512 (rtla-5.14.0.tar.bz2) = 1cf03f7f3fcd2c59a358d6c928048d7ddb82028b21a00d9cbe34cddd291427ab99230163cba90479155e2b57f67911b33cd1d4fe82c02115d26443e4174cc763 SHA512 (rtla-6.6.0.tar.bz2) = 6b8cb82280b18df7653bb2c58f724a58ed34415d50de991e1e124226da0bc06ae7e2d52ae4af667e5359d8cc4031b92bc5db14529d453c488c7549fbc3c9514c

36
tools-tracing-rtla-osnoise_hist-display-average-with.patch
View File

@ -1,36 +0,0 @@
From 1fab1469b66baf7847298b205e5c4aff47c2ae8a Mon Sep 17 00:00:00 2001
From: Andreas Ziegler <br015@umbiko.net>
Date: Tue, 3 Jan 2023 11:34:00 +0100
Subject: [PATCH 2/8] tools/tracing/rtla: osnoise_hist: display average with
two-digit precision
Calculate average value in osnoise-hist summary with two-digit
precision to avoid displaying too optimitic results.
Link: https://lkml.kernel.org/r/20230103103400.275566-3-br015@umbiko.net
Signed-off-by: Andreas Ziegler <br015@umbiko.net>
Acked-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
src/osnoise_hist.c | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/src/osnoise_hist.c b/src/osnoise_hist.c
index fe34452fc4ec..13e1233690bb 100644
--- a/src/osnoise_hist.c
+++ b/src/osnoise_hist.c
@@ -335,8 +335,8 @@ osnoise_print_summary(struct osnoise_hist_params *params,
continue;
if (data->hist[cpu].count)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].sum_sample / data->hist[cpu].count);
+ trace_seq_printf(trace->seq, "%9.2f ",
+ ((double) data->hist[cpu].sum_sample) / data->hist[cpu].count);
else
trace_seq_printf(trace->seq, " - ");
}
--
2.40.1

51
tools-tracing-rtla-osnoise_hist-use-total-duration-f.patch
View File

@ -1,51 +0,0 @@
From fe137a4fe0e77eb95396cfc5c3dd7df404421aa4 Mon Sep 17 00:00:00 2001
From: Andreas Ziegler <br015@umbiko.net>
Date: Tue, 3 Jan 2023 11:33:59 +0100
Subject: [PATCH 1/8] tools/tracing/rtla: osnoise_hist: use total duration for
average calculation
Sampled durations must be weighted by observed quantity, to arrive at a correct
average duration value.
Perform calculation of total duration by summing (duration * count).
Link: https://lkml.kernel.org/r/20230103103400.275566-2-br015@umbiko.net
Fixes: 829a6c0b5698 ("rtla/osnoise: Add the hist mode")
Signed-off-by: Andreas Ziegler <br015@umbiko.net>
Acked-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
src/osnoise_hist.c | 5 ++++-
1 file changed, 4 insertions(+), 1 deletion(-)
diff --git a/src/osnoise_hist.c b/src/osnoise_hist.c
index 5d7ea479ac89..fe34452fc4ec 100644
--- a/src/osnoise_hist.c
+++ b/src/osnoise_hist.c
@@ -121,6 +121,7 @@ static void osnoise_hist_update_multiple(struct osnoise_tool *tool, int cpu,
{
struct osnoise_hist_params *params = tool->params;
struct osnoise_hist_data *data = tool->data;
+ unsigned long long total_duration;
int entries = data->entries;
int bucket;
int *hist;
@@ -131,10 +132,12 @@ static void osnoise_hist_update_multiple(struct osnoise_tool *tool, int cpu,
if (data->bucket_size)
bucket = duration / data->bucket_size;
+ total_duration = duration * count;
+
hist = data->hist[cpu].samples;
data->hist[cpu].count += count;
update_min(&data->hist[cpu].min_sample, &duration);
- update_sum(&data->hist[cpu].sum_sample, &duration);
+ update_sum(&data->hist[cpu].sum_sample, &total_duration);
update_max(&data->hist[cpu].max_sample, &duration);
if (bucket < entries)
--
2.40.1