aboutsummaryrefslogtreecommitdiff
path: root/kernel/trace/trace_sched_wakeup.c
AgeCommit message (Collapse)AuthorFilesLines
2008-10-14ftrace: make work with new ring bufferSteven Rostedt1-1/+1
This patch ports ftrace over to the new ring buffer. Signed-off-by: Steven Rostedt <[email protected]> Signed-off-by: Ingo Molnar <[email protected]>
2008-10-14ftrace: port to tracepointsMathieu Desnoyers1-101/+34
Porting the trace_mark() used by ftrace to tracepoints. (cleanup) Changelog : - Change error messages : marker -> tracepoint [ [email protected]: conflict resolutions ] Signed-off-by: Mathieu Desnoyers <[email protected]> Acked-by: 'Peter Zijlstra' <[email protected]> Signed-off-by: Ingo Molnar <[email protected]>
2008-07-18ftrace: fix 4d3702b6 (post-v2.6.26): WARNING: at kernel/lockdep.c:2731 ↵Steven Rostedt1-11/+16
check_flags (ftrace) On Wed, 16 Jul 2008, Vegard Nossum wrote: > When booting 4d3702b6, I got this huge thing: > > Testing tracer wakeup: <4>------------[ cut here ]------------ > WARNING: at kernel/lockdep.c:2731 check_flags+0x123/0x160() > Modules linked in: > Pid: 1, comm: swapper Not tainted 2.6.26-crashing-02127-g4d3702b6 #30 > [<c015c349>] warn_on_slowpath+0x59/0xb0 > [<c01276c6>] ? ftrace_call+0x5/0x8 > [<c012d800>] ? native_read_tsc+0x0/0x20 > [<c0158de2>] ? sub_preempt_count+0x12/0xf0 > [<c01814eb>] ? trace_hardirqs_off+0xb/0x10 > [<c0182fbc>] ? __lock_acquire+0x2cc/0x1120 > [<c01814eb>] ? trace_hardirqs_off+0xb/0x10 > [<c01276af>] ? mcount_call+0x5/0xa > [<c017ff53>] check_flags+0x123/0x160 > [<c0183e61>] lock_acquire+0x51/0xd0 > [<c01276c6>] ? ftrace_call+0x5/0x8 > [<c0613d4f>] _spin_lock_irqsave+0x5f/0xa0 > [<c01a8d45>] ? ftrace_record_ip+0xf5/0x220 > [<c02d5413>] ? debug_locks_off+0x3/0x50 > [<c01a8d45>] ftrace_record_ip+0xf5/0x220 > [<c01276af>] mcount_call+0x5/0xa > [<c02d5418>] ? debug_locks_off+0x8/0x50 > [<c017ff27>] check_flags+0xf7/0x160 > [<c0183e61>] lock_acquire+0x51/0xd0 > [<c01276c6>] ? ftrace_call+0x5/0x8 > [<c0613d4f>] _spin_lock_irqsave+0x5f/0xa0 > [<c01affcd>] ? wakeup_tracer_call+0x6d/0xf0 > [<c01625e2>] ? _local_bh_enable+0x62/0xb0 > [<c0158ddd>] ? sub_preempt_count+0xd/0xf0 > [<c01affcd>] wakeup_tracer_call+0x6d/0xf0 > [<c0162724>] ? __do_softirq+0xf4/0x110 > [<c01afff1>] ? wakeup_tracer_call+0x91/0xf0 > [<c01276c6>] ftrace_call+0x5/0x8 > [<c0162724>] ? __do_softirq+0xf4/0x110 > [<c0158de2>] ? sub_preempt_count+0x12/0xf0 > [<c01625e2>] _local_bh_enable+0x62/0xb0 > [<c0162724>] __do_softirq+0xf4/0x110 > [<c01627ed>] do_softirq+0xad/0xb0 > [<c0162a15>] irq_exit+0xa5/0xb0 > [<c013a506>] smp_apic_timer_interrupt+0x66/0xa0 > [<c02d3fac>] ? trace_hardirqs_off_thunk+0xc/0x10 > [<c0127449>] apic_timer_interrupt+0x2d/0x34 > [<c018007b>] ? find_usage_backwards+0xb/0xf0 > [<c0613a09>] ? _spin_unlock_irqrestore+0x69/0x80 > [<c014ef32>] tg_shares_up+0x132/0x1d0 > [<c014d2a2>] walk_tg_tree+0x62/0xa0 > [<c014ee00>] ? tg_shares_up+0x0/0x1d0 > [<c014a860>] ? tg_nop+0x0/0x10 > [<c015499d>] update_shares+0x5d/0x80 > [<c0154a2f>] try_to_wake_up+0x6f/0x280 > [<c01a8b90>] ? __ftrace_modify_code+0x0/0xc0 > [<c01a8b90>] ? __ftrace_modify_code+0x0/0xc0 > [<c0154c94>] wake_up_process+0x14/0x20 > [<c01725f6>] kthread_create+0x66/0xb0 > [<c0195400>] ? do_stop+0x0/0x200 > [<c0195320>] ? __stop_machine_run+0x30/0xb0 > [<c0195340>] __stop_machine_run+0x50/0xb0 > [<c0195400>] ? do_stop+0x0/0x200 > [<c01a8b90>] ? __ftrace_modify_code+0x0/0xc0 > [<c061242d>] ? mutex_unlock+0xd/0x10 > [<c01953cc>] stop_machine_run+0x2c/0x60 > [<c01a94d3>] unregister_ftrace_function+0x103/0x180 > [<c01b0517>] stop_wakeup_tracer+0x17/0x60 > [<c01b056f>] wakeup_tracer_ctrl_update+0xf/0x30 > [<c01ab8d5>] trace_selftest_startup_wakeup+0xb5/0x130 > [<c01ab950>] ? trace_wakeup_test_thread+0x0/0x70 > [<c01aadf5>] register_tracer+0x135/0x1b0 > [<c0877d02>] init_wakeup_tracer+0xd/0xf > [<c085d437>] kernel_init+0x1a9/0x2ce > [<c061397b>] ? _spin_unlock_irq+0x3b/0x60 > [<c02d3f9c>] ? trace_hardirqs_on_thunk+0xc/0x10 > [<c0877cf5>] ? init_wakeup_tracer+0x0/0xf > [<c0182646>] ? trace_hardirqs_on_caller+0x126/0x180 > [<c02d3f9c>] ? trace_hardirqs_on_thunk+0xc/0x10 > [<c01269c8>] ? restore_nocheck_notrace+0x0/0xe > [<c085d28e>] ? kernel_init+0x0/0x2ce > [<c085d28e>] ? kernel_init+0x0/0x2ce > [<c01275fb>] kernel_thread_helper+0x7/0x10 > ======================= > ---[ end trace a7919e7f17c0a725 ]--- > irq event stamp: 579530 > hardirqs last enabled at (579528): [<c01826ab>] trace_hardirqs_on+0xb/0x10 > hardirqs last disabled at (579529): [<c01814eb>] trace_hardirqs_off+0xb/0x10 > softirqs last enabled at (579530): [<c0162724>] __do_softirq+0xf4/0x110 > softirqs last disabled at (579517): [<c01627ed>] do_softirq+0xad/0xb0 > irq event stamp: 579530 > hardirqs last enabled at (579528): [<c01826ab>] trace_hardirqs_on+0xb/0x10 > hardirqs last disabled at (579529): [<c01814eb>] trace_hardirqs_off+0xb/0x10 > softirqs last enabled at (579530): [<c0162724>] __do_softirq+0xf4/0x110 > softirqs last disabled at (579517): [<c01627ed>] do_softirq+0xad/0xb0 > PASSED > > Incidentally, the kernel also hung while I was typing in this report. Things get weird between lockdep and ftrace because ftrace can be called within lockdep internal code (via the mcount pointer) and lockdep can be called with ftrace (via spin_locks). Signed-off-by: Steven Rostedt <[email protected]> Tested-by: Vegard Nossum <[email protected]> Signed-off-by: Ingo Molnar <[email protected]>
2008-07-11ftrace: start wakeup tracing after setting function tracerSteven Rostedt1-1/+2
Enabling the wakeup tracer before enabling the function tracing causes some strange results due to the dynamic enabling of the functions. Signed-off-by: Steven Rostedt <[email protected]> Cc: Steven Rostedt <[email protected]> Cc: Peter Zijlstra <[email protected]> Cc: Andrew Morton <[email protected]> Signed-off-by: Ingo Molnar <[email protected]>
2008-05-26ftrace: add function tracing to wake up tracingSteven Rostedt1-1/+66
This patch adds function tracing to the functions that are called on the CPU of the task being traced. Signed-off-by: Steven Rostedt <[email protected]> Cc: [email protected] Cc: [email protected] Cc: [email protected] Cc: [email protected] Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23Port ftrace to markersMathieu Desnoyers1-6/+100
Porting ftrace to the marker infrastructure. Don't need to chain to the wakeup tracer from the sched tracer, because markers support multiple probes connected. Signed-off-by: Mathieu Desnoyers <[email protected]> CC: Steven Rostedt <[email protected]> Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23ftrace: printk and trace irqsoff and wakeupsSteven Rostedt1-13/+0
printk called from wakeup critical timings and irqs off can cause deadlocks since printk might do a wakeup itself. If the call to printk happens with the runqueue lock held, it can deadlock. This patch protects the printk from being called in trace irqs off with a test to see if the runqueue for the current CPU is locked. If it is locked, the printk is skipped. The wakeup always holds the runqueue lock, so the printk is simply removed. Signed-off-by: Steven Rostedt <[email protected]> Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23ftrace: sched tracer fixIngo Molnar1-10/+3
Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23ftrace: add wakeup events to sched tracerIngo Molnar1-1/+1
Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23ftrace: remove notraceIngo Molnar1-14/+14
now that we have a kbuild method for notrace, no need to pollute the C code with the annotations. Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23ftrace: add trace_function api for other tracers to useSteven Rostedt1-2/+3
A new check was added in the ftrace function that wont trace if the CPU trace buffer is disabled. Unfortunately, other tracers used ftrace() to write to the buffer after they disabled it. The new disable check makes these calls into a nop. This patch changes the __ftrace that is called without the check into a new api for the other tracers to use, called "trace_function". The other tracers use this interface instead when the trace CPU buffer is already disabled. Signed-off-by: Steven Rostedt <[email protected]> Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23ftrace: timestamp syncing, prepareIngo Molnar1-2/+2
rename and uninline now() to ftrace_now(). Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23ftrace: cleanupsIngo Molnar1-12/+6
factor out code and clean it up. Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23ftrace: add self-testsSteven Rostedt1-0/+3
Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
2008-05-23ftrace: tracer for scheduler wakeup latencySteven Rostedt1-0/+310
This patch adds the tracer that tracks the wakeup latency of the highest priority waking task. "wakeup" is added to /debugfs/tracing/available_tracers Also added to /debugfs/tracing tracing_max_latency holds the current max latency for the wakeup wakeup_thresh if set to other than zero, a log will be recorded for every wakeup that takes longer than the number entered in here (usecs for all counters) (deletes previous trace) Examples: (with ftrace_enabled = 0) ============ preemption latency trace v1.1.5 on 2.6.24-rc8 Signed-off-by: Ingo Molnar <[email protected]> -------------------------------------------------------------------- latency: 26 us, #2/2, CPU#1 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2) ----------------- | task: migration/0-3 (uid:0 nice:-5 policy:1 rt_prio:99) ----------------- _------=> CPU# / _-----=> irqs-off | / _----=> need-resched || / _---=> hardirq/softirq ||| / _--=> preempt-depth |||| / ||||| delay cmd pid ||||| time | caller \ / ||||| \ | / quilt-8551 0d..3 0us+: wake_up_process+0x15/0x17 <ffffffff80233e80> (sched_exec+0xc9/0x100 <ffffffff80235343>) quilt-8551 0d..4 26us : sched_switch_callback+0x73/0x81 <ffffffff80338d2f> (schedule+0x483/0x6d5 <ffffffff8048b3ee>) vim:ft=help ============ (with ftrace_enabled = 1) ============ preemption latency trace v1.1.5 on 2.6.24-rc8 -------------------------------------------------------------------- latency: 36 us, #45/45, CPU#0 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2) ----------------- | task: migration/1-5 (uid:0 nice:-5 policy:1 rt_prio:99) ----------------- _------=> CPU# / _-----=> irqs-off | / _----=> need-resched || / _---=> hardirq/softirq ||| / _--=> preempt-depth |||| / ||||| delay cmd pid ||||| time | caller \ / ||||| \ | / bash-10653 1d..3 0us : wake_up_process+0x15/0x17 <ffffffff80233e80> (sched_exec+0xc9/0x100 <ffffffff80235343>) bash-10653 1d..3 1us : try_to_wake_up+0x271/0x2e7 <ffffffff80233dcf> (sub_preempt_count+0xc/0x7a <ffffffff8023309e>) bash-10653 1d..2 2us : try_to_wake_up+0x296/0x2e7 <ffffffff80233df4> (update_rq_clock+0x9/0x20 <ffffffff802303f3>) bash-10653 1d..2 2us : update_rq_clock+0x1e/0x20 <ffffffff80230408> (__update_rq_clock+0xc/0x90 <ffffffff80230366>) bash-10653 1d..2 3us : __update_rq_clock+0x1b/0x90 <ffffffff80230375> (sched_clock+0x9/0x29 <ffffffff80214529>) bash-10653 1d..2 4us : try_to_wake_up+0x2a6/0x2e7 <ffffffff80233e04> (activate_task+0xc/0x3f <ffffffff8022ffca>) bash-10653 1d..2 4us : activate_task+0x2d/0x3f <ffffffff8022ffeb> (enqueue_task+0xe/0x66 <ffffffff8022ff66>) bash-10653 1d..2 5us : enqueue_task+0x5b/0x66 <ffffffff8022ffb3> (enqueue_task_rt+0x9/0x3c <ffffffff80233351>) bash-10653 1d..2 6us : try_to_wake_up+0x2ba/0x2e7 <ffffffff80233e18> (check_preempt_wakeup+0x12/0x99 <ffffffff80234f84>) [...] bash-10653 1d..5 33us : tracing_record_cmdline+0xcf/0xd4 <ffffffff80338aad> (_spin_unlock+0x9/0x33 <ffffffff8048d3ec>) bash-10653 1d..5 34us : _spin_unlock+0x19/0x33 <ffffffff8048d3fc> (sub_preempt_count+0xc/0x7a <ffffffff8023309e>) bash-10653 1d..4 35us : wakeup_sched_switch+0x65/0x2ff <ffffffff80339f66> (_spin_lock_irqsave+0xc/0xa9 <ffffffff8048d08b>) bash-10653 1d..4 35us : _spin_lock_irqsave+0x19/0xa9 <ffffffff8048d098> (add_preempt_count+0xe/0x77 <ffffffff8023311a>) bash-10653 1d..4 36us : sched_switch_callback+0x73/0x81 <ffffffff80338d2f> (schedule+0x483/0x6d5 <ffffffff8048b3ee>) vim:ft=help ============ The [...] was added here to not waste your email box space. Signed-off-by: Steven Rostedt <[email protected]> Signed-off-by: Ingo Molnar <[email protected]> Signed-off-by: Thomas Gleixner <[email protected]>
Powered by cgit, Gruvboxed by Blaster4385.