diff options
Diffstat (limited to 'kernel/trace/trace_irqsoff.c')
-rw-r--r-- | kernel/trace/trace_irqsoff.c | 502 |
1 files changed, 502 insertions, 0 deletions
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c new file mode 100644 index 000000000000..761f3ec66c50 --- /dev/null +++ b/kernel/trace/trace_irqsoff.c | |||
@@ -0,0 +1,502 @@ | |||
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 | if (!runqueue_is_locked()) { | ||
169 | if (tracing_thresh) { | ||
170 | printk(KERN_INFO "(%16s-%-5d|#%d): %lu us critical" | ||
171 | " section violates %lu us threshold.\n", | ||
172 | current->comm, current->pid, | ||
173 | raw_smp_processor_id(), | ||
174 | latency, nsecs_to_usecs(tracing_thresh)); | ||
175 | } else { | ||
176 | printk(KERN_INFO "(%16s-%-5d|#%d): new %lu us" | ||
177 | " maximum-latency critical section.\n", | ||
178 | current->comm, current->pid, | ||
179 | raw_smp_processor_id(), | ||
180 | latency); | ||
181 | } | ||
182 | } | ||
183 | |||
184 | max_sequence++; | ||
185 | |||
186 | out_unlock: | ||
187 | spin_unlock_irqrestore(&max_trace_lock, flags); | ||
188 | |||
189 | out: | ||
190 | data->critical_sequence = max_sequence; | ||
191 | data->preempt_timestamp = ftrace_now(cpu); | ||
192 | tracing_reset(data); | ||
193 | trace_function(tr, data, CALLER_ADDR0, parent_ip, flags); | ||
194 | } | ||
195 | |||
196 | static inline void | ||
197 | start_critical_timing(unsigned long ip, unsigned long parent_ip) | ||
198 | { | ||
199 | int cpu; | ||
200 | struct trace_array *tr = irqsoff_trace; | ||
201 | struct trace_array_cpu *data; | ||
202 | unsigned long flags; | ||
203 | |||
204 | if (likely(!tracer_enabled)) | ||
205 | return; | ||
206 | |||
207 | cpu = raw_smp_processor_id(); | ||
208 | |||
209 | if (per_cpu(tracing_cpu, cpu)) | ||
210 | return; | ||
211 | |||
212 | data = tr->data[cpu]; | ||
213 | |||
214 | if (unlikely(!data) || atomic_read(&data->disabled)) | ||
215 | return; | ||
216 | |||
217 | atomic_inc(&data->disabled); | ||
218 | |||
219 | data->critical_sequence = max_sequence; | ||
220 | data->preempt_timestamp = ftrace_now(cpu); | ||
221 | data->critical_start = parent_ip ? : ip; | ||
222 | tracing_reset(data); | ||
223 | |||
224 | local_save_flags(flags); | ||
225 | |||
226 | trace_function(tr, data, ip, parent_ip, flags); | ||
227 | |||
228 | per_cpu(tracing_cpu, cpu) = 1; | ||
229 | |||
230 | atomic_dec(&data->disabled); | ||
231 | } | ||
232 | |||
233 | static inline void | ||
234 | stop_critical_timing(unsigned long ip, unsigned long parent_ip) | ||
235 | { | ||
236 | int cpu; | ||
237 | struct trace_array *tr = irqsoff_trace; | ||
238 | struct trace_array_cpu *data; | ||
239 | unsigned long flags; | ||
240 | |||
241 | cpu = raw_smp_processor_id(); | ||
242 | /* Always clear the tracing cpu on stopping the trace */ | ||
243 | if (unlikely(per_cpu(tracing_cpu, cpu))) | ||
244 | per_cpu(tracing_cpu, cpu) = 0; | ||
245 | else | ||
246 | return; | ||
247 | |||
248 | if (!tracer_enabled) | ||
249 | return; | ||
250 | |||
251 | data = tr->data[cpu]; | ||
252 | |||
253 | if (unlikely(!data) || unlikely(!head_page(data)) || | ||
254 | !data->critical_start || atomic_read(&data->disabled)) | ||
255 | return; | ||
256 | |||
257 | atomic_inc(&data->disabled); | ||
258 | |||
259 | local_save_flags(flags); | ||
260 | trace_function(tr, data, ip, parent_ip, flags); | ||
261 | check_critical_timing(tr, data, parent_ip ? : ip, cpu); | ||
262 | data->critical_start = 0; | ||
263 | atomic_dec(&data->disabled); | ||
264 | } | ||
265 | |||
266 | /* start and stop critical timings used to for stoppage (in idle) */ | ||
267 | void start_critical_timings(void) | ||
268 | { | ||
269 | if (preempt_trace() || irq_trace()) | ||
270 | start_critical_timing(CALLER_ADDR0, CALLER_ADDR1); | ||
271 | } | ||
272 | |||
273 | void stop_critical_timings(void) | ||
274 | { | ||
275 | if (preempt_trace() || irq_trace()) | ||
276 | stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1); | ||
277 | } | ||
278 | |||
279 | #ifdef CONFIG_IRQSOFF_TRACER | ||
280 | #ifdef CONFIG_PROVE_LOCKING | ||
281 | void time_hardirqs_on(unsigned long a0, unsigned long a1) | ||
282 | { | ||
283 | if (!preempt_trace() && irq_trace()) | ||
284 | stop_critical_timing(a0, a1); | ||
285 | } | ||
286 | |||
287 | void time_hardirqs_off(unsigned long a0, unsigned long a1) | ||
288 | { | ||
289 | if (!preempt_trace() && irq_trace()) | ||
290 | start_critical_timing(a0, a1); | ||
291 | } | ||
292 | |||
293 | #else /* !CONFIG_PROVE_LOCKING */ | ||
294 | |||
295 | /* | ||
296 | * Stubs: | ||
297 | */ | ||
298 | |||
299 | void early_boot_irqs_off(void) | ||
300 | { | ||
301 | } | ||
302 | |||
303 | void early_boot_irqs_on(void) | ||
304 | { | ||
305 | } | ||
306 | |||
307 | void trace_softirqs_on(unsigned long ip) | ||
308 | { | ||
309 | } | ||
310 | |||
311 | void trace_softirqs_off(unsigned long ip) | ||
312 | { | ||
313 | } | ||
314 | |||
315 | inline void print_irqtrace_events(struct task_struct *curr) | ||
316 | { | ||
317 | } | ||
318 | |||
319 | /* | ||
320 | * We are only interested in hardirq on/off events: | ||
321 | */ | ||
322 | void trace_hardirqs_on(void) | ||
323 | { | ||
324 | if (!preempt_trace() && irq_trace()) | ||
325 | stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1); | ||
326 | } | ||
327 | EXPORT_SYMBOL(trace_hardirqs_on); | ||
328 | |||
329 | void trace_hardirqs_off(void) | ||
330 | { | ||
331 | if (!preempt_trace() && irq_trace()) | ||
332 | start_critical_timing(CALLER_ADDR0, CALLER_ADDR1); | ||
333 | } | ||
334 | EXPORT_SYMBOL(trace_hardirqs_off); | ||
335 | |||
336 | void trace_hardirqs_on_caller(unsigned long caller_addr) | ||
337 | { | ||
338 | if (!preempt_trace() && irq_trace()) | ||
339 | stop_critical_timing(CALLER_ADDR0, caller_addr); | ||
340 | } | ||
341 | EXPORT_SYMBOL(trace_hardirqs_on_caller); | ||
342 | |||
343 | void trace_hardirqs_off_caller(unsigned long caller_addr) | ||
344 | { | ||
345 | if (!preempt_trace() && irq_trace()) | ||
346 | start_critical_timing(CALLER_ADDR0, caller_addr); | ||
347 | } | ||
348 | EXPORT_SYMBOL(trace_hardirqs_off_caller); | ||
349 | |||
350 | #endif /* CONFIG_PROVE_LOCKING */ | ||
351 | #endif /* CONFIG_IRQSOFF_TRACER */ | ||
352 | |||
353 | #ifdef CONFIG_PREEMPT_TRACER | ||
354 | void trace_preempt_on(unsigned long a0, unsigned long a1) | ||
355 | { | ||
356 | stop_critical_timing(a0, a1); | ||
357 | } | ||
358 | |||
359 | void trace_preempt_off(unsigned long a0, unsigned long a1) | ||
360 | { | ||
361 | start_critical_timing(a0, a1); | ||
362 | } | ||
363 | #endif /* CONFIG_PREEMPT_TRACER */ | ||
364 | |||
365 | static void start_irqsoff_tracer(struct trace_array *tr) | ||
366 | { | ||
367 | register_ftrace_function(&trace_ops); | ||
368 | tracer_enabled = 1; | ||
369 | } | ||
370 | |||
371 | static void stop_irqsoff_tracer(struct trace_array *tr) | ||
372 | { | ||
373 | tracer_enabled = 0; | ||
374 | unregister_ftrace_function(&trace_ops); | ||
375 | } | ||
376 | |||
377 | static void __irqsoff_tracer_init(struct trace_array *tr) | ||
378 | { | ||
379 | irqsoff_trace = tr; | ||
380 | /* make sure that the tracer is visible */ | ||
381 | smp_wmb(); | ||
382 | |||
383 | if (tr->ctrl) | ||
384 | start_irqsoff_tracer(tr); | ||
385 | } | ||
386 | |||
387 | static void irqsoff_tracer_reset(struct trace_array *tr) | ||
388 | { | ||
389 | if (tr->ctrl) | ||
390 | stop_irqsoff_tracer(tr); | ||
391 | } | ||
392 | |||
393 | static void irqsoff_tracer_ctrl_update(struct trace_array *tr) | ||
394 | { | ||
395 | if (tr->ctrl) | ||
396 | start_irqsoff_tracer(tr); | ||
397 | else | ||
398 | stop_irqsoff_tracer(tr); | ||
399 | } | ||
400 | |||
401 | static void irqsoff_tracer_open(struct trace_iterator *iter) | ||
402 | { | ||
403 | /* stop the trace while dumping */ | ||
404 | if (iter->tr->ctrl) | ||
405 | stop_irqsoff_tracer(iter->tr); | ||
406 | } | ||
407 | |||
408 | static void irqsoff_tracer_close(struct trace_iterator *iter) | ||
409 | { | ||
410 | if (iter->tr->ctrl) | ||
411 | start_irqsoff_tracer(iter->tr); | ||
412 | } | ||
413 | |||
414 | #ifdef CONFIG_IRQSOFF_TRACER | ||
415 | static void irqsoff_tracer_init(struct trace_array *tr) | ||
416 | { | ||
417 | trace_type = TRACER_IRQS_OFF; | ||
418 | |||
419 | __irqsoff_tracer_init(tr); | ||
420 | } | ||
421 | static struct tracer irqsoff_tracer __read_mostly = | ||
422 | { | ||
423 | .name = "irqsoff", | ||
424 | .init = irqsoff_tracer_init, | ||
425 | .reset = irqsoff_tracer_reset, | ||
426 | .open = irqsoff_tracer_open, | ||
427 | .close = irqsoff_tracer_close, | ||
428 | .ctrl_update = irqsoff_tracer_ctrl_update, | ||
429 | .print_max = 1, | ||
430 | #ifdef CONFIG_FTRACE_SELFTEST | ||
431 | .selftest = trace_selftest_startup_irqsoff, | ||
432 | #endif | ||
433 | }; | ||
434 | # define register_irqsoff(trace) register_tracer(&trace) | ||
435 | #else | ||
436 | # define register_irqsoff(trace) do { } while (0) | ||
437 | #endif | ||
438 | |||
439 | #ifdef CONFIG_PREEMPT_TRACER | ||
440 | static void preemptoff_tracer_init(struct trace_array *tr) | ||
441 | { | ||
442 | trace_type = TRACER_PREEMPT_OFF; | ||
443 | |||
444 | __irqsoff_tracer_init(tr); | ||
445 | } | ||
446 | |||
447 | static struct tracer preemptoff_tracer __read_mostly = | ||
448 | { | ||
449 | .name = "preemptoff", | ||
450 | .init = preemptoff_tracer_init, | ||
451 | .reset = irqsoff_tracer_reset, | ||
452 | .open = irqsoff_tracer_open, | ||
453 | .close = irqsoff_tracer_close, | ||
454 | .ctrl_update = irqsoff_tracer_ctrl_update, | ||
455 | .print_max = 1, | ||
456 | #ifdef CONFIG_FTRACE_SELFTEST | ||
457 | .selftest = trace_selftest_startup_preemptoff, | ||
458 | #endif | ||
459 | }; | ||
460 | # define register_preemptoff(trace) register_tracer(&trace) | ||
461 | #else | ||
462 | # define register_preemptoff(trace) do { } while (0) | ||
463 | #endif | ||
464 | |||
465 | #if defined(CONFIG_IRQSOFF_TRACER) && \ | ||
466 | defined(CONFIG_PREEMPT_TRACER) | ||
467 | |||
468 | static void preemptirqsoff_tracer_init(struct trace_array *tr) | ||
469 | { | ||
470 | trace_type = TRACER_IRQS_OFF | TRACER_PREEMPT_OFF; | ||
471 | |||
472 | __irqsoff_tracer_init(tr); | ||
473 | } | ||
474 | |||
475 | static struct tracer preemptirqsoff_tracer __read_mostly = | ||
476 | { | ||
477 | .name = "preemptirqsoff", | ||
478 | .init = preemptirqsoff_tracer_init, | ||
479 | .reset = irqsoff_tracer_reset, | ||
480 | .open = irqsoff_tracer_open, | ||
481 | .close = irqsoff_tracer_close, | ||
482 | .ctrl_update = irqsoff_tracer_ctrl_update, | ||
483 | .print_max = 1, | ||
484 | #ifdef CONFIG_FTRACE_SELFTEST | ||
485 | .selftest = trace_selftest_startup_preemptirqsoff, | ||
486 | #endif | ||
487 | }; | ||
488 | |||
489 | # define register_preemptirqsoff(trace) register_tracer(&trace) | ||
490 | #else | ||
491 | # define register_preemptirqsoff(trace) do { } while (0) | ||
492 | #endif | ||
493 | |||
494 | __init static int init_irqsoff_tracer(void) | ||
495 | { | ||
496 | register_irqsoff(irqsoff_tracer); | ||
497 | register_preemptoff(preemptoff_tracer); | ||
498 | register_preemptirqsoff(preemptirqsoff_tracer); | ||
499 | |||
500 | return 0; | ||
501 | } | ||
502 | device_initcall(init_irqsoff_tracer); | ||