xref: /linux/kernel/trace/trace_sched_wakeup.c (revision b3b77c8caef1750ebeea1054e39e358550ea9f55)
1 /*
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>
18 #include <trace/events/sched.h>
19 
20 #include "trace.h"
21 
22 static struct trace_array	*wakeup_trace;
23 static int __read_mostly	tracer_enabled;
24 
25 static struct task_struct	*wakeup_task;
26 static int			wakeup_cpu;
27 static int			wakeup_current_cpu;
28 static unsigned			wakeup_prio = -1;
29 static int			wakeup_rt;
30 
31 static arch_spinlock_t wakeup_lock =
32 	(arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED;
33 
34 static void __wakeup_reset(struct trace_array *tr);
35 
36 static int save_lat_flag;
37 
38 #ifdef CONFIG_FUNCTION_TRACER
39 /*
40  * irqsoff uses its own tracer function to keep the overhead down:
41  */
42 static void
43 wakeup_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;
51 	int pc;
52 
53 	if (likely(!wakeup_task))
54 		return;
55 
56 	pc = preempt_count();
57 	resched = ftrace_preempt_disable();
58 
59 	cpu = raw_smp_processor_id();
60 	if (cpu != wakeup_current_cpu)
61 		goto out_enable;
62 
63 	data = tr->data[cpu];
64 	disabled = atomic_inc_return(&data->disabled);
65 	if (unlikely(disabled != 1))
66 		goto out;
67 
68 	local_irq_save(flags);
69 
70 	trace_function(tr, ip, parent_ip, flags, pc);
71 
72 	local_irq_restore(flags);
73 
74  out:
75 	atomic_dec(&data->disabled);
76  out_enable:
77 	ftrace_preempt_enable(resched);
78 }
79 
80 static struct ftrace_ops trace_ops __read_mostly =
81 {
82 	.func = wakeup_tracer_call,
83 };
84 #endif /* CONFIG_FUNCTION_TRACER */
85 
86 /*
87  * Should this new latency be reported/recorded?
88  */
89 static int report_latency(cycle_t delta)
90 {
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 
101 static void probe_wakeup_migrate_task(struct task_struct *task, int cpu)
102 {
103 	if (task != wakeup_task)
104 		return;
105 
106 	wakeup_current_cpu = cpu;
107 }
108 
109 static void notrace
110 probe_wakeup_sched_switch(struct task_struct *prev, struct task_struct *next)
111 {
112 	struct trace_array_cpu *data;
113 	cycle_t T0, T1, delta;
114 	unsigned long flags;
115 	long disabled;
116 	int cpu;
117 	int pc;
118 
119 	tracing_record_cmdline(prev);
120 
121 	if (unlikely(!tracer_enabled))
122 		return;
123 
124 	/*
125 	 * When we start a new trace, we set wakeup_task to NULL
126 	 * and then set tracer_enabled = 1. We want to make sure
127 	 * that another CPU does not see the tracer_enabled = 1
128 	 * and the wakeup_task with an older task, that might
129 	 * actually be the same as next.
130 	 */
131 	smp_rmb();
132 
133 	if (next != wakeup_task)
134 		return;
135 
136 	pc = preempt_count();
137 
138 	/* disable local data, not wakeup_cpu data */
139 	cpu = raw_smp_processor_id();
140 	disabled = atomic_inc_return(&wakeup_trace->data[cpu]->disabled);
141 	if (likely(disabled != 1))
142 		goto out;
143 
144 	local_irq_save(flags);
145 	arch_spin_lock(&wakeup_lock);
146 
147 	/* We could race with grabbing wakeup_lock */
148 	if (unlikely(!tracer_enabled || next != wakeup_task))
149 		goto out_unlock;
150 
151 	/* The task we are waiting for is waking up */
152 	data = wakeup_trace->data[wakeup_cpu];
153 
154 	trace_function(wakeup_trace, CALLER_ADDR0, CALLER_ADDR1, flags, pc);
155 	tracing_sched_switch_trace(wakeup_trace, prev, next, flags, pc);
156 
157 	T0 = data->preempt_timestamp;
158 	T1 = ftrace_now(cpu);
159 	delta = T1-T0;
160 
161 	if (!report_latency(delta))
162 		goto out_unlock;
163 
164 	if (likely(!is_tracing_stopped())) {
165 		tracing_max_latency = delta;
166 		update_max_tr(wakeup_trace, wakeup_task, wakeup_cpu);
167 	}
168 
169 out_unlock:
170 	__wakeup_reset(wakeup_trace);
171 	arch_spin_unlock(&wakeup_lock);
172 	local_irq_restore(flags);
173 out:
174 	atomic_dec(&wakeup_trace->data[cpu]->disabled);
175 }
176 
177 static void __wakeup_reset(struct trace_array *tr)
178 {
179 	wakeup_cpu = -1;
180 	wakeup_prio = -1;
181 
182 	if (wakeup_task)
183 		put_task_struct(wakeup_task);
184 
185 	wakeup_task = NULL;
186 }
187 
188 static void wakeup_reset(struct trace_array *tr)
189 {
190 	unsigned long flags;
191 
192 	tracing_reset_online_cpus(tr);
193 
194 	local_irq_save(flags);
195 	arch_spin_lock(&wakeup_lock);
196 	__wakeup_reset(tr);
197 	arch_spin_unlock(&wakeup_lock);
198 	local_irq_restore(flags);
199 }
200 
201 static void
202 probe_wakeup(struct task_struct *p, int success)
203 {
204 	struct trace_array_cpu *data;
205 	int cpu = smp_processor_id();
206 	unsigned long flags;
207 	long disabled;
208 	int pc;
209 
210 	if (likely(!tracer_enabled))
211 		return;
212 
213 	tracing_record_cmdline(p);
214 	tracing_record_cmdline(current);
215 
216 	if ((wakeup_rt && !rt_task(p)) ||
217 			p->prio >= wakeup_prio ||
218 			p->prio >= current->prio)
219 		return;
220 
221 	pc = preempt_count();
222 	disabled = atomic_inc_return(&wakeup_trace->data[cpu]->disabled);
223 	if (unlikely(disabled != 1))
224 		goto out;
225 
226 	/* interrupts should be off from try_to_wake_up */
227 	arch_spin_lock(&wakeup_lock);
228 
229 	/* check for races. */
230 	if (!tracer_enabled || p->prio >= wakeup_prio)
231 		goto out_locked;
232 
233 	/* reset the trace */
234 	__wakeup_reset(wakeup_trace);
235 
236 	wakeup_cpu = task_cpu(p);
237 	wakeup_current_cpu = wakeup_cpu;
238 	wakeup_prio = p->prio;
239 
240 	wakeup_task = p;
241 	get_task_struct(wakeup_task);
242 
243 	local_save_flags(flags);
244 
245 	data = wakeup_trace->data[wakeup_cpu];
246 	data->preempt_timestamp = ftrace_now(cpu);
247 	tracing_sched_wakeup_trace(wakeup_trace, p, current, flags, pc);
248 
249 	/*
250 	 * We must be careful in using CALLER_ADDR2. But since wake_up
251 	 * is not called by an assembly function  (where as schedule is)
252 	 * it should be safe to use it here.
253 	 */
254 	trace_function(wakeup_trace, CALLER_ADDR1, CALLER_ADDR2, flags, pc);
255 
256 out_locked:
257 	arch_spin_unlock(&wakeup_lock);
258 out:
259 	atomic_dec(&wakeup_trace->data[cpu]->disabled);
260 }
261 
262 static void start_wakeup_tracer(struct trace_array *tr)
263 {
264 	int ret;
265 
266 	ret = register_trace_sched_wakeup(probe_wakeup);
267 	if (ret) {
268 		pr_info("wakeup trace: Couldn't activate tracepoint"
269 			" probe to kernel_sched_wakeup\n");
270 		return;
271 	}
272 
273 	ret = register_trace_sched_wakeup_new(probe_wakeup);
274 	if (ret) {
275 		pr_info("wakeup trace: Couldn't activate tracepoint"
276 			" probe to kernel_sched_wakeup_new\n");
277 		goto fail_deprobe;
278 	}
279 
280 	ret = register_trace_sched_switch(probe_wakeup_sched_switch);
281 	if (ret) {
282 		pr_info("sched trace: Couldn't activate tracepoint"
283 			" probe to kernel_sched_switch\n");
284 		goto fail_deprobe_wake_new;
285 	}
286 
287 	ret = register_trace_sched_migrate_task(probe_wakeup_migrate_task);
288 	if (ret) {
289 		pr_info("wakeup trace: Couldn't activate tracepoint"
290 			" probe to kernel_sched_migrate_task\n");
291 		return;
292 	}
293 
294 	wakeup_reset(tr);
295 
296 	/*
297 	 * Don't let the tracer_enabled = 1 show up before
298 	 * the wakeup_task is reset. This may be overkill since
299 	 * wakeup_reset does a spin_unlock after setting the
300 	 * wakeup_task to NULL, but I want to be safe.
301 	 * This is a slow path anyway.
302 	 */
303 	smp_wmb();
304 
305 	register_ftrace_function(&trace_ops);
306 
307 	if (tracing_is_enabled())
308 		tracer_enabled = 1;
309 	else
310 		tracer_enabled = 0;
311 
312 	return;
313 fail_deprobe_wake_new:
314 	unregister_trace_sched_wakeup_new(probe_wakeup);
315 fail_deprobe:
316 	unregister_trace_sched_wakeup(probe_wakeup);
317 }
318 
319 static void stop_wakeup_tracer(struct trace_array *tr)
320 {
321 	tracer_enabled = 0;
322 	unregister_ftrace_function(&trace_ops);
323 	unregister_trace_sched_switch(probe_wakeup_sched_switch);
324 	unregister_trace_sched_wakeup_new(probe_wakeup);
325 	unregister_trace_sched_wakeup(probe_wakeup);
326 	unregister_trace_sched_migrate_task(probe_wakeup_migrate_task);
327 }
328 
329 static int __wakeup_tracer_init(struct trace_array *tr)
330 {
331 	save_lat_flag = trace_flags & TRACE_ITER_LATENCY_FMT;
332 	trace_flags |= TRACE_ITER_LATENCY_FMT;
333 
334 	tracing_max_latency = 0;
335 	wakeup_trace = tr;
336 	start_wakeup_tracer(tr);
337 	return 0;
338 }
339 
340 static int wakeup_tracer_init(struct trace_array *tr)
341 {
342 	wakeup_rt = 0;
343 	return __wakeup_tracer_init(tr);
344 }
345 
346 static int wakeup_rt_tracer_init(struct trace_array *tr)
347 {
348 	wakeup_rt = 1;
349 	return __wakeup_tracer_init(tr);
350 }
351 
352 static void wakeup_tracer_reset(struct trace_array *tr)
353 {
354 	stop_wakeup_tracer(tr);
355 	/* make sure we put back any tasks we are tracing */
356 	wakeup_reset(tr);
357 
358 	if (!save_lat_flag)
359 		trace_flags &= ~TRACE_ITER_LATENCY_FMT;
360 }
361 
362 static void wakeup_tracer_start(struct trace_array *tr)
363 {
364 	wakeup_reset(tr);
365 	tracer_enabled = 1;
366 }
367 
368 static void wakeup_tracer_stop(struct trace_array *tr)
369 {
370 	tracer_enabled = 0;
371 }
372 
373 static struct tracer wakeup_tracer __read_mostly =
374 {
375 	.name		= "wakeup",
376 	.init		= wakeup_tracer_init,
377 	.reset		= wakeup_tracer_reset,
378 	.start		= wakeup_tracer_start,
379 	.stop		= wakeup_tracer_stop,
380 	.print_max	= 1,
381 #ifdef CONFIG_FTRACE_SELFTEST
382 	.selftest    = trace_selftest_startup_wakeup,
383 #endif
384 };
385 
386 static struct tracer wakeup_rt_tracer __read_mostly =
387 {
388 	.name		= "wakeup_rt",
389 	.init		= wakeup_rt_tracer_init,
390 	.reset		= wakeup_tracer_reset,
391 	.start		= wakeup_tracer_start,
392 	.stop		= wakeup_tracer_stop,
393 	.wait_pipe	= poll_wait_pipe,
394 	.print_max	= 1,
395 #ifdef CONFIG_FTRACE_SELFTEST
396 	.selftest    = trace_selftest_startup_wakeup,
397 #endif
398 };
399 
400 __init static int init_wakeup_tracer(void)
401 {
402 	int ret;
403 
404 	ret = register_tracer(&wakeup_tracer);
405 	if (ret)
406 		return ret;
407 
408 	ret = register_tracer(&wakeup_rt_tracer);
409 	if (ret)
410 		return ret;
411 
412 	return 0;
413 }
414 device_initcall(init_wakeup_tracer);
415