Re: [PATCH RFC 1/2] m68k: Add tracirqs

[Jean-Michel Hautbois <jeanmichel.hautbois@yoseli.org>]

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@yoseli.org> 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
>