blob: e303ccb62cdfb1284847864821d63a72694ca6af [file] [log] [blame]
Steven Rostedt352ad252008-05-12 21:20:42 +02001/*
2 * trace task wakeup timings
3 *
4 * Copyright (C) 2007-2008 Steven Rostedt <srostedt@redhat.com>
5 * Copyright (C) 2008 Ingo Molnar <mingo@redhat.com>
6 *
7 * Based on code from 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/module.h>
13#include <linux/fs.h>
14#include <linux/debugfs.h>
15#include <linux/kallsyms.h>
16#include <linux/uaccess.h>
17#include <linux/ftrace.h>
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +020018#include <linux/marker.h>
Steven Rostedt352ad252008-05-12 21:20:42 +020019
20#include "trace.h"
21
22static struct trace_array *wakeup_trace;
23static int __read_mostly tracer_enabled;
24
25static struct task_struct *wakeup_task;
26static int wakeup_cpu;
27static unsigned wakeup_prio = -1;
28
Steven Rostedte59494f2008-07-16 00:13:45 -040029static raw_spinlock_t wakeup_lock =
30 (raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED;
Steven Rostedt352ad252008-05-12 21:20:42 +020031
Ingo Molnare309b412008-05-12 21:20:51 +020032static void __wakeup_reset(struct trace_array *tr);
Steven Rostedt352ad252008-05-12 21:20:42 +020033
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040034#ifdef CONFIG_FTRACE
35/*
36 * irqsoff uses its own tracer function to keep the overhead down:
37 */
38static void
39wakeup_tracer_call(unsigned long ip, unsigned long parent_ip)
40{
41 struct trace_array *tr = wakeup_trace;
42 struct trace_array_cpu *data;
43 unsigned long flags;
44 long disabled;
45 int resched;
46 int cpu;
47
48 if (likely(!wakeup_task))
49 return;
50
51 resched = need_resched();
52 preempt_disable_notrace();
53
54 cpu = raw_smp_processor_id();
55 data = tr->data[cpu];
56 disabled = atomic_inc_return(&data->disabled);
57 if (unlikely(disabled != 1))
58 goto out;
59
Steven Rostedte59494f2008-07-16 00:13:45 -040060 local_irq_save(flags);
61 __raw_spin_lock(&wakeup_lock);
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040062
63 if (unlikely(!wakeup_task))
64 goto unlock;
65
66 /*
67 * The task can't disappear because it needs to
68 * wake up first, and we have the wakeup_lock.
69 */
70 if (task_cpu(wakeup_task) != cpu)
71 goto unlock;
72
73 trace_function(tr, data, ip, parent_ip, flags);
74
75 unlock:
Steven Rostedte59494f2008-07-16 00:13:45 -040076 __raw_spin_unlock(&wakeup_lock);
77 local_irq_restore(flags);
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040078
79 out:
80 atomic_dec(&data->disabled);
81
82 /*
83 * To prevent recursion from the scheduler, if the
84 * resched flag was set before we entered, then
85 * don't reschedule.
86 */
87 if (resched)
88 preempt_enable_no_resched_notrace();
89 else
90 preempt_enable_notrace();
91}
92
93static struct ftrace_ops trace_ops __read_mostly =
94{
95 .func = wakeup_tracer_call,
96};
97#endif /* CONFIG_FTRACE */
98
Steven Rostedt352ad252008-05-12 21:20:42 +020099/*
100 * Should this new latency be reported/recorded?
101 */
Ingo Molnare309b412008-05-12 21:20:51 +0200102static int report_latency(cycle_t delta)
Steven Rostedt352ad252008-05-12 21:20:42 +0200103{
104 if (tracing_thresh) {
105 if (delta < tracing_thresh)
106 return 0;
107 } else {
108 if (delta <= tracing_max_latency)
109 return 0;
110 }
111 return 1;
112}
113
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200114static void notrace
115wakeup_sched_switch(void *private, void *rq, struct task_struct *prev,
116 struct task_struct *next)
Steven Rostedt352ad252008-05-12 21:20:42 +0200117{
118 unsigned long latency = 0, t0 = 0, t1 = 0;
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200119 struct trace_array **ptr = private;
120 struct trace_array *tr = *ptr;
Steven Rostedt352ad252008-05-12 21:20:42 +0200121 struct trace_array_cpu *data;
122 cycle_t T0, T1, delta;
123 unsigned long flags;
124 long disabled;
125 int cpu;
126
127 if (unlikely(!tracer_enabled))
128 return;
129
130 /*
131 * When we start a new trace, we set wakeup_task to NULL
132 * and then set tracer_enabled = 1. We want to make sure
133 * that another CPU does not see the tracer_enabled = 1
134 * and the wakeup_task with an older task, that might
135 * actually be the same as next.
136 */
137 smp_rmb();
138
139 if (next != wakeup_task)
140 return;
141
Steven Rostedt7e18d8e2008-05-22 00:22:19 -0400142 /* The task we are waiting for is waking up */
Steven Rostedt352ad252008-05-12 21:20:42 +0200143 data = tr->data[wakeup_cpu];
144
145 /* disable local data, not wakeup_cpu data */
146 cpu = raw_smp_processor_id();
147 disabled = atomic_inc_return(&tr->data[cpu]->disabled);
148 if (likely(disabled != 1))
149 goto out;
150
Steven Rostedte59494f2008-07-16 00:13:45 -0400151 local_irq_save(flags);
152 __raw_spin_lock(&wakeup_lock);
Steven Rostedt352ad252008-05-12 21:20:42 +0200153
154 /* We could race with grabbing wakeup_lock */
155 if (unlikely(!tracer_enabled || next != wakeup_task))
156 goto out_unlock;
157
Steven Rostedt6fb44b72008-05-12 21:20:49 +0200158 trace_function(tr, data, CALLER_ADDR1, CALLER_ADDR2, flags);
Steven Rostedt352ad252008-05-12 21:20:42 +0200159
160 /*
161 * usecs conversion is slow so we try to delay the conversion
162 * as long as possible:
163 */
164 T0 = data->preempt_timestamp;
Ingo Molnar750ed1a2008-05-12 21:20:46 +0200165 T1 = ftrace_now(cpu);
Steven Rostedt352ad252008-05-12 21:20:42 +0200166 delta = T1-T0;
167
168 if (!report_latency(delta))
169 goto out_unlock;
170
171 latency = nsecs_to_usecs(delta);
172
173 tracing_max_latency = delta;
174 t0 = nsecs_to_usecs(T0);
175 t1 = nsecs_to_usecs(T1);
176
177 update_max_tr(tr, wakeup_task, wakeup_cpu);
178
Steven Rostedt352ad252008-05-12 21:20:42 +0200179out_unlock:
180 __wakeup_reset(tr);
Steven Rostedte59494f2008-07-16 00:13:45 -0400181 __raw_spin_unlock(&wakeup_lock);
182 local_irq_restore(flags);
Steven Rostedt352ad252008-05-12 21:20:42 +0200183out:
184 atomic_dec(&tr->data[cpu]->disabled);
185}
186
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200187static notrace void
188sched_switch_callback(void *probe_data, void *call_data,
189 const char *format, va_list *args)
190{
191 struct task_struct *prev;
192 struct task_struct *next;
193 struct rq *__rq;
194
195 /* skip prev_pid %d next_pid %d prev_state %ld */
196 (void)va_arg(*args, int);
197 (void)va_arg(*args, int);
198 (void)va_arg(*args, long);
199 __rq = va_arg(*args, typeof(__rq));
200 prev = va_arg(*args, typeof(prev));
201 next = va_arg(*args, typeof(next));
202
203 tracing_record_cmdline(prev);
204
205 /*
206 * If tracer_switch_func only points to the local
207 * switch func, it still needs the ptr passed to it.
208 */
209 wakeup_sched_switch(probe_data, __rq, prev, next);
210}
211
Ingo Molnare309b412008-05-12 21:20:51 +0200212static void __wakeup_reset(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200213{
214 struct trace_array_cpu *data;
215 int cpu;
216
Steven Rostedt352ad252008-05-12 21:20:42 +0200217 for_each_possible_cpu(cpu) {
218 data = tr->data[cpu];
219 tracing_reset(data);
220 }
221
222 wakeup_cpu = -1;
223 wakeup_prio = -1;
224
225 if (wakeup_task)
226 put_task_struct(wakeup_task);
227
228 wakeup_task = NULL;
229}
230
Ingo Molnare309b412008-05-12 21:20:51 +0200231static void wakeup_reset(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200232{
233 unsigned long flags;
234
Steven Rostedte59494f2008-07-16 00:13:45 -0400235 local_irq_save(flags);
236 __raw_spin_lock(&wakeup_lock);
Steven Rostedt352ad252008-05-12 21:20:42 +0200237 __wakeup_reset(tr);
Steven Rostedte59494f2008-07-16 00:13:45 -0400238 __raw_spin_unlock(&wakeup_lock);
239 local_irq_restore(flags);
Steven Rostedt352ad252008-05-12 21:20:42 +0200240}
241
Ingo Molnare309b412008-05-12 21:20:51 +0200242static void
Steven Rostedt352ad252008-05-12 21:20:42 +0200243wakeup_check_start(struct trace_array *tr, struct task_struct *p,
244 struct task_struct *curr)
245{
246 int cpu = smp_processor_id();
247 unsigned long flags;
248 long disabled;
249
250 if (likely(!rt_task(p)) ||
251 p->prio >= wakeup_prio ||
252 p->prio >= curr->prio)
253 return;
254
255 disabled = atomic_inc_return(&tr->data[cpu]->disabled);
256 if (unlikely(disabled != 1))
257 goto out;
258
259 /* interrupts should be off from try_to_wake_up */
Steven Rostedte59494f2008-07-16 00:13:45 -0400260 __raw_spin_lock(&wakeup_lock);
Steven Rostedt352ad252008-05-12 21:20:42 +0200261
262 /* check for races. */
263 if (!tracer_enabled || p->prio >= wakeup_prio)
264 goto out_locked;
265
266 /* reset the trace */
267 __wakeup_reset(tr);
268
269 wakeup_cpu = task_cpu(p);
270 wakeup_prio = p->prio;
271
272 wakeup_task = p;
273 get_task_struct(wakeup_task);
274
275 local_save_flags(flags);
276
Ingo Molnar750ed1a2008-05-12 21:20:46 +0200277 tr->data[wakeup_cpu]->preempt_timestamp = ftrace_now(cpu);
Steven Rostedt6fb44b72008-05-12 21:20:49 +0200278 trace_function(tr, tr->data[wakeup_cpu],
279 CALLER_ADDR1, CALLER_ADDR2, flags);
Steven Rostedt352ad252008-05-12 21:20:42 +0200280
281out_locked:
Steven Rostedte59494f2008-07-16 00:13:45 -0400282 __raw_spin_unlock(&wakeup_lock);
Steven Rostedt352ad252008-05-12 21:20:42 +0200283out:
284 atomic_dec(&tr->data[cpu]->disabled);
285}
286
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200287static notrace void
288wake_up_callback(void *probe_data, void *call_data,
289 const char *format, va_list *args)
Steven Rostedt352ad252008-05-12 21:20:42 +0200290{
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200291 struct trace_array **ptr = probe_data;
292 struct trace_array *tr = *ptr;
293 struct task_struct *curr;
294 struct task_struct *task;
295 struct rq *__rq;
296
Steven Rostedt352ad252008-05-12 21:20:42 +0200297 if (likely(!tracer_enabled))
298 return;
299
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200300 /* Skip pid %d state %ld */
301 (void)va_arg(*args, int);
302 (void)va_arg(*args, long);
303 /* now get the meat: "rq %p task %p rq->curr %p" */
304 __rq = va_arg(*args, typeof(__rq));
305 task = va_arg(*args, typeof(task));
306 curr = va_arg(*args, typeof(curr));
Steven Rostedt352ad252008-05-12 21:20:42 +0200307
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200308 tracing_record_cmdline(task);
309 tracing_record_cmdline(curr);
310
311 wakeup_check_start(tr, task, curr);
Steven Rostedt352ad252008-05-12 21:20:42 +0200312}
313
Ingo Molnare309b412008-05-12 21:20:51 +0200314static void start_wakeup_tracer(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200315{
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200316 int ret;
317
318 ret = marker_probe_register("kernel_sched_wakeup",
319 "pid %d state %ld ## rq %p task %p rq->curr %p",
320 wake_up_callback,
321 &wakeup_trace);
322 if (ret) {
323 pr_info("wakeup trace: Couldn't add marker"
324 " probe to kernel_sched_wakeup\n");
325 return;
326 }
327
328 ret = marker_probe_register("kernel_sched_wakeup_new",
329 "pid %d state %ld ## rq %p task %p rq->curr %p",
330 wake_up_callback,
331 &wakeup_trace);
332 if (ret) {
333 pr_info("wakeup trace: Couldn't add marker"
334 " probe to kernel_sched_wakeup_new\n");
335 goto fail_deprobe;
336 }
337
338 ret = marker_probe_register("kernel_sched_schedule",
339 "prev_pid %d next_pid %d prev_state %ld "
340 "## rq %p prev %p next %p",
341 sched_switch_callback,
342 &wakeup_trace);
343 if (ret) {
344 pr_info("sched trace: Couldn't add marker"
345 " probe to kernel_sched_schedule\n");
346 goto fail_deprobe_wake_new;
347 }
348
Steven Rostedt352ad252008-05-12 21:20:42 +0200349 wakeup_reset(tr);
350
351 /*
352 * Don't let the tracer_enabled = 1 show up before
353 * the wakeup_task is reset. This may be overkill since
354 * wakeup_reset does a spin_unlock after setting the
355 * wakeup_task to NULL, but I want to be safe.
356 * This is a slow path anyway.
357 */
358 smp_wmb();
359
Steven Rostedt7e18d8e2008-05-22 00:22:19 -0400360 register_ftrace_function(&trace_ops);
Steven Rostedt352ad252008-05-12 21:20:42 +0200361
Steven Rostedtad591242008-07-10 20:58:13 -0400362 tracer_enabled = 1;
363
Steven Rostedt352ad252008-05-12 21:20:42 +0200364 return;
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200365fail_deprobe_wake_new:
366 marker_probe_unregister("kernel_sched_wakeup_new",
367 wake_up_callback,
368 &wakeup_trace);
369fail_deprobe:
370 marker_probe_unregister("kernel_sched_wakeup",
371 wake_up_callback,
372 &wakeup_trace);
Steven Rostedt352ad252008-05-12 21:20:42 +0200373}
374
Ingo Molnare309b412008-05-12 21:20:51 +0200375static void stop_wakeup_tracer(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200376{
377 tracer_enabled = 0;
Steven Rostedt7e18d8e2008-05-22 00:22:19 -0400378 unregister_ftrace_function(&trace_ops);
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200379 marker_probe_unregister("kernel_sched_schedule",
380 sched_switch_callback,
381 &wakeup_trace);
382 marker_probe_unregister("kernel_sched_wakeup_new",
383 wake_up_callback,
384 &wakeup_trace);
385 marker_probe_unregister("kernel_sched_wakeup",
386 wake_up_callback,
387 &wakeup_trace);
Steven Rostedt352ad252008-05-12 21:20:42 +0200388}
389
Ingo Molnare309b412008-05-12 21:20:51 +0200390static void wakeup_tracer_init(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200391{
392 wakeup_trace = tr;
393
394 if (tr->ctrl)
395 start_wakeup_tracer(tr);
396}
397
Ingo Molnare309b412008-05-12 21:20:51 +0200398static void wakeup_tracer_reset(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200399{
400 if (tr->ctrl) {
401 stop_wakeup_tracer(tr);
402 /* make sure we put back any tasks we are tracing */
403 wakeup_reset(tr);
404 }
405}
406
407static void wakeup_tracer_ctrl_update(struct trace_array *tr)
408{
409 if (tr->ctrl)
410 start_wakeup_tracer(tr);
411 else
412 stop_wakeup_tracer(tr);
413}
414
Ingo Molnare309b412008-05-12 21:20:51 +0200415static void wakeup_tracer_open(struct trace_iterator *iter)
Steven Rostedt352ad252008-05-12 21:20:42 +0200416{
417 /* stop the trace while dumping */
418 if (iter->tr->ctrl)
419 stop_wakeup_tracer(iter->tr);
420}
421
Ingo Molnare309b412008-05-12 21:20:51 +0200422static void wakeup_tracer_close(struct trace_iterator *iter)
Steven Rostedt352ad252008-05-12 21:20:42 +0200423{
424 /* forget about any processes we were recording */
425 if (iter->tr->ctrl)
426 start_wakeup_tracer(iter->tr);
427}
428
429static struct tracer wakeup_tracer __read_mostly =
430{
431 .name = "wakeup",
432 .init = wakeup_tracer_init,
433 .reset = wakeup_tracer_reset,
434 .open = wakeup_tracer_open,
435 .close = wakeup_tracer_close,
436 .ctrl_update = wakeup_tracer_ctrl_update,
437 .print_max = 1,
Steven Rostedt60a11772008-05-12 21:20:44 +0200438#ifdef CONFIG_FTRACE_SELFTEST
439 .selftest = trace_selftest_startup_wakeup,
440#endif
Steven Rostedt352ad252008-05-12 21:20:42 +0200441};
442
443__init static int init_wakeup_tracer(void)
444{
445 int ret;
446
447 ret = register_tracer(&wakeup_tracer);
448 if (ret)
449 return ret;
450
451 return 0;
452}
453device_initcall(init_wakeup_tracer);