tracing: Fix uninitialized variable of tracing/trace output
[linux-2.6.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 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
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_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_lat_flag;
36
37 #ifdef CONFIG_PREEMPT_TRACER
38 static inline int
39 preempt_trace(void)
40 {
41         return ((trace_type & TRACER_PREEMPT_OFF) && preempt_count());
42 }
43 #else
44 # define preempt_trace() (0)
45 #endif
46
47 #ifdef CONFIG_IRQSOFF_TRACER
48 static inline int
49 irq_trace(void)
50 {
51         return ((trace_type & TRACER_IRQS_OFF) &&
52                 irqs_disabled());
53 }
54 #else
55 # define irq_trace() (0)
56 #endif
57
58 /*
59  * Sequence count - we record it when starting a measurement and
60  * skip the latency if the sequence has changed - some other section
61  * did a maximum and could disturb our measurement with serial console
62  * printouts, etc. Truly coinciding maximum latencies should be rare
63  * and what happens together happens separately as well, so this doesnt
64  * decrease the validity of the maximum found:
65  */
66 static __cacheline_aligned_in_smp       unsigned long max_sequence;
67
68 #ifdef CONFIG_FUNCTION_TRACER
69 /*
70  * irqsoff uses its own tracer function to keep the overhead down:
71  */
72 static void
73 irqsoff_tracer_call(unsigned long ip, unsigned long parent_ip)
74 {
75         struct trace_array *tr = irqsoff_trace;
76         struct trace_array_cpu *data;
77         unsigned long flags;
78         long disabled;
79         int cpu;
80
81         /*
82          * Does not matter if we preempt. We test the flags
83          * afterward, to see if irqs are disabled or not.
84          * If we preempt and get a false positive, the flags
85          * test will fail.
86          */
87         cpu = raw_smp_processor_id();
88         if (likely(!per_cpu(tracing_cpu, cpu)))
89                 return;
90
91         local_save_flags(flags);
92         /* slight chance to get a false positive on tracing_cpu */
93         if (!irqs_disabled_flags(flags))
94                 return;
95
96         data = tr->data[cpu];
97         disabled = atomic_inc_return(&data->disabled);
98
99         if (likely(disabled == 1))
100                 trace_function(tr, ip, parent_ip, flags, preempt_count());
101
102         atomic_dec(&data->disabled);
103 }
104
105 static struct ftrace_ops trace_ops __read_mostly =
106 {
107         .func = irqsoff_tracer_call,
108 };
109 #endif /* CONFIG_FUNCTION_TRACER */
110
111 /*
112  * Should this new latency be reported/recorded?
113  */
114 static int report_latency(cycle_t delta)
115 {
116         if (tracing_thresh) {
117                 if (delta < tracing_thresh)
118                         return 0;
119         } else {
120                 if (delta <= tracing_max_latency)
121                         return 0;
122         }
123         return 1;
124 }
125
126 static void
127 check_critical_timing(struct trace_array *tr,
128                       struct trace_array_cpu *data,
129                       unsigned long parent_ip,
130                       int cpu)
131 {
132         cycle_t T0, T1, delta;
133         unsigned long flags;
134         int pc;
135
136         T0 = data->preempt_timestamp;
137         T1 = ftrace_now(cpu);
138         delta = T1-T0;
139
140         local_save_flags(flags);
141
142         pc = preempt_count();
143
144         if (!report_latency(delta))
145                 goto out;
146
147         spin_lock_irqsave(&max_trace_lock, flags);
148
149         /* check if we are still the max latency */
150         if (!report_latency(delta))
151                 goto out_unlock;
152
153         trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
154         /* Skip 5 functions to get to the irq/preempt enable function */
155         __trace_stack(tr, flags, 5, pc);
156
157         if (data->critical_sequence != max_sequence)
158                 goto out_unlock;
159
160         data->critical_end = parent_ip;
161
162         if (likely(!is_tracing_stopped())) {
163                 tracing_max_latency = delta;
164                 update_max_tr_single(tr, current, cpu);
165         }
166
167         max_sequence++;
168
169 out_unlock:
170         spin_unlock_irqrestore(&max_trace_lock, flags);
171
172 out:
173         data->critical_sequence = max_sequence;
174         data->preempt_timestamp = ftrace_now(cpu);
175         trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc);
176 }
177
178 static inline void
179 start_critical_timing(unsigned long ip, unsigned long parent_ip)
180 {
181         int cpu;
182         struct trace_array *tr = irqsoff_trace;
183         struct trace_array_cpu *data;
184         unsigned long flags;
185
186         if (likely(!tracer_enabled))
187                 return;
188
189         cpu = raw_smp_processor_id();
190
191         if (per_cpu(tracing_cpu, cpu))
192                 return;
193
194         data = tr->data[cpu];
195
196         if (unlikely(!data) || atomic_read(&data->disabled))
197                 return;
198
199         atomic_inc(&data->disabled);
200
201         data->critical_sequence = max_sequence;
202         data->preempt_timestamp = ftrace_now(cpu);
203         data->critical_start = parent_ip ? : ip;
204
205         local_save_flags(flags);
206
207         trace_function(tr, ip, parent_ip, flags, preempt_count());
208
209         per_cpu(tracing_cpu, cpu) = 1;
210
211         atomic_dec(&data->disabled);
212 }
213
214 static inline void
215 stop_critical_timing(unsigned long ip, unsigned long parent_ip)
216 {
217         int cpu;
218         struct trace_array *tr = irqsoff_trace;
219         struct trace_array_cpu *data;
220         unsigned long flags;
221
222         cpu = raw_smp_processor_id();
223         /* Always clear the tracing cpu on stopping the trace */
224         if (unlikely(per_cpu(tracing_cpu, cpu)))
225                 per_cpu(tracing_cpu, cpu) = 0;
226         else
227                 return;
228
229         if (!tracer_enabled)
230                 return;
231
232         data = tr->data[cpu];
233
234         if (unlikely(!data) ||
235             !data->critical_start || atomic_read(&data->disabled))
236                 return;
237
238         atomic_inc(&data->disabled);
239
240         local_save_flags(flags);
241         trace_function(tr, ip, parent_ip, flags, preempt_count());
242         check_critical_timing(tr, data, parent_ip ? : ip, cpu);
243         data->critical_start = 0;
244         atomic_dec(&data->disabled);
245 }
246
247 /* start and stop critical timings used to for stoppage (in idle) */
248 void start_critical_timings(void)
249 {
250         if (preempt_trace() || irq_trace())
251                 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
252 }
253 EXPORT_SYMBOL_GPL(start_critical_timings);
254
255 void stop_critical_timings(void)
256 {
257         if (preempt_trace() || irq_trace())
258                 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
259 }
260 EXPORT_SYMBOL_GPL(stop_critical_timings);
261
262 #ifdef CONFIG_IRQSOFF_TRACER
263 #ifdef CONFIG_PROVE_LOCKING
264 void time_hardirqs_on(unsigned long a0, unsigned long a1)
265 {
266         if (!preempt_trace() && irq_trace())
267                 stop_critical_timing(a0, a1);
268 }
269
270 void time_hardirqs_off(unsigned long a0, unsigned long a1)
271 {
272         if (!preempt_trace() && irq_trace())
273                 start_critical_timing(a0, a1);
274 }
275
276 #else /* !CONFIG_PROVE_LOCKING */
277
278 /*
279  * Stubs:
280  */
281
282 void early_boot_irqs_off(void)
283 {
284 }
285
286 void early_boot_irqs_on(void)
287 {
288 }
289
290 void trace_softirqs_on(unsigned long ip)
291 {
292 }
293
294 void trace_softirqs_off(unsigned long ip)
295 {
296 }
297
298 inline void print_irqtrace_events(struct task_struct *curr)
299 {
300 }
301
302 /*
303  * We are only interested in hardirq on/off events:
304  */
305 void trace_hardirqs_on(void)
306 {
307         if (!preempt_trace() && irq_trace())
308                 stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
309 }
310 EXPORT_SYMBOL(trace_hardirqs_on);
311
312 void trace_hardirqs_off(void)
313 {
314         if (!preempt_trace() && irq_trace())
315                 start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
316 }
317 EXPORT_SYMBOL(trace_hardirqs_off);
318
319 void trace_hardirqs_on_caller(unsigned long caller_addr)
320 {
321         if (!preempt_trace() && irq_trace())
322                 stop_critical_timing(CALLER_ADDR0, caller_addr);
323 }
324 EXPORT_SYMBOL(trace_hardirqs_on_caller);
325
326 void trace_hardirqs_off_caller(unsigned long caller_addr)
327 {
328         if (!preempt_trace() && irq_trace())
329                 start_critical_timing(CALLER_ADDR0, caller_addr);
330 }
331 EXPORT_SYMBOL(trace_hardirqs_off_caller);
332
333 #endif /* CONFIG_PROVE_LOCKING */
334 #endif /*  CONFIG_IRQSOFF_TRACER */
335
336 #ifdef CONFIG_PREEMPT_TRACER
337 void trace_preempt_on(unsigned long a0, unsigned long a1)
338 {
339         if (preempt_trace())
340                 stop_critical_timing(a0, a1);
341 }
342
343 void trace_preempt_off(unsigned long a0, unsigned long a1)
344 {
345         if (preempt_trace())
346                 start_critical_timing(a0, a1);
347 }
348 #endif /* CONFIG_PREEMPT_TRACER */
349
350 static void start_irqsoff_tracer(struct trace_array *tr)
351 {
352         register_ftrace_function(&trace_ops);
353         if (tracing_is_enabled())
354                 tracer_enabled = 1;
355         else
356                 tracer_enabled = 0;
357 }
358
359 static void stop_irqsoff_tracer(struct trace_array *tr)
360 {
361         tracer_enabled = 0;
362         unregister_ftrace_function(&trace_ops);
363 }
364
365 static void __irqsoff_tracer_init(struct trace_array *tr)
366 {
367         save_lat_flag = trace_flags & TRACE_ITER_LATENCY_FMT;
368         trace_flags |= TRACE_ITER_LATENCY_FMT;
369
370         tracing_max_latency = 0;
371         irqsoff_trace = tr;
372         /* make sure that the tracer is visible */
373         smp_wmb();
374         tracing_reset_online_cpus(tr);
375         start_irqsoff_tracer(tr);
376 }
377
378 static void irqsoff_tracer_reset(struct trace_array *tr)
379 {
380         stop_irqsoff_tracer(tr);
381
382         if (!save_lat_flag)
383                 trace_flags &= ~TRACE_ITER_LATENCY_FMT;
384 }
385
386 static void irqsoff_tracer_start(struct trace_array *tr)
387 {
388         tracer_enabled = 1;
389 }
390
391 static void irqsoff_tracer_stop(struct trace_array *tr)
392 {
393         tracer_enabled = 0;
394 }
395
396 #ifdef CONFIG_IRQSOFF_TRACER
397 static int irqsoff_tracer_init(struct trace_array *tr)
398 {
399         trace_type = TRACER_IRQS_OFF;
400
401         __irqsoff_tracer_init(tr);
402         return 0;
403 }
404 static struct tracer irqsoff_tracer __read_mostly =
405 {
406         .name           = "irqsoff",
407         .init           = irqsoff_tracer_init,
408         .reset          = irqsoff_tracer_reset,
409         .start          = irqsoff_tracer_start,
410         .stop           = irqsoff_tracer_stop,
411         .print_max      = 1,
412 #ifdef CONFIG_FTRACE_SELFTEST
413         .selftest    = trace_selftest_startup_irqsoff,
414 #endif
415 };
416 # define register_irqsoff(trace) register_tracer(&trace)
417 #else
418 # define register_irqsoff(trace) do { } while (0)
419 #endif
420
421 #ifdef CONFIG_PREEMPT_TRACER
422 static int preemptoff_tracer_init(struct trace_array *tr)
423 {
424         trace_type = TRACER_PREEMPT_OFF;
425
426         __irqsoff_tracer_init(tr);
427         return 0;
428 }
429
430 static struct tracer preemptoff_tracer __read_mostly =
431 {
432         .name           = "preemptoff",
433         .init           = preemptoff_tracer_init,
434         .reset          = irqsoff_tracer_reset,
435         .start          = irqsoff_tracer_start,
436         .stop           = irqsoff_tracer_stop,
437         .print_max      = 1,
438 #ifdef CONFIG_FTRACE_SELFTEST
439         .selftest    = trace_selftest_startup_preemptoff,
440 #endif
441 };
442 # define register_preemptoff(trace) register_tracer(&trace)
443 #else
444 # define register_preemptoff(trace) do { } while (0)
445 #endif
446
447 #if defined(CONFIG_IRQSOFF_TRACER) && \
448         defined(CONFIG_PREEMPT_TRACER)
449
450 static int preemptirqsoff_tracer_init(struct trace_array *tr)
451 {
452         trace_type = TRACER_IRQS_OFF | TRACER_PREEMPT_OFF;
453
454         __irqsoff_tracer_init(tr);
455         return 0;
456 }
457
458 static struct tracer preemptirqsoff_tracer __read_mostly =
459 {
460         .name           = "preemptirqsoff",
461         .init           = preemptirqsoff_tracer_init,
462         .reset          = irqsoff_tracer_reset,
463         .start          = irqsoff_tracer_start,
464         .stop           = irqsoff_tracer_stop,
465         .print_max      = 1,
466 #ifdef CONFIG_FTRACE_SELFTEST
467         .selftest    = trace_selftest_startup_preemptirqsoff,
468 #endif
469 };
470
471 # define register_preemptirqsoff(trace) register_tracer(&trace)
472 #else
473 # define register_preemptirqsoff(trace) do { } while (0)
474 #endif
475
476 __init static int init_irqsoff_tracer(void)
477 {
478         register_irqsoff(irqsoff_tracer);
479         register_preemptoff(preemptoff_tracer);
480         register_preemptirqsoff(preemptirqsoff_tracer);
481
482         return 0;
483 }
484 device_initcall(init_irqsoff_tracer);