#
301deca0 |
|
04-Aug-2023 |
Daniel Bristot de Oliveira <bristot@kernel.org> |
rtla/timerlat_aa: Fix previous IRQ delay for IRQs that happens after thread sample timerlat auto-analysis takes note of all IRQs, before or after the execution of the timerlat thread. Because we cannot go backward in the trace (we will fix it when moving to trace-cmd lib?), timerlat aa take note of the last IRQ execution in the waiting for the IRQ state, and then print it if it is executed after the expected timer IRQ starting time. After the thread sample, the timerlat starts recording the next IRQs as "previous" irq for the next occurrence. However, if an IRQ happens after the thread measurement but before the tracing stops, it is classified as a previous IRQ. That is not wrong, as it can be "previous" for the subsequent activation. What is wrong is considering it as a potential source for the last activation. Ignore the IRQ interference that happens after the IRQ starting time for now. A future improvement for timerlat can be either keeping a list of previous IRQ execution or using the trace-cmd library. Still, it requires further investigation - it is a new feature. Link: https://lore.kernel.org/lkml/a44a3f5c801dcc697bacf7325b65d4a5b0460537.1691162043.git.bristot@kernel.org Fixes: 27e348b221f6 ("rtla/timerlat: Add auto-analysis core") Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
|
#
6c73daf2 |
|
04-Aug-2023 |
Daniel Bristot de Oliveira <bristot@kernel.org> |
rtla/timerlat_aa: Fix negative IRQ delay When estimating the IRQ timer delay, we are dealing with two different clock sources: the external clock source that timerlat uses as a reference and the clock used by the tracer. There are also two moments: the time reading the clock and the timer in which the event is placed in the buffer (the trace event timestamp). If the processor is slow or there is some hardware noise, the difference between the timestamp and the external clock, read can be longer than the IRQ handler delay, resulting in a negative time. If so, set IRQ to start delay as 0. In the end, it is less near-zero and relevant then the noise. Link: https://lore.kernel.org/lkml/a066fb667c7136d86dcddb3c7ccd72587db3e7c7.1691162043.git.bristot@kernel.org Fixes: 27e348b221f6 ("rtla/timerlat: Add auto-analysis core") Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
|
#
02d89917 |
|
04-Aug-2023 |
Daniel Bristot de Oliveira <bristot@kernel.org> |
rtla/timerlat_aa: Zero thread sum after every sample analysis The thread thread_thread_sum accounts for thread interference during a single activation. It was not being zeroed, so it was accumulating thread interference over all activations. It was not that visible when timerlat was the highest priority. Link: https://lore.kernel.org/lkml/97bff55b0141f2d01b47d9450a5672fde147b89a.1691162043.git.bristot@kernel.org Fixes: 27e348b221f6 ("rtla/timerlat: Add auto-analysis core") Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org>
|
#
c66552be |
|
06-Jun-2023 |
Daniel Bristot de Oliveira <bristot@kernel.org> |
rtla/timerlat: Give timerlat auto analysis its own instance Currently, the auto-analysis is attached to the timerlat top instance. The idea was to avoid creating another instance just for that, so one instance could be reused. The drawback is that, by doing so, the auto-analysis run for the entire session, consuming CPU time. On my 24 box CPUs for timerlat with a 100 us period consumed 50 % with auto analysis, but only 16 % without. By creating an instance for auto-analysis, we can keep the processing stopped until a stop tracing condition is hit. Once it happens, timerlat auto-analysis can use its own trace instance to parse only the end of the trace. By doing so, auto-analysis stop consuming cpu time when it is not needed. If the --aa-only is passed, the timerlat top instance is reused for auto analysis. Link: https://lkml.kernel.org/r/346b7168c1bae552a415715ec6d23c129a43bdb7.1686066600.git.bristot@kernel.org Cc: William White <chwhite@redhat.com> Cc: Jonathan Corbet <corbet@lwn.net> Tested-by: Juri Lelli <juri.lelli@redhat.com> Signed-off-by: Daniel Bristot de Oliveira <bristot@kernel.org> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
|
#
82253a27 |
|
24-Mar-2023 |
Daniel Bristot de Oliveira <bristot@kernel.org> |
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>
|
#
27e348b2 |
|
31-Jan-2023 |
Daniel Bristot de Oliveira <bristot@kernel.org> |
rtla/timerlat: Add auto-analysis core Currently, timerlat displays a summary of the timerlat tracer results saving the trace if the system hits a stop condition. While this represented a huge step forward, the root cause was not that is accessible to non-expert users. The auto-analysis fulfill this gap by parsing the trace timerlat runs, printing an intuitive auto-analysis. Link: https://lkml.kernel.org/r/1ee073822f6a2cbb33da0c817331d0d4045e837f.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>
|