Merge branch 'pm-cpuidle'
[cascardo/linux.git] / kernel / trace / trace_irqsoff.c
1 /*
2  * trace irqs off critical 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 Nadia Yvette Chambers
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
21 static struct trace_array               *irqsoff_trace __read_mostly;
22 static int                              tracer_enabled __read_mostly;
23
24 static DEFINE_PER_CPU(int, tracing_cpu);
25
26 static DEFINE_RAW_SPINLOCK(max_trace_lock);
27
28 enum {
29         TRACER_IRQS_OFF         = (1 << 1),
30         TRACER_PREEMPT_OFF      = (1 << 2),
31 };
32
33 static int trace_type __read_mostly;
34
35 static int save_flags;
36 static bool function_enabled;
37
38 static void stop_irqsoff_tracer(struct trace_array *tr, int graph);
39 static int start_irqsoff_tracer(struct trace_array *tr, int graph);
40
41 #ifdef CONFIG_PREEMPT_TRACER
42 static inline int
43 preempt_trace(void)
44 {
45         return ((trace_type & TRACER_PREEMPT_OFF) && preempt_count());
46 }
47 #else
48 # define preempt_trace() (0)
49 #endif
50
51 #ifdef CONFIG_IRQSOFF_TRACER
52 static inline int
53 irq_trace(void)
54 {
55         return ((trace_type & TRACER_IRQS_OFF) &&
56                 irqs_disabled());
57 }
58 #else
59 # define irq_trace() (0)
60 #endif
61
62 #define TRACE_DISPLAY_GRAPH     1
63
64 static struct tracer_opt trace_opts[] = {
65 #ifdef CONFIG_FUNCTION_GRAPH_TRACER
66         /* display latency trace as call graph */
67         { TRACER_OPT(display-graph, TRACE_DISPLAY_GRAPH) },
68 #endif
69         { } /* Empty entry */
70 };
71
72 static struct tracer_flags tracer_flags = {
73         .val  = 0,
74         .opts = trace_opts,
75 };
76
77 #define is_graph() (tracer_flags.val & TRACE_DISPLAY_GRAPH)
78
79 /*
80  * Sequence count - we record it when starting a measurement and
81  * skip the latency if the sequence has changed - some other section
82  * did a maximum and could disturb our measurement with serial console
83  * printouts, etc. Truly coinciding maximum latencies should be rare
84  * and what happens together happens separately as well, so this doesn't
85  * decrease the validity of the maximum found:
86  */
87 static __cacheline_aligned_in_smp       unsigned long max_sequence;
88
89 #ifdef CONFIG_FUNCTION_TRACER
90 /*
91  * Prologue for the preempt and irqs off function tracers.
92  *
93  * Returns 1 if it is OK to continue, and data->disabled is
94  *            incremented.
95  *         0 if the trace is to be ignored, and data->disabled
96  *            is kept the same.
97  *
98  * Note, this function is also used outside this ifdef but
99  *  inside the #ifdef of the function graph tracer below.
100  *  This is OK, since the function graph tracer is
101  *  dependent on the function tracer.
102  */
103 static int func_prolog_dec(struct trace_array *tr,
104                            struct trace_array_cpu **data,
105                            unsigned long *flags)
106 {
107         long disabled;
108         int cpu;
109
110         /*
111          * Does not matter if we preempt. We test the flags
112          * afterward, to see if irqs are disabled or not.
113          * If we preempt and get a false positive, the flags
114          * test will fail.
115          */
116         cpu = raw_smp_processor_id();
117         if (likely(!per_cpu(tracing_cpu, cpu)))
118                 return 0;
119
120         local_save_flags(*flags);
121         /* slight chance to get a false positive on tracing_cpu */
122         if (!irqs_disabled_flags(*flags))
123                 return 0;
124
125         *data = per_cpu_ptr(tr->trace_buffer.data, cpu);
126         disabled = atomic_inc_return(&(*data)->disabled);
127
128         if (likely(disabled == 1))
129                 return 1;
130
131         atomic_dec(&(*data)->disabled);
132
133         return 0;
134 }
135
136 /*
137  * irqsoff uses its own tracer function to keep the overhead down:
138  */
139 static void
140 irqsoff_tracer_call(unsigned long ip, unsigned long parent_ip,
141                     struct ftrace_ops *op, struct pt_regs *pt_regs)
142 {
143         struct trace_array *tr = irqsoff_trace;
144         struct trace_array_cpu *data;
145         unsigned long flags;
146
147         if (!func_prolog_dec(tr, &data, &flags))
148                 return;
149
150         trace_function(tr, ip, parent_ip, flags, preempt_count());
151
152         atomic_dec(&data->disabled);
153 }
154
155 static struct ftrace_ops trace_ops __read_mostly =
156 {
157         .func = irqsoff_tracer_call,
158         .flags = FTRACE_OPS_FL_GLOBAL | FTRACE_OPS_FL_RECURSION_SAFE,
159 };
160 #endif /* CONFIG_FUNCTION_TRACER */
161
162 #ifdef CONFIG_FUNCTION_GRAPH_TRACER
163 static int
164 irqsoff_set_flag(struct trace_array *tr, u32 old_flags, u32 bit, int set)
165 {
166         int cpu;
167
168         if (!(bit & TRACE_DISPLAY_GRAPH))
169                 return -EINVAL;
170
171         if (!(is_graph() ^ set))
172                 return 0;
173
174         stop_irqsoff_tracer(irqsoff_trace, !set);
175
176         for_each_possible_cpu(cpu)
177                 per_cpu(tracing_cpu, cpu) = 0;
178
179         tracing_max_latency = 0;
180         tracing_reset_online_cpus(&irqsoff_trace->trace_buffer);
181
182         return start_irqsoff_tracer(irqsoff_trace, set);
183 }
184
185 static int irqsoff_graph_entry(struct ftrace_graph_ent *trace)
186 {
187         struct trace_array *tr = irqsoff_trace;
188         struct trace_array_cpu *data;
189         unsigned long flags;
190         int ret;
191         int pc;
192
193         if (!func_prolog_dec(tr, &data, &flags))
194                 return 0;
195
196         pc = preempt_count();
197         ret = __trace_graph_entry(tr, trace, flags, pc);
198         atomic_dec(&data->disabled);
199
200         return ret;
201 }
202
203 static void irqsoff_graph_return(struct ftrace_graph_ret *trace)
204 {
205         struct trace_array *tr = irqsoff_trace;
206         struct trace_array_cpu *data;
207         unsigned long flags;
208         int pc;
209
210         if (!func_prolog_dec(tr, &data, &flags))
211                 return;
212
213         pc = preempt_count();
214         __trace_graph_return(tr, trace, flags, pc);
215         atomic_dec(&data->disabled);
216 }
217
218 static void irqsoff_trace_open(struct trace_iterator *iter)
219 {
220         if (is_graph())
221                 graph_trace_open(iter);
222
223 }
224
225 static void irqsoff_trace_close(struct trace_iterator *iter)
226 {
227         if (iter->private)
228                 graph_trace_close(iter);
229 }
230
231 #define GRAPH_TRACER_FLAGS (TRACE_GRAPH_PRINT_CPU | \
232                             TRACE_GRAPH_PRINT_PROC | \
233                             TRACE_GRAPH_PRINT_ABS_TIME | \
234                             TRACE_GRAPH_PRINT_DURATION)
235
236 static enum print_line_t irqsoff_print_line(struct trace_iterator *iter)
237 {
238         /*
239          * In graph mode call the graph tracer output function,
240          * otherwise go with the TRACE_FN event handler
241          */
242         if (is_graph())
243                 return print_graph_function_flags(iter, GRAPH_TRACER_FLAGS);
244
245         return TRACE_TYPE_UNHANDLED;
246 }
247
248 static void irqsoff_print_header(struct seq_file *s)
249 {
250         if (is_graph())
251                 print_graph_headers_flags(s, GRAPH_TRACER_FLAGS);
252         else
253                 trace_default_header(s);
254 }
255
256 static void
257 __trace_function(struct trace_array *tr,
258                  unsigned long ip, unsigned long parent_ip,
259                  unsigned long flags, int pc)
260 {
261         if (is_graph())
262                 trace_graph_function(tr, ip, parent_ip, flags, pc);
263         else
264                 trace_function(tr, ip, parent_ip, flags, pc);
265 }
266
267 #else
268 #define __trace_function trace_function
269
270 static int
271 irqsoff_set_flag(struct trace_array *tr, u32 old_flags, u32 bit, int set)
272 {
273         return -EINVAL;
274 }
275
276 static int irqsoff_graph_entry(struct ftrace_graph_ent *trace)
277 {
278         return -1;
279 }
280
281 static enum print_line_t irqsoff_print_line(struct trace_iterator *iter)
282 {
283         return TRACE_TYPE_UNHANDLED;
284 }
285
286 static void irqsoff_graph_return(struct ftrace_graph_ret *trace) { }
287 static void irqsoff_trace_open(struct trace_iterator *iter) { }
288 static void irqsoff_trace_close(struct trace_iterator *iter) { }
289
290 #ifdef CONFIG_FUNCTION_TRACER
291 static void irqsoff_print_header(struct seq_file *s)
292 {
293         trace_default_header(s);
294 }
295 #else
296 static void irqsoff_print_header(struct seq_file *s)
297 {
298         trace_latency_header(s);
299 }
300 #endif /* CONFIG_FUNCTION_TRACER */
301 #endif /* CONFIG_FUNCTION_GRAPH_TRACER */
302
303 /*
304  * Should this new latency be reported/recorded?
305  */
306 static int report_latency(cycle_t delta)
307 {
308         if (tracing_thresh) {
309                 if (delta < tracing_thresh)
310                         return 0;
311         } else {
312                 if (delta <= tracing_max_latency)
313                         return 0;
314         }
315         return 1;
316 }
317
318 static void
319 check_critical_timing(struct trace_array *tr,
320                       struct trace_array_cpu *data,
321                       unsigned long parent_ip,
322                       int cpu)
323 {
324         cycle_t T0, T1, delta;
325         unsigned long flags;
326         int pc;
327
328         T0 = data->preempt_timestamp;
329         T1 = ftrace_now(cpu);
330         delta = T1-T0;
331
332         local_save_flags(flags);
333
334         pc = preempt_count();
335
336         if (!report_latency(delta))
337                 goto out;
338
339         raw_spin_lock_irqsave(&max_trace_lock, flags);
340
341         /* check if we are still the max latency */
342         if (!report_latency(delta))
343                 goto out_unlock;
344
345         __trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
346         /* Skip 5 functions to get to the irq/preempt enable function */
347         __trace_stack(tr, flags, 5, pc);
348
349         if (data->critical_sequence != max_sequence)
350                 goto out_unlock;
351
352         data->critical_end = parent_ip;
353
354         if (likely(!is_tracing_stopped())) {
355                 tracing_max_latency = delta;
356                 update_max_tr_single(tr, current, cpu);
357         }
358
359         max_sequence++;
360
361 out_unlock:
362         raw_spin_unlock_irqrestore(&max_trace_lock, flags);
363
364 out:
365         data->critical_sequence = max_sequence;
366         data->preempt_timestamp = ftrace_now(cpu);
367         __trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
368 }
369
370 static inline void
371 start_critical_timing(unsigned long ip, unsigned long parent_ip)
372 {
373         int cpu;
374         struct trace_array *tr = irqsoff_trace;
375         struct trace_array_cpu *data;
376         unsigned long flags;
377
378         if (!tracer_enabled || !tracing_is_enabled())
379                 return;
380
381         cpu = raw_smp_processor_id();
382
383         if (per_cpu(tracing_cpu, cpu))
384                 return;
385
386         data = per_cpu_ptr(tr->trace_buffer.data, cpu);
387
388         if (unlikely(!data) || atomic_read(&data->disabled))
389                 return;
390
391         atomic_inc(&data->disabled);
392
393         data->critical_sequence = max_sequence;
394         data->preempt_timestamp = ftrace_now(cpu);
395         data->critical_start = parent_ip ? : ip;
396
397         local_save_flags(flags);
398
399         __trace_function(tr, ip, parent_ip, flags, preempt_count());
400
401         per_cpu(tracing_cpu, cpu) = 1;
402
403         atomic_dec(&data->disabled);
404 }
405
406 static inline void
407 stop_critical_timing(unsigned long ip, unsigned long parent_ip)
408 {
409         int cpu;
410         struct trace_array *tr = irqsoff_trace;
411         struct trace_array_cpu *data;
412         unsigned long flags;
413
414         cpu = raw_smp_processor_id();
415         /* Always clear the tracing cpu on stopping the trace */
416         if (unlikely(per_cpu(tracing_cpu, cpu)))
417                 per_cpu(tracing_cpu, cpu) = 0;
418         else
419                 return;
420
421         if (!tracer_enabled || !tracing_is_enabled())
422                 return;
423
424         data = per_cpu_ptr(tr->trace_buffer.data, cpu);
425
426         if (unlikely(!data) ||
427             !data->critical_start || atomic_read(&data->disabled))
428                 return;
429
430         atomic_inc(&data->disabled);
431
432         local_save_flags(flags);
433         __trace_function(tr, ip, parent_ip, flags, preempt_count());
434         check_critical_timing(tr, data, parent_ip ? : ip, cpu);
435         data->critical_start = 0;
436         atomic_dec(&data->disabled);
437 }
438
439 /* start and stop critical timings used to for stoppage (in idle) */
440 void start_critical_timings(void)
441 {
442         if (preempt_trace() || irq_trace())
443                 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
444 }
445 EXPORT_SYMBOL_GPL(start_critical_timings);
446
447 void stop_critical_timings(void)
448 {
449         if (preempt_trace() || irq_trace())
450                 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
451 }
452 EXPORT_SYMBOL_GPL(stop_critical_timings);
453
454 #ifdef CONFIG_IRQSOFF_TRACER
455 #ifdef CONFIG_PROVE_LOCKING
456 void time_hardirqs_on(unsigned long a0, unsigned long a1)
457 {
458         if (!preempt_trace() && irq_trace())
459                 stop_critical_timing(a0, a1);
460 }
461
462 void time_hardirqs_off(unsigned long a0, unsigned long a1)
463 {
464         if (!preempt_trace() && irq_trace())
465                 start_critical_timing(a0, a1);
466 }
467
468 #else /* !CONFIG_PROVE_LOCKING */
469
470 /*
471  * Stubs:
472  */
473
474 void trace_softirqs_on(unsigned long ip)
475 {
476 }
477
478 void trace_softirqs_off(unsigned long ip)
479 {
480 }
481
482 inline void print_irqtrace_events(struct task_struct *curr)
483 {
484 }
485
486 /*
487  * We are only interested in hardirq on/off events:
488  */
489 void trace_hardirqs_on(void)
490 {
491         if (!preempt_trace() && irq_trace())
492                 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
493 }
494 EXPORT_SYMBOL(trace_hardirqs_on);
495
496 void trace_hardirqs_off(void)
497 {
498         if (!preempt_trace() && irq_trace())
499                 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
500 }
501 EXPORT_SYMBOL(trace_hardirqs_off);
502
503 __visible void trace_hardirqs_on_caller(unsigned long caller_addr)
504 {
505         if (!preempt_trace() && irq_trace())
506                 stop_critical_timing(CALLER_ADDR0, caller_addr);
507 }
508 EXPORT_SYMBOL(trace_hardirqs_on_caller);
509
510 __visible void trace_hardirqs_off_caller(unsigned long caller_addr)
511 {
512         if (!preempt_trace() && irq_trace())
513                 start_critical_timing(CALLER_ADDR0, caller_addr);
514 }
515 EXPORT_SYMBOL(trace_hardirqs_off_caller);
516
517 #endif /* CONFIG_PROVE_LOCKING */
518 #endif /*  CONFIG_IRQSOFF_TRACER */
519
520 #ifdef CONFIG_PREEMPT_TRACER
521 void trace_preempt_on(unsigned long a0, unsigned long a1)
522 {
523         if (preempt_trace() && !irq_trace())
524                 stop_critical_timing(a0, a1);
525 }
526
527 void trace_preempt_off(unsigned long a0, unsigned long a1)
528 {
529         if (preempt_trace() && !irq_trace())
530                 start_critical_timing(a0, a1);
531 }
532 #endif /* CONFIG_PREEMPT_TRACER */
533
534 static int register_irqsoff_function(int graph, int set)
535 {
536         int ret;
537
538         /* 'set' is set if TRACE_ITER_FUNCTION is about to be set */
539         if (function_enabled || (!set && !(trace_flags & TRACE_ITER_FUNCTION)))
540                 return 0;
541
542         if (graph)
543                 ret = register_ftrace_graph(&irqsoff_graph_return,
544                                             &irqsoff_graph_entry);
545         else
546                 ret = register_ftrace_function(&trace_ops);
547
548         if (!ret)
549                 function_enabled = true;
550
551         return ret;
552 }
553
554 static void unregister_irqsoff_function(int graph)
555 {
556         if (!function_enabled)
557                 return;
558
559         if (graph)
560                 unregister_ftrace_graph();
561         else
562                 unregister_ftrace_function(&trace_ops);
563
564         function_enabled = false;
565 }
566
567 static void irqsoff_function_set(int set)
568 {
569         if (set)
570                 register_irqsoff_function(is_graph(), 1);
571         else
572                 unregister_irqsoff_function(is_graph());
573 }
574
575 static int irqsoff_flag_changed(struct trace_array *tr, u32 mask, int set)
576 {
577         struct tracer *tracer = tr->current_trace;
578
579         if (mask & TRACE_ITER_FUNCTION)
580                 irqsoff_function_set(set);
581
582         return trace_keep_overwrite(tracer, mask, set);
583 }
584
585 static int start_irqsoff_tracer(struct trace_array *tr, int graph)
586 {
587         int ret;
588
589         ret = register_irqsoff_function(graph, 0);
590
591         if (!ret && tracing_is_enabled())
592                 tracer_enabled = 1;
593         else
594                 tracer_enabled = 0;
595
596         return ret;
597 }
598
599 static void stop_irqsoff_tracer(struct trace_array *tr, int graph)
600 {
601         tracer_enabled = 0;
602
603         unregister_irqsoff_function(graph);
604 }
605
606 static void __irqsoff_tracer_init(struct trace_array *tr)
607 {
608         save_flags = trace_flags;
609
610         /* non overwrite screws up the latency tracers */
611         set_tracer_flag(tr, TRACE_ITER_OVERWRITE, 1);
612         set_tracer_flag(tr, TRACE_ITER_LATENCY_FMT, 1);
613
614         tracing_max_latency = 0;
615         irqsoff_trace = tr;
616         /* make sure that the tracer is visible */
617         smp_wmb();
618         tracing_reset_online_cpus(&tr->trace_buffer);
619
620         if (start_irqsoff_tracer(tr, is_graph()))
621                 printk(KERN_ERR "failed to start irqsoff tracer\n");
622 }
623
624 static void irqsoff_tracer_reset(struct trace_array *tr)
625 {
626         int lat_flag = save_flags & TRACE_ITER_LATENCY_FMT;
627         int overwrite_flag = save_flags & TRACE_ITER_OVERWRITE;
628
629         stop_irqsoff_tracer(tr, is_graph());
630
631         set_tracer_flag(tr, TRACE_ITER_LATENCY_FMT, lat_flag);
632         set_tracer_flag(tr, TRACE_ITER_OVERWRITE, overwrite_flag);
633 }
634
635 static void irqsoff_tracer_start(struct trace_array *tr)
636 {
637         tracer_enabled = 1;
638 }
639
640 static void irqsoff_tracer_stop(struct trace_array *tr)
641 {
642         tracer_enabled = 0;
643 }
644
645 #ifdef CONFIG_IRQSOFF_TRACER
646 static int irqsoff_tracer_init(struct trace_array *tr)
647 {
648         trace_type = TRACER_IRQS_OFF;
649
650         __irqsoff_tracer_init(tr);
651         return 0;
652 }
653 static struct tracer irqsoff_tracer __read_mostly =
654 {
655         .name           = "irqsoff",
656         .init           = irqsoff_tracer_init,
657         .reset          = irqsoff_tracer_reset,
658         .start          = irqsoff_tracer_start,
659         .stop           = irqsoff_tracer_stop,
660         .print_max      = true,
661         .print_header   = irqsoff_print_header,
662         .print_line     = irqsoff_print_line,
663         .flags          = &tracer_flags,
664         .set_flag       = irqsoff_set_flag,
665         .flag_changed   = irqsoff_flag_changed,
666 #ifdef CONFIG_FTRACE_SELFTEST
667         .selftest    = trace_selftest_startup_irqsoff,
668 #endif
669         .open           = irqsoff_trace_open,
670         .close          = irqsoff_trace_close,
671         .use_max_tr     = true,
672 };
673 # define register_irqsoff(trace) register_tracer(&trace)
674 #else
675 # define register_irqsoff(trace) do { } while (0)
676 #endif
677
678 #ifdef CONFIG_PREEMPT_TRACER
679 static int preemptoff_tracer_init(struct trace_array *tr)
680 {
681         trace_type = TRACER_PREEMPT_OFF;
682
683         __irqsoff_tracer_init(tr);
684         return 0;
685 }
686
687 static struct tracer preemptoff_tracer __read_mostly =
688 {
689         .name           = "preemptoff",
690         .init           = preemptoff_tracer_init,
691         .reset          = irqsoff_tracer_reset,
692         .start          = irqsoff_tracer_start,
693         .stop           = irqsoff_tracer_stop,
694         .print_max      = true,
695         .print_header   = irqsoff_print_header,
696         .print_line     = irqsoff_print_line,
697         .flags          = &tracer_flags,
698         .set_flag       = irqsoff_set_flag,
699         .flag_changed   = irqsoff_flag_changed,
700 #ifdef CONFIG_FTRACE_SELFTEST
701         .selftest    = trace_selftest_startup_preemptoff,
702 #endif
703         .open           = irqsoff_trace_open,
704         .close          = irqsoff_trace_close,
705         .use_max_tr     = true,
706 };
707 # define register_preemptoff(trace) register_tracer(&trace)
708 #else
709 # define register_preemptoff(trace) do { } while (0)
710 #endif
711
712 #if defined(CONFIG_IRQSOFF_TRACER) && \
713         defined(CONFIG_PREEMPT_TRACER)
714
715 static int preemptirqsoff_tracer_init(struct trace_array *tr)
716 {
717         trace_type = TRACER_IRQS_OFF | TRACER_PREEMPT_OFF;
718
719         __irqsoff_tracer_init(tr);
720         return 0;
721 }
722
723 static struct tracer preemptirqsoff_tracer __read_mostly =
724 {
725         .name           = "preemptirqsoff",
726         .init           = preemptirqsoff_tracer_init,
727         .reset          = irqsoff_tracer_reset,
728         .start          = irqsoff_tracer_start,
729         .stop           = irqsoff_tracer_stop,
730         .print_max      = true,
731         .print_header   = irqsoff_print_header,
732         .print_line     = irqsoff_print_line,
733         .flags          = &tracer_flags,
734         .set_flag       = irqsoff_set_flag,
735         .flag_changed   = irqsoff_flag_changed,
736 #ifdef CONFIG_FTRACE_SELFTEST
737         .selftest    = trace_selftest_startup_preemptirqsoff,
738 #endif
739         .open           = irqsoff_trace_open,
740         .close          = irqsoff_trace_close,
741         .use_max_tr     = true,
742 };
743
744 # define register_preemptirqsoff(trace) register_tracer(&trace)
745 #else
746 # define register_preemptirqsoff(trace) do { } while (0)
747 #endif
748
749 __init static int init_irqsoff_tracer(void)
750 {
751         register_irqsoff(irqsoff_tracer);
752         register_preemptoff(preemptoff_tracer);
753         register_preemptirqsoff(preemptirqsoff_tracer);
754
755         return 0;
756 }
757 core_initcall(init_irqsoff_tracer);