Documentation/trace/timerlat-tracer.rst

36           <idle>-0       [000] d.h1    54.029328: #1     context    irq timer_latency       932 ns
37            <...>-867     [000] ....    54.029339: #1     context thread timer_latency     11700 ns
38           <idle>-0       [001] dNh1    54.029346: #1     context    irq timer_latency      2833 ns
39            <...>-868     [001] ....    54.029353: #1     context thread timer_latency      9820 ns
40           <idle>-0       [000] d.h1    54.030328: #2     context    irq timer_latency       769 ns
41            <...>-867     [000] ....    54.030330: #2     context thread timer_latency      3070 ns
42           <idle>-0       [001] d.h1    54.030344: #2     context    irq timer_latency       935 ns
43            <...>-868     [001] ....    54.030347: #2     context thread timer_latency      4351 ns
90         [root@f32 tracing]# echo 25 > osnoise/stop_tracing_total_us
92 …          cc1-87882   [005] d..h...   548.771078: #402268 context    irq timer_latency     13585 ns
93 …87882   [005] dNLh1..   548.771082: irq_noise: local_timer:236 start 548.771077442 duration 7597 ns
94 …     cc1-87882   [005] dNLh2..   548.771099: irq_noise: qxl:21 start 548.771085017 duration 7139 ns
95 …882   [005] d...3..   548.771102: thread_noise:      cc1:87882 start 548.771078243 duration 9909 ns
96 …   timerlat/5-1035    [005] .......   548.771104: #402268 context thread timer_latency     39960 ns
102 thread took 7597 ns, and the qxl:21 device IRQ took 7139 ns. Finally,
103 the cc1 thread noise took 9909 ns of time before the context switch.
110 by the IRQ execution (which indeed accounted for 12736 ns). But
120        event        13585 ns                   39960 ns
133                             |          |       + thread_noise: 9909 ns
134                             |          +-> irq_noise: 6139 ns
135                             +-> irq_noise: 7597 ns
148 …1026    [007] dN.h1..   200.201948: irq_noise: local_timer:236 start 200.201939376 duration 7872 ns
149 …        insmod-1026    [007] d..h1..   200.202587: #29800 context    irq timer_latency      1616 ns
150 …026    [007] dN.h2..   200.202598: irq_noise: local_timer:236 start 200.202586162 duration 11855 ns
151 …1026    [007] dN.h3..   200.202947: irq_noise: local_timer:236 start 200.202939174 duration 7318 ns
152 …6    [007] d...3..   200.203444: thread_noise:   insmod:1026 start 200.202586933 duration 838681 ns
153 …    timerlat/7-1001    [007] .......   200.203445: #29800 context thread timer_latency    859978 ns