diff options
author | Ingo Molnar <mingo@elte.hu> | 2008-07-10 05:43:00 -0400 |
---|---|---|
committer | Ingo Molnar <mingo@elte.hu> | 2008-07-10 05:43:00 -0400 |
commit | bac0c9103b31c3dd83ad9d731dd9834e2ba75e4f (patch) | |
tree | 702dd6a7ce06d224d594c2293af546b11ac9f51b /kernel/trace/trace_irqsoff.c | |
parent | 6329d3021bcfa9038621e6e917d98929421d8ec8 (diff) | |
parent | 98a05ed4bd7774f533ab185fe0bf2fdc58292d7c (diff) |
Merge branch 'tracing/ftrace' into auto-ftrace-next
Diffstat (limited to 'kernel/trace/trace_irqsoff.c')
-rw-r--r-- | kernel/trace/trace_irqsoff.c | 486 |
1 files changed, 486 insertions, 0 deletions
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c new file mode 100644 index 000000000000..421d6fe3650e --- /dev/null +++ b/kernel/trace/trace_irqsoff.c | |||
@@ -0,0 +1,486 @@ | |||
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 | |||
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 | #ifdef CONFIG_PREEMPT_TRACER | ||
36 | static inline int | ||
37 | preempt_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 | ||
46 | static inline int | ||
47 | irq_trace(void) | ||
48 | { | ||
49 | return ((trace_type & TRACER_IRQS_OFF) && | ||
50 | irqs_disabled()); | ||
51 | } | ||
52 | #else | ||
53 | # define irq_trace() (0) | ||
54 | #endif | ||
55 | |||
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 | */ | ||
64 | static __cacheline_aligned_in_smp unsigned long max_sequence; | ||
65 | |||
66 | #ifdef CONFIG_FTRACE | ||
67 | /* | ||
68 | * irqsoff uses its own tracer function to keep the overhead down: | ||
69 | */ | ||
70 | static void | ||
71 | irqsoff_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 | |||
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))) | ||
87 | return; | ||
88 | |||
89 | local_save_flags(flags); | ||
90 | /* slight chance to get a false positive on tracing_cpu */ | ||
91 | if (!irqs_disabled_flags(flags)) | ||
92 | return; | ||
93 | |||
94 | data = tr->data[cpu]; | ||
95 | disabled = atomic_inc_return(&data->disabled); | ||
96 | |||
97 | if (likely(disabled == 1)) | ||
98 | trace_function(tr, data, ip, parent_ip, flags); | ||
99 | |||
100 | atomic_dec(&data->disabled); | ||
101 | } | ||
102 | |||
103 | static struct ftrace_ops trace_ops __read_mostly = | ||
104 | { | ||
105 | .func = irqsoff_tracer_call, | ||
106 | }; | ||
107 | #endif /* CONFIG_FTRACE */ | ||
108 | |||
109 | /* | ||
110 | * Should this new latency be reported/recorded? | ||
111 | */ | ||
112 | static int report_latency(cycle_t delta) | ||
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 | |||
124 | static void | ||
125 | check_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; | ||
131 | cycle_t T0, T1, delta; | ||
132 | unsigned long flags; | ||
133 | |||
134 | /* | ||
135 | * usecs conversion is slow so we try to delay the conversion | ||
136 | * as long as possible: | ||
137 | */ | ||
138 | T0 = data->preempt_timestamp; | ||
139 | T1 = ftrace_now(cpu); | ||
140 | delta = T1-T0; | ||
141 | |||
142 | local_save_flags(flags); | ||
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, data, CALLER_ADDR0, parent_ip, flags); | ||
154 | |||
155 | latency = nsecs_to_usecs(delta); | ||
156 | |||
157 | if (data->critical_sequence != max_sequence) | ||
158 | goto out_unlock; | ||
159 | |||
160 | tracing_max_latency = delta; | ||
161 | t0 = nsecs_to_usecs(T0); | ||
162 | t1 = nsecs_to_usecs(T1); | ||
163 | |||
164 | data->critical_end = parent_ip; | ||
165 | |||
166 | update_max_tr_single(tr, current, cpu); | ||
167 | |||
168 | max_sequence++; | ||
169 | |||
170 | out_unlock: | ||
171 | spin_unlock_irqrestore(&max_trace_lock, flags); | ||
172 | |||
173 | out: | ||
174 | data->critical_sequence = max_sequence; | ||
175 | data->preempt_timestamp = ftrace_now(cpu); | ||
176 | tracing_reset(data); | ||
177 | trace_function(tr, data, CALLER_ADDR0, parent_ip, flags); | ||
178 | } | ||
179 | |||
180 | static inline void | ||
181 | start_critical_timing(unsigned long ip, unsigned long parent_ip) | ||
182 | { | ||
183 | int cpu; | ||
184 | struct trace_array *tr = irqsoff_trace; | ||
185 | struct trace_array_cpu *data; | ||
186 | unsigned long flags; | ||
187 | |||
188 | if (likely(!tracer_enabled)) | ||
189 | return; | ||
190 | |||
191 | cpu = raw_smp_processor_id(); | ||
192 | |||
193 | if (per_cpu(tracing_cpu, cpu)) | ||
194 | return; | ||
195 | |||
196 | data = tr->data[cpu]; | ||
197 | |||
198 | if (unlikely(!data) || atomic_read(&data->disabled)) | ||
199 | return; | ||
200 | |||
201 | atomic_inc(&data->disabled); | ||
202 | |||
203 | data->critical_sequence = max_sequence; | ||
204 | data->preempt_timestamp = ftrace_now(cpu); | ||
205 | data->critical_start = parent_ip ? : ip; | ||
206 | tracing_reset(data); | ||
207 | |||
208 | local_save_flags(flags); | ||
209 | |||
210 | trace_function(tr, data, ip, parent_ip, flags); | ||
211 | |||
212 | per_cpu(tracing_cpu, cpu) = 1; | ||
213 | |||
214 | atomic_dec(&data->disabled); | ||
215 | } | ||
216 | |||
217 | static inline void | ||
218 | stop_critical_timing(unsigned long ip, unsigned long parent_ip) | ||
219 | { | ||
220 | int cpu; | ||
221 | struct trace_array *tr = irqsoff_trace; | ||
222 | struct trace_array_cpu *data; | ||
223 | unsigned long flags; | ||
224 | |||
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; | ||
229 | else | ||
230 | return; | ||
231 | |||
232 | if (!tracer_enabled) | ||
233 | return; | ||
234 | |||
235 | data = tr->data[cpu]; | ||
236 | |||
237 | if (unlikely(!data) || unlikely(!head_page(data)) || | ||
238 | !data->critical_start || atomic_read(&data->disabled)) | ||
239 | return; | ||
240 | |||
241 | atomic_inc(&data->disabled); | ||
242 | |||
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); | ||
248 | } | ||
249 | |||
250 | /* start and stop critical timings used to for stoppage (in idle) */ | ||
251 | void start_critical_timings(void) | ||
252 | { | ||
253 | if (preempt_trace() || irq_trace()) | ||
254 | start_critical_timing(CALLER_ADDR0, CALLER_ADDR1); | ||
255 | } | ||
256 | |||
257 | void stop_critical_timings(void) | ||
258 | { | ||
259 | if (preempt_trace() || irq_trace()) | ||
260 | stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1); | ||
261 | } | ||
262 | |||
263 | #ifdef CONFIG_IRQSOFF_TRACER | ||
264 | #ifdef CONFIG_PROVE_LOCKING | ||
265 | void time_hardirqs_on(unsigned long a0, unsigned long a1) | ||
266 | { | ||
267 | if (!preempt_trace() && irq_trace()) | ||
268 | stop_critical_timing(a0, a1); | ||
269 | } | ||
270 | |||
271 | void time_hardirqs_off(unsigned long a0, unsigned long a1) | ||
272 | { | ||
273 | if (!preempt_trace() && irq_trace()) | ||
274 | start_critical_timing(a0, a1); | ||
275 | } | ||
276 | |||
277 | #else /* !CONFIG_PROVE_LOCKING */ | ||
278 | |||
279 | /* | ||
280 | * Stubs: | ||
281 | */ | ||
282 | |||
283 | void early_boot_irqs_off(void) | ||
284 | { | ||
285 | } | ||
286 | |||
287 | void early_boot_irqs_on(void) | ||
288 | { | ||
289 | } | ||
290 | |||
291 | void trace_softirqs_on(unsigned long ip) | ||
292 | { | ||
293 | } | ||
294 | |||
295 | void trace_softirqs_off(unsigned long ip) | ||
296 | { | ||
297 | } | ||
298 | |||
299 | inline void print_irqtrace_events(struct task_struct *curr) | ||
300 | { | ||
301 | } | ||
302 | |||
303 | /* | ||
304 | * We are only interested in hardirq on/off events: | ||
305 | */ | ||
306 | void trace_hardirqs_on(void) | ||
307 | { | ||
308 | if (!preempt_trace() && irq_trace()) | ||
309 | stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1); | ||
310 | } | ||
311 | EXPORT_SYMBOL(trace_hardirqs_on); | ||
312 | |||
313 | void trace_hardirqs_off(void) | ||
314 | { | ||
315 | if (!preempt_trace() && irq_trace()) | ||
316 | start_critical_timing(CALLER_ADDR0, CALLER_ADDR1); | ||
317 | } | ||
318 | EXPORT_SYMBOL(trace_hardirqs_off); | ||
319 | |||
320 | void trace_hardirqs_on_caller(unsigned long caller_addr) | ||
321 | { | ||
322 | if (!preempt_trace() && irq_trace()) | ||
323 | stop_critical_timing(CALLER_ADDR0, caller_addr); | ||
324 | } | ||
325 | EXPORT_SYMBOL(trace_hardirqs_on_caller); | ||
326 | |||
327 | void trace_hardirqs_off_caller(unsigned long caller_addr) | ||
328 | { | ||
329 | if (!preempt_trace() && irq_trace()) | ||
330 | start_critical_timing(CALLER_ADDR0, caller_addr); | ||
331 | } | ||
332 | EXPORT_SYMBOL(trace_hardirqs_off_caller); | ||
333 | |||
334 | #endif /* CONFIG_PROVE_LOCKING */ | ||
335 | #endif /* CONFIG_IRQSOFF_TRACER */ | ||
336 | |||
337 | #ifdef CONFIG_PREEMPT_TRACER | ||
338 | void trace_preempt_on(unsigned long a0, unsigned long a1) | ||
339 | { | ||
340 | stop_critical_timing(a0, a1); | ||
341 | } | ||
342 | |||
343 | void trace_preempt_off(unsigned long a0, unsigned long a1) | ||
344 | { | ||
345 | start_critical_timing(a0, a1); | ||
346 | } | ||
347 | #endif /* CONFIG_PREEMPT_TRACER */ | ||
348 | |||
349 | static void start_irqsoff_tracer(struct trace_array *tr) | ||
350 | { | ||
351 | register_ftrace_function(&trace_ops); | ||
352 | tracer_enabled = 1; | ||
353 | } | ||
354 | |||
355 | static void stop_irqsoff_tracer(struct trace_array *tr) | ||
356 | { | ||
357 | tracer_enabled = 0; | ||
358 | unregister_ftrace_function(&trace_ops); | ||
359 | } | ||
360 | |||
361 | static void __irqsoff_tracer_init(struct trace_array *tr) | ||
362 | { | ||
363 | irqsoff_trace = tr; | ||
364 | /* make sure that the tracer is visible */ | ||
365 | smp_wmb(); | ||
366 | |||
367 | if (tr->ctrl) | ||
368 | start_irqsoff_tracer(tr); | ||
369 | } | ||
370 | |||
371 | static void irqsoff_tracer_reset(struct trace_array *tr) | ||
372 | { | ||
373 | if (tr->ctrl) | ||
374 | stop_irqsoff_tracer(tr); | ||
375 | } | ||
376 | |||
377 | static void irqsoff_tracer_ctrl_update(struct trace_array *tr) | ||
378 | { | ||
379 | if (tr->ctrl) | ||
380 | start_irqsoff_tracer(tr); | ||
381 | else | ||
382 | stop_irqsoff_tracer(tr); | ||
383 | } | ||
384 | |||
385 | static void irqsoff_tracer_open(struct trace_iterator *iter) | ||
386 | { | ||
387 | /* stop the trace while dumping */ | ||
388 | if (iter->tr->ctrl) | ||
389 | stop_irqsoff_tracer(iter->tr); | ||
390 | } | ||
391 | |||
392 | static void irqsoff_tracer_close(struct trace_iterator *iter) | ||
393 | { | ||
394 | if (iter->tr->ctrl) | ||
395 | start_irqsoff_tracer(iter->tr); | ||
396 | } | ||
397 | |||
398 | #ifdef CONFIG_IRQSOFF_TRACER | ||
399 | static void irqsoff_tracer_init(struct trace_array *tr) | ||
400 | { | ||
401 | trace_type = TRACER_IRQS_OFF; | ||
402 | |||
403 | __irqsoff_tracer_init(tr); | ||
404 | } | ||
405 | static struct tracer irqsoff_tracer __read_mostly = | ||
406 | { | ||
407 | .name = "irqsoff", | ||
408 | .init = irqsoff_tracer_init, | ||
409 | .reset = irqsoff_tracer_reset, | ||
410 | .open = irqsoff_tracer_open, | ||
411 | .close = irqsoff_tracer_close, | ||
412 | .ctrl_update = irqsoff_tracer_ctrl_update, | ||
413 | .print_max = 1, | ||
414 | #ifdef CONFIG_FTRACE_SELFTEST | ||
415 | .selftest = trace_selftest_startup_irqsoff, | ||
416 | #endif | ||
417 | }; | ||
418 | # define register_irqsoff(trace) register_tracer(&trace) | ||
419 | #else | ||
420 | # define register_irqsoff(trace) do { } while (0) | ||
421 | #endif | ||
422 | |||
423 | #ifdef CONFIG_PREEMPT_TRACER | ||
424 | static void preemptoff_tracer_init(struct trace_array *tr) | ||
425 | { | ||
426 | trace_type = TRACER_PREEMPT_OFF; | ||
427 | |||
428 | __irqsoff_tracer_init(tr); | ||
429 | } | ||
430 | |||
431 | static struct tracer preemptoff_tracer __read_mostly = | ||
432 | { | ||
433 | .name = "preemptoff", | ||
434 | .init = preemptoff_tracer_init, | ||
435 | .reset = irqsoff_tracer_reset, | ||
436 | .open = irqsoff_tracer_open, | ||
437 | .close = irqsoff_tracer_close, | ||
438 | .ctrl_update = irqsoff_tracer_ctrl_update, | ||
439 | .print_max = 1, | ||
440 | #ifdef CONFIG_FTRACE_SELFTEST | ||
441 | .selftest = trace_selftest_startup_preemptoff, | ||
442 | #endif | ||
443 | }; | ||
444 | # define register_preemptoff(trace) register_tracer(&trace) | ||
445 | #else | ||
446 | # define register_preemptoff(trace) do { } while (0) | ||
447 | #endif | ||
448 | |||
449 | #if defined(CONFIG_IRQSOFF_TRACER) && \ | ||
450 | defined(CONFIG_PREEMPT_TRACER) | ||
451 | |||
452 | static void preemptirqsoff_tracer_init(struct trace_array *tr) | ||
453 | { | ||
454 | trace_type = TRACER_IRQS_OFF | TRACER_PREEMPT_OFF; | ||
455 | |||
456 | __irqsoff_tracer_init(tr); | ||
457 | } | ||
458 | |||
459 | static struct tracer preemptirqsoff_tracer __read_mostly = | ||
460 | { | ||
461 | .name = "preemptirqsoff", | ||
462 | .init = preemptirqsoff_tracer_init, | ||
463 | .reset = irqsoff_tracer_reset, | ||
464 | .open = irqsoff_tracer_open, | ||
465 | .close = irqsoff_tracer_close, | ||
466 | .ctrl_update = irqsoff_tracer_ctrl_update, | ||
467 | .print_max = 1, | ||
468 | #ifdef CONFIG_FTRACE_SELFTEST | ||
469 | .selftest = trace_selftest_startup_preemptirqsoff, | ||
470 | #endif | ||
471 | }; | ||
472 | |||
473 | # define register_preemptirqsoff(trace) register_tracer(&trace) | ||
474 | #else | ||
475 | # define register_preemptirqsoff(trace) do { } while (0) | ||
476 | #endif | ||
477 | |||
478 | __init static int init_irqsoff_tracer(void) | ||
479 | { | ||
480 | register_irqsoff(irqsoff_tracer); | ||
481 | register_preemptoff(preemptoff_tracer); | ||
482 | register_preemptirqsoff(preemptirqsoff_tracer); | ||
483 | |||
484 | return 0; | ||
485 | } | ||
486 | device_initcall(init_irqsoff_tracer); | ||