Hi Steve,
On 15/11/2024 16:25, Steven Rostedt wrote:
On Fri, 15 Nov 2024 09:26:07 +0100
Jean-Michel Hautbois <jeanmichel.hautbois@xxxxxxxxxx> wrote:
Nevertheless it sounds like a really high latency for wake_up().
I have a custom driver which basically gets an IRQ, and calls wake_up on
a read() call. This wake_up() on a high cpu usage can be more than 1ms !
Even with a fifo/99 priority for my kernel thread !
I don't know if it rings any bell ?
I can obviously do more tests if it can help getting down to the issue :-).
Try running timerlat.
Thanks !
Here is what I get:
# echo timerlat > current_tracer
# echo 1 > events/osnoise/enable
# echo 25 > osnoise/stop_tracing_total_us
# tail -10 trace
bash-224 [000] d.h.. 153.268917: #77645 context
irq timer_latency 45056 ns
bash-224 [000] dnh.. 153.268987: irq_noise: timer:206
start 153.268879083 duration 93957 ns
bash-224 [000] d.... 153.269056: thread_noise:
bash:224 start 153.268905324 duration 71045 ns
timerlat/0-271 [000] ..... 153.269103: #77645 context
thread timer_latency 230656 ns
bash-224 [000] d.h.. 153.269735: irq_noise: timer:206
start 153.269613847 duration 103558 ns
bash-224 [000] d.h.. 153.269911: #77646 context
irq timer_latency 40640 ns
bash-224 [000] dnh.. 153.269982: irq_noise: timer:206
start 153.269875367 duration 93190 ns
bash-224 [000] d.... 153.270053: thread_noise:
bash:224 start 153.269900969 duration 72709 ns
timerlat/0-271 [000] ..... 153.270100: #77646 context
thread timer_latency 227008 ns
timerlat/0-271 [000] ..... 153.270155: timerlat_main: stop
tracing hit on cpu 0
It looks awful, right ?
JM
