blob: 0e73bc2ef8c55a0b8a47ffe19d7b1aad3577de2b [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>
Steven Rostedtad8d75f2009-04-14 19:39:12 -040018#include <trace/events/sched.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;
Steven Rostedt478142c32009-09-09 10:36:01 -040027static int wakeup_current_cpu;
Steven Rostedt352ad252008-05-12 21:20:42 +020028static unsigned wakeup_prio = -1;
Steven Rostedt32443512009-01-21 16:24:46 -050029static int wakeup_rt;
Steven Rostedt352ad252008-05-12 21:20:42 +020030
Thomas Gleixner445c8952009-12-02 19:49:50 +010031static arch_spinlock_t wakeup_lock =
Thomas Gleixneredc35bd2009-12-03 12:38:57 +010032 (arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED;
Steven Rostedt352ad252008-05-12 21:20:42 +020033
Ingo Molnare309b412008-05-12 21:20:51 +020034static void __wakeup_reset(struct trace_array *tr);
Steven Rostedt352ad252008-05-12 21:20:42 +020035
Steven Rostedte9d25fe2009-03-04 22:15:30 -050036static int save_lat_flag;
37
Steven Rostedt606576c2008-10-06 19:06:12 -040038#ifdef CONFIG_FUNCTION_TRACER
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040039/*
40 * irqsoff uses its own tracer function to keep the overhead down:
41 */
42static void
43wakeup_tracer_call(unsigned long ip, unsigned long parent_ip)
44{
45 struct trace_array *tr = wakeup_trace;
46 struct trace_array_cpu *data;
47 unsigned long flags;
48 long disabled;
49 int resched;
50 int cpu;
Steven Rostedt38697052008-10-01 13:14:09 -040051 int pc;
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040052
53 if (likely(!wakeup_task))
54 return;
55
Steven Rostedt38697052008-10-01 13:14:09 -040056 pc = preempt_count();
Steven Rostedt182e9f52008-11-03 23:15:56 -050057 resched = ftrace_preempt_disable();
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040058
59 cpu = raw_smp_processor_id();
Steven Rostedt478142c32009-09-09 10:36:01 -040060 if (cpu != wakeup_current_cpu)
61 goto out_enable;
62
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040063 data = tr->data[cpu];
64 disabled = atomic_inc_return(&data->disabled);
65 if (unlikely(disabled != 1))
66 goto out;
67
Steven Rostedte59494f2008-07-16 00:13:45 -040068 local_irq_save(flags);
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040069
Arnaldo Carvalho de Melo7be42152009-02-05 01:13:37 -050070 trace_function(tr, ip, parent_ip, flags, pc);
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040071
Steven Rostedte59494f2008-07-16 00:13:45 -040072 local_irq_restore(flags);
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040073
74 out:
75 atomic_dec(&data->disabled);
Steven Rostedt478142c32009-09-09 10:36:01 -040076 out_enable:
Steven Rostedt182e9f52008-11-03 23:15:56 -050077 ftrace_preempt_enable(resched);
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040078}
79
80static struct ftrace_ops trace_ops __read_mostly =
81{
82 .func = wakeup_tracer_call,
83};
Steven Rostedt606576c2008-10-06 19:06:12 -040084#endif /* CONFIG_FUNCTION_TRACER */
Steven Rostedt7e18d8e2008-05-22 00:22:19 -040085
Steven Rostedt352ad252008-05-12 21:20:42 +020086/*
87 * Should this new latency be reported/recorded?
88 */
Ingo Molnare309b412008-05-12 21:20:51 +020089static int report_latency(cycle_t delta)
Steven Rostedt352ad252008-05-12 21:20:42 +020090{
91 if (tracing_thresh) {
92 if (delta < tracing_thresh)
93 return 0;
94 } else {
95 if (delta <= tracing_max_latency)
96 return 0;
97 }
98 return 1;
99}
100
Steven Rostedt38516ab2010-04-20 17:04:50 -0400101static void
102probe_wakeup_migrate_task(void *ignore, struct task_struct *task, int cpu)
Steven Rostedt478142c32009-09-09 10:36:01 -0400103{
104 if (task != wakeup_task)
105 return;
106
107 wakeup_current_cpu = cpu;
108}
109
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200110static void notrace
Steven Rostedt38516ab2010-04-20 17:04:50 -0400111probe_wakeup_sched_switch(void *ignore,
112 struct task_struct *prev, struct task_struct *next)
Steven Rostedt352ad252008-05-12 21:20:42 +0200113{
Steven Rostedt352ad252008-05-12 21:20:42 +0200114 struct trace_array_cpu *data;
115 cycle_t T0, T1, delta;
116 unsigned long flags;
117 long disabled;
118 int cpu;
Steven Rostedt38697052008-10-01 13:14:09 -0400119 int pc;
Steven Rostedt352ad252008-05-12 21:20:42 +0200120
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400121 tracing_record_cmdline(prev);
122
Steven Rostedt352ad252008-05-12 21:20:42 +0200123 if (unlikely(!tracer_enabled))
124 return;
125
126 /*
127 * When we start a new trace, we set wakeup_task to NULL
128 * and then set tracer_enabled = 1. We want to make sure
129 * that another CPU does not see the tracer_enabled = 1
130 * and the wakeup_task with an older task, that might
131 * actually be the same as next.
132 */
133 smp_rmb();
134
135 if (next != wakeup_task)
136 return;
137
Steven Rostedt38697052008-10-01 13:14:09 -0400138 pc = preempt_count();
139
Steven Rostedt352ad252008-05-12 21:20:42 +0200140 /* disable local data, not wakeup_cpu data */
141 cpu = raw_smp_processor_id();
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400142 disabled = atomic_inc_return(&wakeup_trace->data[cpu]->disabled);
Steven Rostedt352ad252008-05-12 21:20:42 +0200143 if (likely(disabled != 1))
144 goto out;
145
Steven Rostedte59494f2008-07-16 00:13:45 -0400146 local_irq_save(flags);
Thomas Gleixner0199c4e2009-12-02 20:01:25 +0100147 arch_spin_lock(&wakeup_lock);
Steven Rostedt352ad252008-05-12 21:20:42 +0200148
149 /* We could race with grabbing wakeup_lock */
150 if (unlikely(!tracer_enabled || next != wakeup_task))
151 goto out_unlock;
152
Steven Rostedt9be24412009-03-26 10:25:24 -0400153 /* The task we are waiting for is waking up */
154 data = wakeup_trace->data[wakeup_cpu];
155
Steven Rostedt301fd742009-04-03 11:12:23 -0400156 trace_function(wakeup_trace, CALLER_ADDR0, CALLER_ADDR1, flags, pc);
Arnaldo Carvalho de Melo7be42152009-02-05 01:13:37 -0500157 tracing_sched_switch_trace(wakeup_trace, prev, next, flags, pc);
Steven Rostedt352ad252008-05-12 21:20:42 +0200158
Steven Rostedt352ad252008-05-12 21:20:42 +0200159 T0 = data->preempt_timestamp;
Ingo Molnar750ed1a2008-05-12 21:20:46 +0200160 T1 = ftrace_now(cpu);
Steven Rostedt352ad252008-05-12 21:20:42 +0200161 delta = T1-T0;
162
163 if (!report_latency(delta))
164 goto out_unlock;
165
Carsten Emdeb5130b12009-09-13 01:43:07 +0200166 if (likely(!is_tracing_stopped())) {
167 tracing_max_latency = delta;
168 update_max_tr(wakeup_trace, wakeup_task, wakeup_cpu);
169 }
Steven Rostedt352ad252008-05-12 21:20:42 +0200170
Steven Rostedt352ad252008-05-12 21:20:42 +0200171out_unlock:
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400172 __wakeup_reset(wakeup_trace);
Thomas Gleixner0199c4e2009-12-02 20:01:25 +0100173 arch_spin_unlock(&wakeup_lock);
Steven Rostedte59494f2008-07-16 00:13:45 -0400174 local_irq_restore(flags);
Steven Rostedt352ad252008-05-12 21:20:42 +0200175out:
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400176 atomic_dec(&wakeup_trace->data[cpu]->disabled);
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200177}
178
Ingo Molnare309b412008-05-12 21:20:51 +0200179static void __wakeup_reset(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200180{
Steven Rostedt352ad252008-05-12 21:20:42 +0200181 wakeup_cpu = -1;
182 wakeup_prio = -1;
183
184 if (wakeup_task)
185 put_task_struct(wakeup_task);
186
187 wakeup_task = NULL;
188}
189
Ingo Molnare309b412008-05-12 21:20:51 +0200190static void wakeup_reset(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200191{
192 unsigned long flags;
193
Steven Rostedt2f26ebd2009-09-01 11:06:29 -0400194 tracing_reset_online_cpus(tr);
195
Steven Rostedte59494f2008-07-16 00:13:45 -0400196 local_irq_save(flags);
Thomas Gleixner0199c4e2009-12-02 20:01:25 +0100197 arch_spin_lock(&wakeup_lock);
Steven Rostedt352ad252008-05-12 21:20:42 +0200198 __wakeup_reset(tr);
Thomas Gleixner0199c4e2009-12-02 20:01:25 +0100199 arch_spin_unlock(&wakeup_lock);
Steven Rostedte59494f2008-07-16 00:13:45 -0400200 local_irq_restore(flags);
Steven Rostedt352ad252008-05-12 21:20:42 +0200201}
202
Ingo Molnare309b412008-05-12 21:20:51 +0200203static void
Steven Rostedt38516ab2010-04-20 17:04:50 -0400204probe_wakeup(void *ignore, struct task_struct *p, int success)
Steven Rostedt352ad252008-05-12 21:20:42 +0200205{
Steven Rostedtf8ec1062009-01-21 17:17:04 -0500206 struct trace_array_cpu *data;
Steven Rostedt352ad252008-05-12 21:20:42 +0200207 int cpu = smp_processor_id();
208 unsigned long flags;
209 long disabled;
Steven Rostedt38697052008-10-01 13:14:09 -0400210 int pc;
Steven Rostedt352ad252008-05-12 21:20:42 +0200211
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400212 if (likely(!tracer_enabled))
Steven Rostedt352ad252008-05-12 21:20:42 +0200213 return;
214
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400215 tracing_record_cmdline(p);
216 tracing_record_cmdline(current);
217
Steven Rostedt32443512009-01-21 16:24:46 -0500218 if ((wakeup_rt && !rt_task(p)) ||
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400219 p->prio >= wakeup_prio ||
220 p->prio >= current->prio)
221 return;
222
Steven Rostedt38697052008-10-01 13:14:09 -0400223 pc = preempt_count();
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400224 disabled = atomic_inc_return(&wakeup_trace->data[cpu]->disabled);
Steven Rostedt352ad252008-05-12 21:20:42 +0200225 if (unlikely(disabled != 1))
226 goto out;
227
228 /* interrupts should be off from try_to_wake_up */
Thomas Gleixner0199c4e2009-12-02 20:01:25 +0100229 arch_spin_lock(&wakeup_lock);
Steven Rostedt352ad252008-05-12 21:20:42 +0200230
231 /* check for races. */
232 if (!tracer_enabled || p->prio >= wakeup_prio)
233 goto out_locked;
234
235 /* reset the trace */
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400236 __wakeup_reset(wakeup_trace);
Steven Rostedt352ad252008-05-12 21:20:42 +0200237
238 wakeup_cpu = task_cpu(p);
Steven Rostedt478142c32009-09-09 10:36:01 -0400239 wakeup_current_cpu = wakeup_cpu;
Steven Rostedt352ad252008-05-12 21:20:42 +0200240 wakeup_prio = p->prio;
241
242 wakeup_task = p;
243 get_task_struct(wakeup_task);
244
245 local_save_flags(flags);
246
Steven Rostedtf8ec1062009-01-21 17:17:04 -0500247 data = wakeup_trace->data[wakeup_cpu];
248 data->preempt_timestamp = ftrace_now(cpu);
Arnaldo Carvalho de Melo7be42152009-02-05 01:13:37 -0500249 tracing_sched_wakeup_trace(wakeup_trace, p, current, flags, pc);
Steven Rostedt301fd742009-04-03 11:12:23 -0400250
251 /*
252 * We must be careful in using CALLER_ADDR2. But since wake_up
253 * is not called by an assembly function (where as schedule is)
254 * it should be safe to use it here.
255 */
Arnaldo Carvalho de Melo7be42152009-02-05 01:13:37 -0500256 trace_function(wakeup_trace, CALLER_ADDR1, CALLER_ADDR2, flags, pc);
Steven Rostedt352ad252008-05-12 21:20:42 +0200257
258out_locked:
Thomas Gleixner0199c4e2009-12-02 20:01:25 +0100259 arch_spin_unlock(&wakeup_lock);
Steven Rostedt352ad252008-05-12 21:20:42 +0200260out:
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400261 atomic_dec(&wakeup_trace->data[cpu]->disabled);
Steven Rostedt352ad252008-05-12 21:20:42 +0200262}
263
Ingo Molnare309b412008-05-12 21:20:51 +0200264static void start_wakeup_tracer(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200265{
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200266 int ret;
267
Steven Rostedt38516ab2010-04-20 17:04:50 -0400268 ret = register_trace_sched_wakeup(probe_wakeup, NULL);
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200269 if (ret) {
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400270 pr_info("wakeup trace: Couldn't activate tracepoint"
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200271 " probe to kernel_sched_wakeup\n");
272 return;
273 }
274
Steven Rostedt38516ab2010-04-20 17:04:50 -0400275 ret = register_trace_sched_wakeup_new(probe_wakeup, NULL);
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200276 if (ret) {
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400277 pr_info("wakeup trace: Couldn't activate tracepoint"
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200278 " probe to kernel_sched_wakeup_new\n");
279 goto fail_deprobe;
280 }
281
Steven Rostedt38516ab2010-04-20 17:04:50 -0400282 ret = register_trace_sched_switch(probe_wakeup_sched_switch, NULL);
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200283 if (ret) {
Mathieu Desnoyersb07c3f12008-07-18 12:16:17 -0400284 pr_info("sched trace: Couldn't activate tracepoint"
Wenji Huang73d8b8b2009-02-17 01:10:02 -0500285 " probe to kernel_sched_switch\n");
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200286 goto fail_deprobe_wake_new;
287 }
288
Steven Rostedt38516ab2010-04-20 17:04:50 -0400289 ret = register_trace_sched_migrate_task(probe_wakeup_migrate_task, NULL);
Steven Rostedt478142c32009-09-09 10:36:01 -0400290 if (ret) {
291 pr_info("wakeup trace: Couldn't activate tracepoint"
292 " probe to kernel_sched_migrate_task\n");
293 return;
294 }
295
Steven Rostedt352ad252008-05-12 21:20:42 +0200296 wakeup_reset(tr);
297
298 /*
299 * Don't let the tracer_enabled = 1 show up before
300 * the wakeup_task is reset. This may be overkill since
301 * wakeup_reset does a spin_unlock after setting the
302 * wakeup_task to NULL, but I want to be safe.
303 * This is a slow path anyway.
304 */
305 smp_wmb();
306
Steven Rostedt7e18d8e2008-05-22 00:22:19 -0400307 register_ftrace_function(&trace_ops);
Steven Rostedt352ad252008-05-12 21:20:42 +0200308
Steven Rostedt5bc45642009-01-21 14:36:52 -0500309 if (tracing_is_enabled())
Steven Rostedt90369902008-11-05 16:05:44 -0500310 tracer_enabled = 1;
Steven Rostedt5bc45642009-01-21 14:36:52 -0500311 else
Steven Rostedt90369902008-11-05 16:05:44 -0500312 tracer_enabled = 0;
Steven Rostedtad591242008-07-10 20:58:13 -0400313
Steven Rostedt352ad252008-05-12 21:20:42 +0200314 return;
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200315fail_deprobe_wake_new:
Steven Rostedt38516ab2010-04-20 17:04:50 -0400316 unregister_trace_sched_wakeup_new(probe_wakeup, NULL);
Mathieu Desnoyers5b82a1b2008-05-12 21:21:10 +0200317fail_deprobe:
Steven Rostedt38516ab2010-04-20 17:04:50 -0400318 unregister_trace_sched_wakeup(probe_wakeup, NULL);
Steven Rostedt352ad252008-05-12 21:20:42 +0200319}
320
Ingo Molnare309b412008-05-12 21:20:51 +0200321static void stop_wakeup_tracer(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200322{
323 tracer_enabled = 0;
Steven Rostedt7e18d8e2008-05-22 00:22:19 -0400324 unregister_ftrace_function(&trace_ops);
Steven Rostedt38516ab2010-04-20 17:04:50 -0400325 unregister_trace_sched_switch(probe_wakeup_sched_switch, NULL);
326 unregister_trace_sched_wakeup_new(probe_wakeup, NULL);
327 unregister_trace_sched_wakeup(probe_wakeup, NULL);
328 unregister_trace_sched_migrate_task(probe_wakeup_migrate_task, NULL);
Steven Rostedt352ad252008-05-12 21:20:42 +0200329}
330
Steven Rostedt32443512009-01-21 16:24:46 -0500331static int __wakeup_tracer_init(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200332{
Steven Rostedte9d25fe2009-03-04 22:15:30 -0500333 save_lat_flag = trace_flags & TRACE_ITER_LATENCY_FMT;
334 trace_flags |= TRACE_ITER_LATENCY_FMT;
335
Steven Rostedt745b1622009-01-15 23:40:11 -0500336 tracing_max_latency = 0;
Steven Rostedt352ad252008-05-12 21:20:42 +0200337 wakeup_trace = tr;
Steven Rostedtc76f0692008-11-07 22:36:02 -0500338 start_wakeup_tracer(tr);
Frederic Weisbecker1c800252008-11-16 05:57:26 +0100339 return 0;
Steven Rostedt352ad252008-05-12 21:20:42 +0200340}
341
Steven Rostedt32443512009-01-21 16:24:46 -0500342static int wakeup_tracer_init(struct trace_array *tr)
343{
344 wakeup_rt = 0;
345 return __wakeup_tracer_init(tr);
346}
347
348static int wakeup_rt_tracer_init(struct trace_array *tr)
349{
350 wakeup_rt = 1;
351 return __wakeup_tracer_init(tr);
352}
353
Ingo Molnare309b412008-05-12 21:20:51 +0200354static void wakeup_tracer_reset(struct trace_array *tr)
Steven Rostedt352ad252008-05-12 21:20:42 +0200355{
Steven Rostedtc76f0692008-11-07 22:36:02 -0500356 stop_wakeup_tracer(tr);
357 /* make sure we put back any tasks we are tracing */
358 wakeup_reset(tr);
Steven Rostedte9d25fe2009-03-04 22:15:30 -0500359
360 if (!save_lat_flag)
361 trace_flags &= ~TRACE_ITER_LATENCY_FMT;
Steven Rostedt352ad252008-05-12 21:20:42 +0200362}
363
Steven Rostedt90369902008-11-05 16:05:44 -0500364static void wakeup_tracer_start(struct trace_array *tr)
365{
366 wakeup_reset(tr);
367 tracer_enabled = 1;
Steven Rostedt90369902008-11-05 16:05:44 -0500368}
369
370static void wakeup_tracer_stop(struct trace_array *tr)
371{
372 tracer_enabled = 0;
Steven Rostedt352ad252008-05-12 21:20:42 +0200373}
374
375static struct tracer wakeup_tracer __read_mostly =
376{
377 .name = "wakeup",
378 .init = wakeup_tracer_init,
379 .reset = wakeup_tracer_reset,
Steven Rostedt90369902008-11-05 16:05:44 -0500380 .start = wakeup_tracer_start,
381 .stop = wakeup_tracer_stop,
Steven Rostedt352ad252008-05-12 21:20:42 +0200382 .print_max = 1,
Steven Rostedt60a11772008-05-12 21:20:44 +0200383#ifdef CONFIG_FTRACE_SELFTEST
384 .selftest = trace_selftest_startup_wakeup,
385#endif
Steven Rostedt352ad252008-05-12 21:20:42 +0200386};
387
Steven Rostedt32443512009-01-21 16:24:46 -0500388static struct tracer wakeup_rt_tracer __read_mostly =
389{
390 .name = "wakeup_rt",
391 .init = wakeup_rt_tracer_init,
392 .reset = wakeup_tracer_reset,
393 .start = wakeup_tracer_start,
394 .stop = wakeup_tracer_stop,
Frederic Weisbecker6eaaa5d2009-02-11 02:25:00 +0100395 .wait_pipe = poll_wait_pipe,
Steven Rostedt32443512009-01-21 16:24:46 -0500396 .print_max = 1,
397#ifdef CONFIG_FTRACE_SELFTEST
398 .selftest = trace_selftest_startup_wakeup,
399#endif
400};
401
Steven Rostedt352ad252008-05-12 21:20:42 +0200402__init static int init_wakeup_tracer(void)
403{
404 int ret;
405
406 ret = register_tracer(&wakeup_tracer);
407 if (ret)
408 return ret;
409
Steven Rostedt32443512009-01-21 16:24:46 -0500410 ret = register_tracer(&wakeup_rt_tracer);
411 if (ret)
412 return ret;
413
Steven Rostedt352ad252008-05-12 21:20:42 +0200414 return 0;
415}
416device_initcall(init_wakeup_tracer);