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;
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 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);
171 spin_unlock_irqrestore(&max_trace_lock, flags);
174 data->critical_sequence = max_sequence;
175 data->preempt_timestamp = ftrace_now(cpu);
177 trace_function(tr, data, CALLER_ADDR0, parent_ip, flags);
181 start_critical_timing(unsigned long ip, unsigned long parent_ip)
184 struct trace_array *tr = irqsoff_trace;
185 struct trace_array_cpu *data;
188 if (likely(!tracer_enabled))
191 cpu = raw_smp_processor_id();
193 if (per_cpu(tracing_cpu, cpu))
196 data = tr->data[cpu];
198 if (unlikely(!data) || atomic_read(&data->disabled))
201 atomic_inc(&data->disabled);
203 data->critical_sequence = max_sequence;
204 data->preempt_timestamp = ftrace_now(cpu);
205 data->critical_start = parent_ip ? : ip;
208 local_save_flags(flags);
210 trace_function(tr, data, ip, parent_ip, flags);
212 per_cpu(tracing_cpu, cpu) = 1;
214 atomic_dec(&data->disabled);
218 stop_critical_timing(unsigned long ip, unsigned long parent_ip)
221 struct trace_array *tr = irqsoff_trace;
222 struct trace_array_cpu *data;
225 cpu = raw_smp_processor_id();
226 /* Always clear the tracing cpu on stopping the trace */
227 if (unlikely(per_cpu(tracing_cpu, cpu)))
228 per_cpu(tracing_cpu, cpu) = 0;
235 data = tr->data[cpu];
237 if (unlikely(!data) || unlikely(!head_page(data)) ||
238 !data->critical_start || atomic_read(&data->disabled))
241 atomic_inc(&data->disabled);
243 local_save_flags(flags);
244 trace_function(tr, data, ip, parent_ip, flags);
245 check_critical_timing(tr, data, parent_ip ? : ip, cpu);
246 data->critical_start = 0;
247 atomic_dec(&data->disabled);
250 /* start and stop critical timings used to for stoppage (in idle) */
251 void start_critical_timings(void)
253 if (preempt_trace() || irq_trace())
254 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
257 void stop_critical_timings(void)
259 if (preempt_trace() || irq_trace())
260 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
263 #ifdef CONFIG_IRQSOFF_TRACER
264 #ifdef CONFIG_PROVE_LOCKING
265 void time_hardirqs_on(unsigned long a0, unsigned long a1)
267 if (!preempt_trace() && irq_trace())
268 stop_critical_timing(a0, a1);
271 void time_hardirqs_off(unsigned long a0, unsigned long a1)
273 if (!preempt_trace() && irq_trace())
274 start_critical_timing(a0, a1);
277 #else /* !CONFIG_PROVE_LOCKING */
283 void early_boot_irqs_off(void)
287 void early_boot_irqs_on(void)
291 void trace_softirqs_on(unsigned long ip)
295 void trace_softirqs_off(unsigned long ip)
299 inline void print_irqtrace_events(struct task_struct *curr)
304 * We are only interested in hardirq on/off events:
306 void trace_hardirqs_on(void)
308 if (!preempt_trace() && irq_trace())
309 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
311 EXPORT_SYMBOL(trace_hardirqs_on);
313 void trace_hardirqs_off(void)
315 if (!preempt_trace() && irq_trace())
316 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
318 EXPORT_SYMBOL(trace_hardirqs_off);
320 void trace_hardirqs_on_caller(unsigned long caller_addr)
322 if (!preempt_trace() && irq_trace())
323 stop_critical_timing(CALLER_ADDR0, caller_addr);
325 EXPORT_SYMBOL(trace_hardirqs_on_caller);
327 void trace_hardirqs_off_caller(unsigned long caller_addr)
329 if (!preempt_trace() && irq_trace())
330 start_critical_timing(CALLER_ADDR0, caller_addr);
332 EXPORT_SYMBOL(trace_hardirqs_off_caller);
334 #endif /* CONFIG_PROVE_LOCKING */
335 #endif /* CONFIG_IRQSOFF_TRACER */
337 #ifdef CONFIG_PREEMPT_TRACER
338 void trace_preempt_on(unsigned long a0, unsigned long a1)
341 stop_critical_timing(a0, a1);
344 void trace_preempt_off(unsigned long a0, unsigned long a1)
347 start_critical_timing(a0, a1);
349 #endif /* CONFIG_PREEMPT_TRACER */
351 static void start_irqsoff_tracer(struct trace_array *tr)
353 register_ftrace_function(&trace_ops);
357 static void stop_irqsoff_tracer(struct trace_array *tr)
360 unregister_ftrace_function(&trace_ops);
363 static void __irqsoff_tracer_init(struct trace_array *tr)
366 /* make sure that the tracer is visible */
370 start_irqsoff_tracer(tr);
373 static void irqsoff_tracer_reset(struct trace_array *tr)
376 stop_irqsoff_tracer(tr);
379 static void irqsoff_tracer_ctrl_update(struct trace_array *tr)
382 start_irqsoff_tracer(tr);
384 stop_irqsoff_tracer(tr);
387 static void irqsoff_tracer_open(struct trace_iterator *iter)
389 /* stop the trace while dumping */
391 stop_irqsoff_tracer(iter->tr);
394 static void irqsoff_tracer_close(struct trace_iterator *iter)
397 start_irqsoff_tracer(iter->tr);
400 #ifdef CONFIG_IRQSOFF_TRACER
401 static void irqsoff_tracer_init(struct trace_array *tr)
403 trace_type = TRACER_IRQS_OFF;
405 __irqsoff_tracer_init(tr);
407 static struct tracer irqsoff_tracer __read_mostly =
410 .init = irqsoff_tracer_init,
411 .reset = irqsoff_tracer_reset,
412 .open = irqsoff_tracer_open,
413 .close = irqsoff_tracer_close,
414 .ctrl_update = irqsoff_tracer_ctrl_update,
416 #ifdef CONFIG_FTRACE_SELFTEST
417 .selftest = trace_selftest_startup_irqsoff,
420 # define register_irqsoff(trace) register_tracer(&trace)
422 # define register_irqsoff(trace) do { } while (0)
425 #ifdef CONFIG_PREEMPT_TRACER
426 static void preemptoff_tracer_init(struct trace_array *tr)
428 trace_type = TRACER_PREEMPT_OFF;
430 __irqsoff_tracer_init(tr);
433 static struct tracer preemptoff_tracer __read_mostly =
435 .name = "preemptoff",
436 .init = preemptoff_tracer_init,
437 .reset = irqsoff_tracer_reset,
438 .open = irqsoff_tracer_open,
439 .close = irqsoff_tracer_close,
440 .ctrl_update = irqsoff_tracer_ctrl_update,
442 #ifdef CONFIG_FTRACE_SELFTEST
443 .selftest = trace_selftest_startup_preemptoff,
446 # define register_preemptoff(trace) register_tracer(&trace)
448 # define register_preemptoff(trace) do { } while (0)
451 #if defined(CONFIG_IRQSOFF_TRACER) && \
452 defined(CONFIG_PREEMPT_TRACER)
454 static void preemptirqsoff_tracer_init(struct trace_array *tr)
456 trace_type = TRACER_IRQS_OFF | TRACER_PREEMPT_OFF;
458 __irqsoff_tracer_init(tr);
461 static struct tracer preemptirqsoff_tracer __read_mostly =
463 .name = "preemptirqsoff",
464 .init = preemptirqsoff_tracer_init,
465 .reset = irqsoff_tracer_reset,
466 .open = irqsoff_tracer_open,
467 .close = irqsoff_tracer_close,
468 .ctrl_update = irqsoff_tracer_ctrl_update,
470 #ifdef CONFIG_FTRACE_SELFTEST
471 .selftest = trace_selftest_startup_preemptirqsoff,
475 # define register_preemptirqsoff(trace) register_tracer(&trace)
477 # define register_preemptirqsoff(trace) do { } while (0)
480 __init static int init_irqsoff_tracer(void)
482 register_irqsoff(irqsoff_tracer);
483 register_preemptoff(preemptoff_tracer);
484 register_preemptirqsoff(preemptirqsoff_tracer);
488 device_initcall(init_irqsoff_tracer);