Hi Steve,
On 23/10/2024 10:47, Steven Rostedt wrote:
On Tue, 22 Oct 2024 11:21:34 +0200
Jean-Michel Hautbois <jeanmichel.hautbois@xxxxxxxxxx> wrote:
I was not really expecting you to review the m68k one no :-).
I think I have other issues which might have impact on ftrace too.
For instance, when I launch cyclictest I have a warning about HRTIMERS:
# cyclictest -p 99
WARN: stat /dev/cpu_dma_latency failed: No such file or directory
WARN: High resolution timers not available
policy: fifo: loadavg: 1.21 0.40 0.14 1/122 245
T: 0 ( 245) P:99 I:1000 C: 11203 Min: 92 Act: 623 Avg: 775 Max:
3516
The latencies are quite high...
Yes, if you don't have high resolution timers, the latency will be high.
According to my config, I should have those:
CONFIG_HIGH_RES_TIMERS=y
But regarding ftrace it seems that the trace is not able to give me more
than a microsecond precision. I addded a few trace_printk() in a driver
of mine and I get:
irq/182-dspi-sl-112 [000] D.... 277.160000: dspi_interrupt:
Received 2 bytes
irq/182-dspi-sl-112 [000] D.... 277.160000: dspi_interrupt:
Received 2 bytes
irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt:
dspi_interrupt
irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt: TX
FIFO overflow
irq/182-dspi-sl-112 [000] D.... 277.163000: dspi_interrupt:
Restart FIFO
Do you have any clue ?
Yes. The ring buffer clock is dependent on the architecture's clock. By
default, it uses whatever the scheduler clock uses. If the scheduler
clock is 1ms resolution, so will the tracing data be.
By default. So, I could change it to mono_raw for instance :-). It seems
that timerlat is ok with it !
irq/178-UART-99 [000] D.h1. 95.766649: #27138 context
irq timer_latency 525376 ns
timerlat/0-235 [000] ..... 95.766826: #27138 context
thread timer_latency 697920 ns
<idle>-0 [000] dnh1. 95.767682: #27139 context
irq timer_latency 559616 ns
timerlat/0-235 [000] ..... 95.767839: #27139 context
thread timer_latency 713216 ns
<idle>-0 [000] dnh1. 95.768701: #27140 context
irq timer_latency 577984 ns
timerlat/0-235 [000] ..... 95.768861: #27140 context
thread timer_latency 734656 ns
irq/178-UART-99 [000] d.h1. 95.769671: #27141 context
irq timer_latency 548736 ns
timerlat/0-235 [000] ..... 95.769838: #27141 context
thread timer_latency 711552 ns
irq/178-UART-99 [000] D.h1. 95.770664: #27142 context
irq timer_latency 540992 ns
timerlat/0-235 [000] ..... 95.770841: #27142 context
thread timer_latency 713024 ns
-- Steve
