ftrace: soft tracing stop and start
[linux-2.6-block.git] / kernel / trace / trace_irqsoff.c
CommitLineData
81d68a96
SR
1/*
2 * trace irqs off criticall timings
3 *
4 * Copyright (C) 2007-2008 Steven Rostedt <srostedt@redhat.com>
5 * Copyright (C) 2008 Ingo Molnar <mingo@redhat.com>
6 *
7 * From code in the latency_tracer, that is:
8 *
9 * Copyright (C) 2004-2006 Ingo Molnar
10 * Copyright (C) 2004 William Lee Irwin III
11 */
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>
17#include <linux/fs.h>
18
19#include "trace.h"
20
21static struct trace_array *irqsoff_trace __read_mostly;
22static int tracer_enabled __read_mostly;
23
6cd8a4bb
SR
24static DEFINE_PER_CPU(int, tracing_cpu);
25
89b2f978
SR
26static DEFINE_SPINLOCK(max_trace_lock);
27
6cd8a4bb
SR
28enum {
29 TRACER_IRQS_OFF = (1 << 1),
30 TRACER_PREEMPT_OFF = (1 << 2),
31};
32
33static int trace_type __read_mostly;
34
35#ifdef CONFIG_PREEMPT_TRACER
e309b41d 36static inline int
6cd8a4bb
SR
37preempt_trace(void)
38{
39 return ((trace_type & TRACER_PREEMPT_OFF) && preempt_count());
40}
41#else
42# define preempt_trace() (0)
43#endif
44
45#ifdef CONFIG_IRQSOFF_TRACER
e309b41d 46static inline int
6cd8a4bb
SR
47irq_trace(void)
48{
49 return ((trace_type & TRACER_IRQS_OFF) &&
50 irqs_disabled());
51}
52#else
53# define irq_trace() (0)
54#endif
55
81d68a96
SR
56/*
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:
63 */
64static __cacheline_aligned_in_smp unsigned long max_sequence;
65
606576ce 66#ifdef CONFIG_FUNCTION_TRACER
81d68a96
SR
67/*
68 * irqsoff uses its own tracer function to keep the overhead down:
69 */
e309b41d 70static void
81d68a96
SR
71irqsoff_tracer_call(unsigned long ip, unsigned long parent_ip)
72{
73 struct trace_array *tr = irqsoff_trace;
74 struct trace_array_cpu *data;
75 unsigned long flags;
76 long disabled;
77 int cpu;
78
361943ad
SR
79 /*
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
83 * test will fail.
84 */
85 cpu = raw_smp_processor_id();
86 if (likely(!per_cpu(tracing_cpu, cpu)))
81d68a96
SR
87 return;
88
89 local_save_flags(flags);
361943ad
SR
90 /* slight chance to get a false positive on tracing_cpu */
91 if (!irqs_disabled_flags(flags))
92 return;
81d68a96 93
81d68a96
SR
94 data = tr->data[cpu];
95 disabled = atomic_inc_return(&data->disabled);
96
97 if (likely(disabled == 1))
38697053 98 trace_function(tr, data, ip, parent_ip, flags, preempt_count());
81d68a96
SR
99
100 atomic_dec(&data->disabled);
101}
102
103static struct ftrace_ops trace_ops __read_mostly =
104{
105 .func = irqsoff_tracer_call,
106};
606576ce 107#endif /* CONFIG_FUNCTION_TRACER */
81d68a96
SR
108
109/*
110 * Should this new latency be reported/recorded?
111 */
e309b41d 112static int report_latency(cycle_t delta)
81d68a96
SR
113{
114 if (tracing_thresh) {
115 if (delta < tracing_thresh)
116 return 0;
117 } else {
118 if (delta <= tracing_max_latency)
119 return 0;
120 }
121 return 1;
122}
123
e309b41d 124static void
81d68a96
SR
125check_critical_timing(struct trace_array *tr,
126 struct trace_array_cpu *data,
127 unsigned long parent_ip,
128 int cpu)
129{
130 unsigned long latency, t0, t1;
89b2f978 131 cycle_t T0, T1, delta;
81d68a96 132 unsigned long flags;
38697053 133 int pc;
81d68a96
SR
134
135 /*
136 * usecs conversion is slow so we try to delay the conversion
137 * as long as possible:
138 */
139 T0 = data->preempt_timestamp;
750ed1a4 140 T1 = ftrace_now(cpu);
81d68a96
SR
141 delta = T1-T0;
142
143 local_save_flags(flags);
144
6450c1d3
SR
145 pc = preempt_count();
146
81d68a96
SR
147 if (!report_latency(delta))
148 goto out;
149
c7aafc54 150 spin_lock_irqsave(&max_trace_lock, flags);
81d68a96 151
89b2f978
SR
152 /* check if we are still the max latency */
153 if (!report_latency(delta))
154 goto out_unlock;
155
38697053 156 trace_function(tr, data, CALLER_ADDR0, parent_ip, flags, pc);
81d68a96
SR
157
158 latency = nsecs_to_usecs(delta);
159
160 if (data->critical_sequence != max_sequence)
89b2f978 161 goto out_unlock;
81d68a96
SR
162
163 tracing_max_latency = delta;
164 t0 = nsecs_to_usecs(T0);
165 t1 = nsecs_to_usecs(T1);
166
167 data->critical_end = parent_ip;
168
169 update_max_tr_single(tr, current, cpu);
170
81d68a96
SR
171 max_sequence++;
172
89b2f978 173out_unlock:
c7aafc54 174 spin_unlock_irqrestore(&max_trace_lock, flags);
89b2f978 175
81d68a96
SR
176out:
177 data->critical_sequence = max_sequence;
750ed1a4 178 data->preempt_timestamp = ftrace_now(cpu);
3928a8a2 179 tracing_reset(tr, cpu);
38697053 180 trace_function(tr, data, CALLER_ADDR0, parent_ip, flags, pc);
81d68a96
SR
181}
182
e309b41d 183static inline void
81d68a96
SR
184start_critical_timing(unsigned long ip, unsigned long parent_ip)
185{
186 int cpu;
187 struct trace_array *tr = irqsoff_trace;
188 struct trace_array_cpu *data;
189 unsigned long flags;
190
191 if (likely(!tracer_enabled))
192 return;
193
c5f888ca
SR
194 cpu = raw_smp_processor_id();
195
196 if (per_cpu(tracing_cpu, cpu))
6cd8a4bb
SR
197 return;
198
81d68a96
SR
199 data = tr->data[cpu];
200
c5f888ca 201 if (unlikely(!data) || atomic_read(&data->disabled))
81d68a96
SR
202 return;
203
204 atomic_inc(&data->disabled);
205
206 data->critical_sequence = max_sequence;
750ed1a4 207 data->preempt_timestamp = ftrace_now(cpu);
6cd8a4bb 208 data->critical_start = parent_ip ? : ip;
3928a8a2 209 tracing_reset(tr, cpu);
81d68a96
SR
210
211 local_save_flags(flags);
6cd8a4bb 212
38697053 213 trace_function(tr, data, ip, parent_ip, flags, preempt_count());
81d68a96 214
c5f888ca 215 per_cpu(tracing_cpu, cpu) = 1;
6cd8a4bb 216
81d68a96
SR
217 atomic_dec(&data->disabled);
218}
219
e309b41d 220static inline void
81d68a96
SR
221stop_critical_timing(unsigned long ip, unsigned long parent_ip)
222{
223 int cpu;
224 struct trace_array *tr = irqsoff_trace;
225 struct trace_array_cpu *data;
226 unsigned long flags;
227
c5f888ca 228 cpu = raw_smp_processor_id();
6cd8a4bb 229 /* Always clear the tracing cpu on stopping the trace */
c5f888ca
SR
230 if (unlikely(per_cpu(tracing_cpu, cpu)))
231 per_cpu(tracing_cpu, cpu) = 0;
6cd8a4bb
SR
232 else
233 return;
234
235 if (!tracer_enabled)
81d68a96
SR
236 return;
237
81d68a96
SR
238 data = tr->data[cpu];
239
3928a8a2 240 if (unlikely(!data) ||
81d68a96
SR
241 !data->critical_start || atomic_read(&data->disabled))
242 return;
243
244 atomic_inc(&data->disabled);
c5f888ca 245
81d68a96 246 local_save_flags(flags);
38697053 247 trace_function(tr, data, ip, parent_ip, flags, preempt_count());
6cd8a4bb 248 check_critical_timing(tr, data, parent_ip ? : ip, cpu);
81d68a96
SR
249 data->critical_start = 0;
250 atomic_dec(&data->disabled);
251}
252
6cd8a4bb 253/* start and stop critical timings used to for stoppage (in idle) */
e309b41d 254void start_critical_timings(void)
81d68a96 255{
6cd8a4bb 256 if (preempt_trace() || irq_trace())
81d68a96
SR
257 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
258}
1fe37104 259EXPORT_SYMBOL_GPL(start_critical_timings);
81d68a96 260
e309b41d 261void stop_critical_timings(void)
81d68a96 262{
6cd8a4bb 263 if (preempt_trace() || irq_trace())
81d68a96
SR
264 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
265}
1fe37104 266EXPORT_SYMBOL_GPL(stop_critical_timings);
81d68a96 267
6cd8a4bb 268#ifdef CONFIG_IRQSOFF_TRACER
81d68a96 269#ifdef CONFIG_PROVE_LOCKING
e309b41d 270void time_hardirqs_on(unsigned long a0, unsigned long a1)
81d68a96 271{
6cd8a4bb 272 if (!preempt_trace() && irq_trace())
81d68a96
SR
273 stop_critical_timing(a0, a1);
274}
275
e309b41d 276void time_hardirqs_off(unsigned long a0, unsigned long a1)
81d68a96 277{
6cd8a4bb 278 if (!preempt_trace() && irq_trace())
81d68a96
SR
279 start_critical_timing(a0, a1);
280}
281
282#else /* !CONFIG_PROVE_LOCKING */
283
284/*
285 * Stubs:
286 */
287
288void early_boot_irqs_off(void)
289{
290}
291
292void early_boot_irqs_on(void)
293{
294}
295
296void trace_softirqs_on(unsigned long ip)
297{
298}
299
300void trace_softirqs_off(unsigned long ip)
301{
302}
303
e309b41d 304inline void print_irqtrace_events(struct task_struct *curr)
81d68a96
SR
305{
306}
307
308/*
309 * We are only interested in hardirq on/off events:
310 */
e309b41d 311void trace_hardirqs_on(void)
81d68a96 312{
6cd8a4bb 313 if (!preempt_trace() && irq_trace())
81d68a96
SR
314 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
315}
316EXPORT_SYMBOL(trace_hardirqs_on);
317
e309b41d 318void trace_hardirqs_off(void)
81d68a96 319{
6cd8a4bb 320 if (!preempt_trace() && irq_trace())
81d68a96
SR
321 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
322}
323EXPORT_SYMBOL(trace_hardirqs_off);
324
e309b41d 325void trace_hardirqs_on_caller(unsigned long caller_addr)
81d68a96 326{
6cd8a4bb 327 if (!preempt_trace() && irq_trace())
81d68a96
SR
328 stop_critical_timing(CALLER_ADDR0, caller_addr);
329}
330EXPORT_SYMBOL(trace_hardirqs_on_caller);
331
e309b41d 332void trace_hardirqs_off_caller(unsigned long caller_addr)
81d68a96 333{
6cd8a4bb 334 if (!preempt_trace() && irq_trace())
81d68a96
SR
335 start_critical_timing(CALLER_ADDR0, caller_addr);
336}
337EXPORT_SYMBOL(trace_hardirqs_off_caller);
338
339#endif /* CONFIG_PROVE_LOCKING */
6cd8a4bb
SR
340#endif /* CONFIG_IRQSOFF_TRACER */
341
342#ifdef CONFIG_PREEMPT_TRACER
e309b41d 343void trace_preempt_on(unsigned long a0, unsigned long a1)
6cd8a4bb 344{
1e01cb0c
SR
345 if (preempt_trace())
346 stop_critical_timing(a0, a1);
6cd8a4bb
SR
347}
348
e309b41d 349void trace_preempt_off(unsigned long a0, unsigned long a1)
6cd8a4bb 350{
1e01cb0c
SR
351 if (preempt_trace())
352 start_critical_timing(a0, a1);
6cd8a4bb
SR
353}
354#endif /* CONFIG_PREEMPT_TRACER */
81d68a96
SR
355
356static void start_irqsoff_tracer(struct trace_array *tr)
357{
81d68a96 358 register_ftrace_function(&trace_ops);
89b2f978 359 tracer_enabled = 1;
81d68a96
SR
360}
361
362static void stop_irqsoff_tracer(struct trace_array *tr)
363{
81d68a96 364 tracer_enabled = 0;
89b2f978 365 unregister_ftrace_function(&trace_ops);
81d68a96
SR
366}
367
6cd8a4bb 368static void __irqsoff_tracer_init(struct trace_array *tr)
81d68a96
SR
369{
370 irqsoff_trace = tr;
c5f888ca 371 /* make sure that the tracer is visible */
81d68a96
SR
372 smp_wmb();
373
374 if (tr->ctrl)
375 start_irqsoff_tracer(tr);
376}
377
378static void irqsoff_tracer_reset(struct trace_array *tr)
379{
380 if (tr->ctrl)
381 stop_irqsoff_tracer(tr);
382}
383
384static void irqsoff_tracer_ctrl_update(struct trace_array *tr)
385{
386 if (tr->ctrl)
387 start_irqsoff_tracer(tr);
388 else
389 stop_irqsoff_tracer(tr);
390}
391
e309b41d 392static void irqsoff_tracer_open(struct trace_iterator *iter)
81d68a96
SR
393{
394 /* stop the trace while dumping */
395 if (iter->tr->ctrl)
396 stop_irqsoff_tracer(iter->tr);
397}
398
e309b41d 399static void irqsoff_tracer_close(struct trace_iterator *iter)
81d68a96
SR
400{
401 if (iter->tr->ctrl)
402 start_irqsoff_tracer(iter->tr);
403}
404
6cd8a4bb
SR
405#ifdef CONFIG_IRQSOFF_TRACER
406static void irqsoff_tracer_init(struct trace_array *tr)
407{
408 trace_type = TRACER_IRQS_OFF;
409
410 __irqsoff_tracer_init(tr);
411}
81d68a96
SR
412static struct tracer irqsoff_tracer __read_mostly =
413{
414 .name = "irqsoff",
415 .init = irqsoff_tracer_init,
416 .reset = irqsoff_tracer_reset,
417 .open = irqsoff_tracer_open,
418 .close = irqsoff_tracer_close,
419 .ctrl_update = irqsoff_tracer_ctrl_update,
420 .print_max = 1,
60a11774
SR
421#ifdef CONFIG_FTRACE_SELFTEST
422 .selftest = trace_selftest_startup_irqsoff,
423#endif
81d68a96 424};
6cd8a4bb
SR
425# define register_irqsoff(trace) register_tracer(&trace)
426#else
427# define register_irqsoff(trace) do { } while (0)
428#endif
429
430#ifdef CONFIG_PREEMPT_TRACER
431static void preemptoff_tracer_init(struct trace_array *tr)
432{
433 trace_type = TRACER_PREEMPT_OFF;
434
435 __irqsoff_tracer_init(tr);
436}
437
438static struct tracer preemptoff_tracer __read_mostly =
439{
440 .name = "preemptoff",
441 .init = preemptoff_tracer_init,
442 .reset = irqsoff_tracer_reset,
443 .open = irqsoff_tracer_open,
444 .close = irqsoff_tracer_close,
445 .ctrl_update = irqsoff_tracer_ctrl_update,
446 .print_max = 1,
60a11774
SR
447#ifdef CONFIG_FTRACE_SELFTEST
448 .selftest = trace_selftest_startup_preemptoff,
449#endif
6cd8a4bb
SR
450};
451# define register_preemptoff(trace) register_tracer(&trace)
452#else
453# define register_preemptoff(trace) do { } while (0)
454#endif
455
456#if defined(CONFIG_IRQSOFF_TRACER) && \
457 defined(CONFIG_PREEMPT_TRACER)
458
459static void preemptirqsoff_tracer_init(struct trace_array *tr)
460{
461 trace_type = TRACER_IRQS_OFF | TRACER_PREEMPT_OFF;
462
463 __irqsoff_tracer_init(tr);
464}
465
466static struct tracer preemptirqsoff_tracer __read_mostly =
467{
468 .name = "preemptirqsoff",
469 .init = preemptirqsoff_tracer_init,
470 .reset = irqsoff_tracer_reset,
471 .open = irqsoff_tracer_open,
472 .close = irqsoff_tracer_close,
473 .ctrl_update = irqsoff_tracer_ctrl_update,
474 .print_max = 1,
60a11774
SR
475#ifdef CONFIG_FTRACE_SELFTEST
476 .selftest = trace_selftest_startup_preemptirqsoff,
477#endif
6cd8a4bb
SR
478};
479
480# define register_preemptirqsoff(trace) register_tracer(&trace)
481#else
482# define register_preemptirqsoff(trace) do { } while (0)
483#endif
81d68a96
SR
484
485__init static int init_irqsoff_tracer(void)
486{
6cd8a4bb
SR
487 register_irqsoff(irqsoff_tracer);
488 register_preemptoff(preemptoff_tracer);
489 register_preemptirqsoff(preemptirqsoff_tracer);
81d68a96
SR
490
491 return 0;
492}
493device_initcall(init_irqsoff_tracer);