Lines Matching +full:measure +full:- +full:delay +full:- +full:time
6 find sources of wakeup latencies of real-time threads. Like cyclictest,
9 time* and the *absolute time* that the timer was set to expire. The main
13 -----
28 # _-----=> irqs-off
29 # / _----=> need-resched
30 # | / _---=> hardirq/softirq
31 # || / _--=> preempt-depth
34 # TASK-PID CPU# |||| TIMESTAMP ID CONTEXT LATENCY
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
46 The tracer creates a per-cpu kernel thread with real-time priority that
55 delayed by hardware-related actions, such as SMIs, NMIs, IRQs,
56 or by thread masking interrupts. Once the timer happens, the delay
63 ---------------------
69 - cpus: CPUs at which a timerlat thread will execute.
70 - timerlat_period_us: the period of the timerlat thread.
71 - stop_tracing_us: stop the system tracing if a
74 - stop_tracing_total_us: stop the system tracing if a
77 - print_stack: save the stack of the IRQ occurrence. The stack is printed
82 ----------------------------
91 [root@f32 tracing]# tail -10 trace
92 … cc1-87882 [005] d..h... 548.771078: #402268 context irq timer_latency 13585 ns
93 …cc1-87882 [005] dNLh1.. 548.771082: irq_noise: local_timer:236 start 548.771077442 duration 75…
94 … cc1-87882 [005] dNLh2.. 548.771099: irq_noise: qxl:21 start 548.771085017 duration 7139 ns
95 …cc1-87882 [005] d...3.. 548.771102: thread_noise: cc1:87882 start 548.771078243 duration …
96 … timerlat/5-1035 [005] ....... 548.771104: #402268 context thread timer_latency 39960 ns
103 the cc1 thread noise took 9909 ns of time before the context switch.
115 observes it at the top and the osnoise: events at the bottom. Each "-"
116 in the timelines means circa 1 us, and the time moves ==>::
123 |-------------| |
124 |-------------+-------------------------|
128 [another thread...^ v..^ v.......][timerlat/ thread] <-- CPU timeline
130 |-------| |-------|
131 |--^ v-------|
134 | +-> irq_noise: 6139 ns
135 +-> irq_noise: 7597 ns
138 ---------------------------
147 [root@f32 tracing]# tail -21 per_cpu/cpu7/trace
148 …insmod-1026 [007] dN.h1.. 200.201948: irq_noise: local_timer:236 start 200.201939376 duration…
149 … insmod-1026 [007] d..h1.. 200.202587: #29800 context irq timer_latency 1616 ns
150 …insmod-1026 [007] dN.h2.. 200.202598: irq_noise: local_timer:236 start 200.202586162 duration…
151 …insmod-1026 [007] dN.h3.. 200.202947: irq_noise: local_timer:236 start 200.202939174 duration…
152 …insmod-1026 [007] d...3.. 200.203444: thread_noise: insmod:1026 start 200.202586933 duratio…
153 … timerlat/7-1001 [007] ....... 200.203445: #29800 context thread timer_latency 859978 ns
154 timerlat/7-1001 [007] ....1.. 200.203446: <stack trace>
184 User-space interface
185 ---------------------------
187 Timerlat allows user-space threads to use timerlat infra-structure to
188 measure scheduling latency. This interface is accessible via a per-CPU
193 - timerlat tracer is enable
194 - osnoise workload option is set to NO_OSNOISE_WORKLOAD
195 - The user-space thread is affined to a single processor
196 - The thread opens the file associated with its single processor
197 - Only one thread can access the file at a time
207 scheduled and report the thread latency via tracer - as for the kernel
210 The difference from the in-kernel timerlat is that, instead of re-arming
215 will report the return from user-space latency, which is the total
217 response time for the request.
222 If at any time one of the conditions is broken, e.g., the thread migrates
224 signal will be sent to the user-space thread.
226 Here is an basic example of user-space code for timerlat::
239 if (sched_setaffinity(gettid(), sizeof(set), &set) == -1)