2 * trace irqs off criticall timings
4 * Copyright (C) 2007-2008 Steven Rostedt <srostedt@redhat.com>
5 * Copyright (C) 2008 Ingo Molnar <mingo@redhat.com>
7 * From code in the latency_tracer, that is:
9 * Copyright (C) 2004-2006 Ingo Molnar
10 * Copyright (C) 2004 William Lee Irwin III
12 #include <linux/kallsyms.h>
13 #include <linux/debugfs.h>
14 #include <linux/uaccess.h>
15 #include <linux/module.h>
16 #include <linux/ftrace.h>
21 static struct trace_array
*irqsoff_trace __read_mostly
;
22 static int tracer_enabled __read_mostly
;
24 static DEFINE_PER_CPU(int, tracing_cpu
);
26 static DEFINE_SPINLOCK(max_trace_lock
);
29 TRACER_IRQS_OFF
= (1 << 1),
30 TRACER_PREEMPT_OFF
= (1 << 2),
33 static int trace_type __read_mostly
;
35 #ifdef CONFIG_PREEMPT_TRACER
36 static inline int notrace
39 return ((trace_type
& TRACER_PREEMPT_OFF
) && preempt_count());
42 # define preempt_trace() (0)
45 #ifdef CONFIG_IRQSOFF_TRACER
46 static inline int notrace
49 return ((trace_type
& TRACER_IRQS_OFF
) &&
53 # define irq_trace() (0)
57 * Sequence count - we record it when starting a measurement and
58 * skip the latency if the sequence has changed - some other section
59 * did a maximum and could disturb our measurement with serial console
60 * printouts, etc. Truly coinciding maximum latencies should be rare
61 * and what happens together happens separately as well, so this doesnt
62 * decrease the validity of the maximum found:
64 static __cacheline_aligned_in_smp
unsigned long max_sequence
;
68 * irqsoff uses its own tracer function to keep the overhead down:
71 irqsoff_tracer_call(unsigned long ip
, unsigned long parent_ip
)
73 struct trace_array
*tr
= irqsoff_trace
;
74 struct trace_array_cpu
*data
;
80 * Does not matter if we preempt. We test the flags
81 * afterward, to see if irqs are disabled or not.
82 * If we preempt and get a false positive, the flags
85 cpu
= raw_smp_processor_id();
86 if (likely(!per_cpu(tracing_cpu
, cpu
)))
89 local_save_flags(flags
);
90 /* slight chance to get a false positive on tracing_cpu */
91 if (!irqs_disabled_flags(flags
))
95 disabled
= atomic_inc_return(&data
->disabled
);
97 if (likely(disabled
== 1))
98 trace_function(tr
, data
, ip
, parent_ip
, flags
);
100 atomic_dec(&data
->disabled
);
103 static struct ftrace_ops trace_ops __read_mostly
=
105 .func
= irqsoff_tracer_call
,
107 #endif /* CONFIG_FTRACE */
110 * Should this new latency be reported/recorded?
112 static int notrace
report_latency(cycle_t delta
)
114 if (tracing_thresh
) {
115 if (delta
< tracing_thresh
)
118 if (delta
<= tracing_max_latency
)
125 check_critical_timing(struct trace_array
*tr
,
126 struct trace_array_cpu
*data
,
127 unsigned long parent_ip
,
130 unsigned long latency
, t0
, t1
;
131 cycle_t T0
, T1
, delta
;
135 * usecs conversion is slow so we try to delay the conversion
136 * as long as possible:
138 T0
= data
->preempt_timestamp
;
139 T1
= ftrace_now(cpu
);
142 local_save_flags(flags
);
144 if (!report_latency(delta
))
147 spin_lock_irqsave(&max_trace_lock
, flags
);
149 /* check if we are still the max latency */
150 if (!report_latency(delta
))
153 trace_function(tr
, data
, CALLER_ADDR0
, parent_ip
, flags
);
155 latency
= nsecs_to_usecs(delta
);
157 if (data
->critical_sequence
!= max_sequence
)
160 tracing_max_latency
= delta
;
161 t0
= nsecs_to_usecs(T0
);
162 t1
= nsecs_to_usecs(T1
);
164 data
->critical_end
= parent_ip
;
166 update_max_tr_single(tr
, current
, cpu
);
168 if (tracing_thresh
) {
169 printk(KERN_INFO
"(%16s-%-5d|#%d):"
170 " %lu us critical section violates %lu us threshold.\n",
171 current
->comm
, current
->pid
,
172 raw_smp_processor_id(),
173 latency
, nsecs_to_usecs(tracing_thresh
));
175 printk(KERN_INFO
"(%16s-%-5d|#%d):"
176 " new %lu us maximum-latency critical section.\n",
177 current
->comm
, current
->pid
,
178 raw_smp_processor_id(),
185 spin_unlock_irqrestore(&max_trace_lock
, flags
);
188 data
->critical_sequence
= max_sequence
;
189 data
->preempt_timestamp
= ftrace_now(cpu
);
191 trace_function(tr
, data
, CALLER_ADDR0
, parent_ip
, flags
);
194 static inline void notrace
195 start_critical_timing(unsigned long ip
, unsigned long parent_ip
)
198 struct trace_array
*tr
= irqsoff_trace
;
199 struct trace_array_cpu
*data
;
202 if (likely(!tracer_enabled
))
205 if (__get_cpu_var(tracing_cpu
))
208 cpu
= raw_smp_processor_id();
209 data
= tr
->data
[cpu
];
211 if (unlikely(!data
) || unlikely(!head_page(data
)) ||
212 atomic_read(&data
->disabled
))
215 atomic_inc(&data
->disabled
);
217 data
->critical_sequence
= max_sequence
;
218 data
->preempt_timestamp
= ftrace_now(cpu
);
219 data
->critical_start
= parent_ip
? : ip
;
222 local_save_flags(flags
);
224 trace_function(tr
, data
, ip
, parent_ip
, flags
);
226 __get_cpu_var(tracing_cpu
) = 1;
228 atomic_dec(&data
->disabled
);
231 static inline void notrace
232 stop_critical_timing(unsigned long ip
, unsigned long parent_ip
)
235 struct trace_array
*tr
= irqsoff_trace
;
236 struct trace_array_cpu
*data
;
239 /* Always clear the tracing cpu on stopping the trace */
240 if (unlikely(__get_cpu_var(tracing_cpu
)))
241 __get_cpu_var(tracing_cpu
) = 0;
248 cpu
= raw_smp_processor_id();
249 data
= tr
->data
[cpu
];
251 if (unlikely(!data
) || unlikely(!head_page(data
)) ||
252 !data
->critical_start
|| atomic_read(&data
->disabled
))
255 atomic_inc(&data
->disabled
);
256 local_save_flags(flags
);
257 trace_function(tr
, data
, ip
, parent_ip
, flags
);
258 check_critical_timing(tr
, data
, parent_ip
? : ip
, cpu
);
259 data
->critical_start
= 0;
260 atomic_dec(&data
->disabled
);
263 /* start and stop critical timings used to for stoppage (in idle) */
264 void notrace
start_critical_timings(void)
266 if (preempt_trace() || irq_trace())
267 start_critical_timing(CALLER_ADDR0
, CALLER_ADDR1
);
270 void notrace
stop_critical_timings(void)
272 if (preempt_trace() || irq_trace())
273 stop_critical_timing(CALLER_ADDR0
, CALLER_ADDR1
);
276 #ifdef CONFIG_IRQSOFF_TRACER
277 #ifdef CONFIG_PROVE_LOCKING
278 void notrace
time_hardirqs_on(unsigned long a0
, unsigned long a1
)
280 if (!preempt_trace() && irq_trace())
281 stop_critical_timing(a0
, a1
);
284 void notrace
time_hardirqs_off(unsigned long a0
, unsigned long a1
)
286 if (!preempt_trace() && irq_trace())
287 start_critical_timing(a0
, a1
);
290 #else /* !CONFIG_PROVE_LOCKING */
296 void early_boot_irqs_off(void)
300 void early_boot_irqs_on(void)
304 void trace_softirqs_on(unsigned long ip
)
308 void trace_softirqs_off(unsigned long ip
)
312 inline void print_irqtrace_events(struct task_struct
*curr
)
317 * We are only interested in hardirq on/off events:
319 void notrace
trace_hardirqs_on(void)
321 if (!preempt_trace() && irq_trace())
322 stop_critical_timing(CALLER_ADDR0
, CALLER_ADDR1
);
324 EXPORT_SYMBOL(trace_hardirqs_on
);
326 void notrace
trace_hardirqs_off(void)
328 if (!preempt_trace() && irq_trace())
329 start_critical_timing(CALLER_ADDR0
, CALLER_ADDR1
);
331 EXPORT_SYMBOL(trace_hardirqs_off
);
333 void notrace
trace_hardirqs_on_caller(unsigned long caller_addr
)
335 if (!preempt_trace() && irq_trace())
336 stop_critical_timing(CALLER_ADDR0
, caller_addr
);
338 EXPORT_SYMBOL(trace_hardirqs_on_caller
);
340 void notrace
trace_hardirqs_off_caller(unsigned long caller_addr
)
342 if (!preempt_trace() && irq_trace())
343 start_critical_timing(CALLER_ADDR0
, caller_addr
);
345 EXPORT_SYMBOL(trace_hardirqs_off_caller
);
347 #endif /* CONFIG_PROVE_LOCKING */
348 #endif /* CONFIG_IRQSOFF_TRACER */
350 #ifdef CONFIG_PREEMPT_TRACER
351 void notrace
trace_preempt_on(unsigned long a0
, unsigned long a1
)
353 stop_critical_timing(a0
, a1
);
356 void notrace
trace_preempt_off(unsigned long a0
, unsigned long a1
)
358 start_critical_timing(a0
, a1
);
360 #endif /* CONFIG_PREEMPT_TRACER */
362 static void start_irqsoff_tracer(struct trace_array
*tr
)
364 register_ftrace_function(&trace_ops
);
368 static void stop_irqsoff_tracer(struct trace_array
*tr
)
371 unregister_ftrace_function(&trace_ops
);
374 static void __irqsoff_tracer_init(struct trace_array
*tr
)
377 /* make sure that the tracer is visibel */
381 start_irqsoff_tracer(tr
);
384 static void irqsoff_tracer_reset(struct trace_array
*tr
)
387 stop_irqsoff_tracer(tr
);
390 static void irqsoff_tracer_ctrl_update(struct trace_array
*tr
)
393 start_irqsoff_tracer(tr
);
395 stop_irqsoff_tracer(tr
);
398 static void notrace
irqsoff_tracer_open(struct trace_iterator
*iter
)
400 /* stop the trace while dumping */
402 stop_irqsoff_tracer(iter
->tr
);
405 static void notrace
irqsoff_tracer_close(struct trace_iterator
*iter
)
408 start_irqsoff_tracer(iter
->tr
);
411 #ifdef CONFIG_IRQSOFF_TRACER
412 static void irqsoff_tracer_init(struct trace_array
*tr
)
414 trace_type
= TRACER_IRQS_OFF
;
416 __irqsoff_tracer_init(tr
);
418 static struct tracer irqsoff_tracer __read_mostly
=
421 .init
= irqsoff_tracer_init
,
422 .reset
= irqsoff_tracer_reset
,
423 .open
= irqsoff_tracer_open
,
424 .close
= irqsoff_tracer_close
,
425 .ctrl_update
= irqsoff_tracer_ctrl_update
,
427 #ifdef CONFIG_FTRACE_SELFTEST
428 .selftest
= trace_selftest_startup_irqsoff
,
431 # define register_irqsoff(trace) register_tracer(&trace)
433 # define register_irqsoff(trace) do { } while (0)
436 #ifdef CONFIG_PREEMPT_TRACER
437 static void preemptoff_tracer_init(struct trace_array
*tr
)
439 trace_type
= TRACER_PREEMPT_OFF
;
441 __irqsoff_tracer_init(tr
);
444 static struct tracer preemptoff_tracer __read_mostly
=
446 .name
= "preemptoff",
447 .init
= preemptoff_tracer_init
,
448 .reset
= irqsoff_tracer_reset
,
449 .open
= irqsoff_tracer_open
,
450 .close
= irqsoff_tracer_close
,
451 .ctrl_update
= irqsoff_tracer_ctrl_update
,
453 #ifdef CONFIG_FTRACE_SELFTEST
454 .selftest
= trace_selftest_startup_preemptoff
,
457 # define register_preemptoff(trace) register_tracer(&trace)
459 # define register_preemptoff(trace) do { } while (0)
462 #if defined(CONFIG_IRQSOFF_TRACER) && \
463 defined(CONFIG_PREEMPT_TRACER)
465 static void preemptirqsoff_tracer_init(struct trace_array
*tr
)
467 trace_type
= TRACER_IRQS_OFF
| TRACER_PREEMPT_OFF
;
469 __irqsoff_tracer_init(tr
);
472 static struct tracer preemptirqsoff_tracer __read_mostly
=
474 .name
= "preemptirqsoff",
475 .init
= preemptirqsoff_tracer_init
,
476 .reset
= irqsoff_tracer_reset
,
477 .open
= irqsoff_tracer_open
,
478 .close
= irqsoff_tracer_close
,
479 .ctrl_update
= irqsoff_tracer_ctrl_update
,
481 #ifdef CONFIG_FTRACE_SELFTEST
482 .selftest
= trace_selftest_startup_preemptirqsoff
,
486 # define register_preemptirqsoff(trace) register_tracer(&trace)
488 # define register_preemptirqsoff(trace) do { } while (0)
491 __init
static int init_irqsoff_tracer(void)
493 register_irqsoff(irqsoff_tracer
);
494 register_preemptoff(preemptoff_tracer
);
495 register_preemptirqsoff(preemptirqsoff_tracer
);
499 device_initcall(init_irqsoff_tracer
);