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
39 return ((trace_type & TRACER_PREEMPT_OFF) && preempt_count());
42 # define preempt_trace() (0)
45 #ifdef CONFIG_IRQSOFF_TRACER
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;
66 #ifdef CONFIG_FUNCTION_TRACER
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, preempt_count());
100 atomic_dec(&data->disabled);
103 static struct ftrace_ops trace_ops __read_mostly =
105 .func = irqsoff_tracer_call,
107 #endif /* CONFIG_FUNCTION_TRACER */
110 * Should this new latency be reported/recorded?
112 static int 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;
136 * usecs conversion is slow so we try to delay the conversion
137 * as long as possible:
139 T0 = data->preempt_timestamp;
140 T1 = ftrace_now(cpu);
143 local_save_flags(flags);
145 pc = preempt_count();
147 if (!report_latency(delta))
150 spin_lock_irqsave(&max_trace_lock, flags);
152 /* check if we are still the max latency */
153 if (!report_latency(delta))
156 trace_function(tr, data, CALLER_ADDR0, parent_ip, flags, pc);
158 latency = nsecs_to_usecs(delta);
160 if (data->critical_sequence != max_sequence)
163 tracing_max_latency = delta;
164 t0 = nsecs_to_usecs(T0);
165 t1 = nsecs_to_usecs(T1);
167 data->critical_end = parent_ip;
169 update_max_tr_single(tr, current, cpu);
174 spin_unlock_irqrestore(&max_trace_lock, flags);
177 data->critical_sequence = max_sequence;
178 data->preempt_timestamp = ftrace_now(cpu);
179 tracing_reset(tr, cpu);
180 trace_function(tr, data, CALLER_ADDR0, parent_ip, flags, pc);
184 start_critical_timing(unsigned long ip, unsigned long parent_ip)
187 struct trace_array *tr = irqsoff_trace;
188 struct trace_array_cpu *data;
191 if (likely(!tracer_enabled))
194 cpu = raw_smp_processor_id();
196 if (per_cpu(tracing_cpu, cpu))
199 data = tr->data[cpu];
201 if (unlikely(!data) || atomic_read(&data->disabled))
204 atomic_inc(&data->disabled);
206 data->critical_sequence = max_sequence;
207 data->preempt_timestamp = ftrace_now(cpu);
208 data->critical_start = parent_ip ? : ip;
209 tracing_reset(tr, cpu);
211 local_save_flags(flags);
213 trace_function(tr, data, ip, parent_ip, flags, preempt_count());
215 per_cpu(tracing_cpu, cpu) = 1;
217 atomic_dec(&data->disabled);
221 stop_critical_timing(unsigned long ip, unsigned long parent_ip)
224 struct trace_array *tr = irqsoff_trace;
225 struct trace_array_cpu *data;
228 cpu = raw_smp_processor_id();
229 /* Always clear the tracing cpu on stopping the trace */
230 if (unlikely(per_cpu(tracing_cpu, cpu)))
231 per_cpu(tracing_cpu, cpu) = 0;
238 data = tr->data[cpu];
240 if (unlikely(!data) ||
241 !data->critical_start || atomic_read(&data->disabled))
244 atomic_inc(&data->disabled);
246 local_save_flags(flags);
247 trace_function(tr, data, ip, parent_ip, flags, preempt_count());
248 check_critical_timing(tr, data, parent_ip ? : ip, cpu);
249 data->critical_start = 0;
250 atomic_dec(&data->disabled);
253 /* start and stop critical timings used to for stoppage (in idle) */
254 void start_critical_timings(void)
256 if (preempt_trace() || irq_trace())
257 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
259 EXPORT_SYMBOL_GPL(start_critical_timings);
261 void stop_critical_timings(void)
263 if (preempt_trace() || irq_trace())
264 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
266 EXPORT_SYMBOL_GPL(stop_critical_timings);
268 #ifdef CONFIG_IRQSOFF_TRACER
269 #ifdef CONFIG_PROVE_LOCKING
270 void time_hardirqs_on(unsigned long a0, unsigned long a1)
272 if (!preempt_trace() && irq_trace())
273 stop_critical_timing(a0, a1);
276 void time_hardirqs_off(unsigned long a0, unsigned long a1)
278 if (!preempt_trace() && irq_trace())
279 start_critical_timing(a0, a1);
282 #else /* !CONFIG_PROVE_LOCKING */
288 void early_boot_irqs_off(void)
292 void early_boot_irqs_on(void)
296 void trace_softirqs_on(unsigned long ip)
300 void trace_softirqs_off(unsigned long ip)
304 inline void print_irqtrace_events(struct task_struct *curr)
309 * We are only interested in hardirq on/off events:
311 void trace_hardirqs_on(void)
313 if (!preempt_trace() && irq_trace())
314 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
316 EXPORT_SYMBOL(trace_hardirqs_on);
318 void trace_hardirqs_off(void)
320 if (!preempt_trace() && irq_trace())
321 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
323 EXPORT_SYMBOL(trace_hardirqs_off);
325 void trace_hardirqs_on_caller(unsigned long caller_addr)
327 if (!preempt_trace() && irq_trace())
328 stop_critical_timing(CALLER_ADDR0, caller_addr);
330 EXPORT_SYMBOL(trace_hardirqs_on_caller);
332 void trace_hardirqs_off_caller(unsigned long caller_addr)
334 if (!preempt_trace() && irq_trace())
335 start_critical_timing(CALLER_ADDR0, caller_addr);
337 EXPORT_SYMBOL(trace_hardirqs_off_caller);
339 #endif /* CONFIG_PROVE_LOCKING */
340 #endif /* CONFIG_IRQSOFF_TRACER */
342 #ifdef CONFIG_PREEMPT_TRACER
343 void trace_preempt_on(unsigned long a0, unsigned long a1)
346 stop_critical_timing(a0, a1);
349 void trace_preempt_off(unsigned long a0, unsigned long a1)
352 start_critical_timing(a0, a1);
354 #endif /* CONFIG_PREEMPT_TRACER */
357 * save_tracer_enabled is used to save the state of the tracer_enabled
358 * variable when we disable it when we open a trace output file.
360 static int save_tracer_enabled;
362 static void start_irqsoff_tracer(struct trace_array *tr)
364 register_ftrace_function(&trace_ops);
365 if (tracing_is_enabled()) {
367 save_tracer_enabled = 1;
370 save_tracer_enabled = 0;
374 static void stop_irqsoff_tracer(struct trace_array *tr)
377 save_tracer_enabled = 0;
378 unregister_ftrace_function(&trace_ops);
381 static void __irqsoff_tracer_init(struct trace_array *tr)
384 /* make sure that the tracer is visible */
386 start_irqsoff_tracer(tr);
389 static void irqsoff_tracer_reset(struct trace_array *tr)
391 stop_irqsoff_tracer(tr);
394 static void irqsoff_tracer_start(struct trace_array *tr)
397 save_tracer_enabled = 1;
400 static void irqsoff_tracer_stop(struct trace_array *tr)
403 save_tracer_enabled = 0;
406 static void irqsoff_tracer_open(struct trace_iterator *iter)
408 /* stop the trace while dumping */
412 static void irqsoff_tracer_close(struct trace_iterator *iter)
414 /* restart tracing */
415 tracer_enabled = save_tracer_enabled;
418 #ifdef CONFIG_IRQSOFF_TRACER
419 static int irqsoff_tracer_init(struct trace_array *tr)
421 trace_type = TRACER_IRQS_OFF;
423 __irqsoff_tracer_init(tr);
426 static struct tracer irqsoff_tracer __read_mostly =
429 .init = irqsoff_tracer_init,
430 .reset = irqsoff_tracer_reset,
431 .start = irqsoff_tracer_start,
432 .stop = irqsoff_tracer_stop,
433 .open = irqsoff_tracer_open,
434 .close = irqsoff_tracer_close,
436 #ifdef CONFIG_FTRACE_SELFTEST
437 .selftest = trace_selftest_startup_irqsoff,
440 # define register_irqsoff(trace) register_tracer(&trace)
442 # define register_irqsoff(trace) do { } while (0)
445 #ifdef CONFIG_PREEMPT_TRACER
446 static int preemptoff_tracer_init(struct trace_array *tr)
448 trace_type = TRACER_PREEMPT_OFF;
450 __irqsoff_tracer_init(tr);
454 static struct tracer preemptoff_tracer __read_mostly =
456 .name = "preemptoff",
457 .init = preemptoff_tracer_init,
458 .reset = irqsoff_tracer_reset,
459 .start = irqsoff_tracer_start,
460 .stop = irqsoff_tracer_stop,
461 .open = irqsoff_tracer_open,
462 .close = irqsoff_tracer_close,
464 #ifdef CONFIG_FTRACE_SELFTEST
465 .selftest = trace_selftest_startup_preemptoff,
468 # define register_preemptoff(trace) register_tracer(&trace)
470 # define register_preemptoff(trace) do { } while (0)
473 #if defined(CONFIG_IRQSOFF_TRACER) && \
474 defined(CONFIG_PREEMPT_TRACER)
476 static int preemptirqsoff_tracer_init(struct trace_array *tr)
478 trace_type = TRACER_IRQS_OFF | TRACER_PREEMPT_OFF;
480 __irqsoff_tracer_init(tr);
484 static struct tracer preemptirqsoff_tracer __read_mostly =
486 .name = "preemptirqsoff",
487 .init = preemptirqsoff_tracer_init,
488 .reset = irqsoff_tracer_reset,
489 .start = irqsoff_tracer_start,
490 .stop = irqsoff_tracer_stop,
491 .open = irqsoff_tracer_open,
492 .close = irqsoff_tracer_close,
494 #ifdef CONFIG_FTRACE_SELFTEST
495 .selftest = trace_selftest_startup_preemptirqsoff,
499 # define register_preemptirqsoff(trace) register_tracer(&trace)
501 # define register_preemptirqsoff(trace) do { } while (0)
504 __init static int init_irqsoff_tracer(void)
506 register_irqsoff(irqsoff_tracer);
507 register_preemptoff(preemptoff_tracer);
508 register_preemptirqsoff(preemptirqsoff_tracer);
512 device_initcall(init_irqsoff_tracer);