ftrace clean ups
Subsystems (2)
Steven Rostedt
maintainercover ftrace clean ups
This patch series contains various ftrace clean ups.
-- Steve
Steven Rostedt
maintainerPATCH 1/5 ftrace: limit use of check pages
The check_pages function is called often enough that it can cause problems with trace outputs or even bringing the system to a halt.
This patch limits the check_pages to the places that are most likely to have problems. The check is made at the flip between the global array and the max save array, as well as when the size of the buffers changes and the self tests.
This patch also removes the BUG_ON from check_pages and replaces it with a WARN_ON and disabling of the tracer.
--- kernel/trace/trace.c | 32 +++++++++++++++++++++++--------- kernel/trace/trace_selftest.c | 1 + 2 files changed, 24 insertions(+), 9 deletions(-)
kernel/trace/trace.c +23 -9
@@ -249,24 +249,32 @@ __update_max_tr(struct trace_array *tr,tracing_record_cmdline (current); } +#define CHECK_COND (cond) \ + if (unlikely(cond)) { \ + tracing_disabled = 0; \ + WARN_ON(1); \ + return -1; \ + } +/** * check_pages - integrity check of trace buffers * * As a safty measure we check to make sure the data pages have not -* been corrupted. TODO: configure to disable this because it adds -* a bit of overhead. +* been corrupted. */ -void check_pages (struct trace_array_cpu *data) +int check_pages (struct trace_array_cpu *data) {struct page *page, *tmp; -BUG_ON (data->trace_pages.next->prev != &data->trace_pages); -BUG_ON (data->trace_pages.prev->next != &data->trace_pages); +CHECK_COND (data->trace_pages.next->prev != &data->trace_pages); +CHECK_COND (data->trace_pages.prev->next != &data->trace_pages);list_for_each_entry_safe (page, tmp, &data->trace_pages, lru) { -BUG_ON (page->lru.next->prev != &page->lru); -BUG_ON (page->lru.prev->next != &page->lru); +CHECK_COND (page->lru.next->prev != &page->lru); +CHECK_COND (page->lru.prev->next != &page->lru); } + +return 0 ; }/**
@@ -280,7 +288,6 @@ void *head_page(struct trace_array_cpu * {struct page *page; -check_pages (data);if (list_empty (&data->trace_pages))return NULL ;
@@ -2608,7 +2615,7 @@ tracing_entries_write(struct file *filp, {unsigned long val;char buf[64 ]; -int ret; +int i, ret;if (cnt >=sizeof (buf))return -EINVAL ;
@@ -2677,8 +2684,15 @@ tracing_entries_write(struct file *filp,trace_free_page (); } +/* check integrity */ +for_each_tracing_cpu (i) +check_pages (global_trace.data[i]); + filp->f_pos += cnt; +/* If check pages failed, return ENOMEM */ +if (tracing_disabled) + cnt = -ENOMEM ; out: max_tr.entries = global_trace.entries;mutex_unlock (&trace_types_lock);
kernel/trace/trace_selftest.c +1 -0
@@ -28,6 +28,7 @@ trace_test_buffer_cpu(struct trace_array page = list_entry(data->trace_pages.next, struct page, lru); entries =page_address (page); +check_pages (data);if (head_page (data) != entries) goto failed;
Re: [PATCH 1/5] ftrace: limit use of check pages
Quoted 22 lines · On Thu, 22 May 2008 00:22:16 -0400 Steven Rostedt <[email protected]> wrote:
The
check_pagesfunction is called often enough that it can cause problems with trace outputs or even bringing the system to a halt.This patch limits the
check_pagesto the places that are most likely to have problems. The check is made at the flip between the global array and the max save array, as well as when the size of the buffers changes and the self tests.This patch also removes the
BUG_ONfromcheck_pagesand replaces it with aWARN_ONand disabling of the tracer.Signed-off-by Steven Rostedt <[email protected]>--- kernel/trace/trace.c | 32 +++++++++++++++++++++++--------- kernel/trace/trace_selftest.c | 1 + 2 files changed, 24 insertions(+), 9 deletions(-)Index:
linux-tip.git/kernel/trace/trace.c
===================================================================
kernel/trace/trace.c __update_max_tr(struct trace_array *tr, · line 254
Quoted 6 lines
kernel/trace/trace.c +3
-0@@ -249,24 +249,32 @@ __update_max_tr(struct trace_array *tr,tracing_record_cmdline (current); } +#define CHECK_COND (cond) \ + if (unlikely(cond)) { \ + tracing_disabled = 0; \
-----------------------------------^
This looks like a typo.
I also quickly read through the other patches and didn't see any obvious problems in them.
Quoted 31 lines
kernel/trace/trace.c +12
-7+WARN_ON (1 ); \ +return -1 ; \ + } +/** * check_pages - integrity check of trace buffers * * As a safty measure we check to make sure the data pages have not -* been corrupted. TODO: configure to disable this because it adds -* a bit of overhead. +* been corrupted. */ -void check_pages (struct trace_array_cpu *data) +int check_pages (struct trace_array_cpu *data) {struct page *page, *tmp; -BUG_ON (data->trace_pages.next->prev != &data->trace_pages); -BUG_ON (data->trace_pages.prev->next != &data->trace_pages); +CHECK_COND (data->trace_pages.next->prev != &data->trace_pages); +CHECK_COND (data->trace_pages.prev->next != &data->trace_pages);list_for_each_entry_safe (page, tmp, &data->trace_pages, lru) { -BUG_ON (page->lru.next->prev != &page->lru); -BUG_ON (page->lru.prev->next != &page->lru); +CHECK_COND (page->lru.next->prev != &page->lru); +CHECK_COND (page->lru.prev->next != &page->lru); } + +return 0 ; }
Signature · 2 lines
Pekka Paalanen http://www.iki.fi/pq/
Steven Rostedt
maintainerRe: [PATCH 1/5] ftrace: limit use of check pages
Quoted 10 lines · Pekka Paalanen
kernel/trace/trace.c __update_max_tr(struct trace_array *tr, · line 254
Quoted 4 lines · On Thu, 22 May 2008 00:22:16 -0400 Steven Rostedt <[email protected]> wrote:
kernel/trace/trace.c +3
-0+#define CHECK_COND (cond) \ + if (unlikely(cond)) { \ + tracing_disabled = 0; \-----------------------------------^
This looks like a typo.
Quoted 2 lines
I also quickly read through the other patches and didn't see any obvious problems in them.
Indeed it is! I haven't hit the cond so I wouldn't have seen it in my tests ;-)
Thanks!
-- Steve
Steven Rostedt
maintainerPATCH 1/1 ftrace: fix check_pages disable set
In reply to Pekka PaalanenPekka Paalanen pointed out that I didn't set the tracing_disabled flag when check_pages failed.
--- kernel/trace/trace.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
kernel/trace/trace.c +1 -1
@@ -251,7 +251,7 @@ __update_max_tr(struct trace_array *tr,#define CHECK_COND (cond) \ if (unlikely(cond)) { \ - tracing_disabled = 0; \ + tracing_disabled = 1; \ WARN_ON(1); \ return -1; \ }
Re: [PATCH 1/5] ftrace: limit use of check pages
In reply to Steven RostedtQuoted 10 lines · Steven Rostedt
The
check_pagesfunction is called often enough that it can cause problems with trace outputs or even bringing the system to a halt.This patch limits the
check_pagesto the places that are most likely to have problems. The check is made at the flip between the global array and the max save array, as well as when the size of the buffers changes and the self tests.This patch also removes the
BUG_ONfromcheck_pagesand replaces it with aWARN_ONand disabling of the tracer.
Applied and fixed the typo.
kernel/trace/trace.c __update_max_tr(struct trace_array *tr, · line 254
Quoted 1 line
kernel/trace/trace.c +1
-0+ tracing_disabled =0 ; \
Thanks,
tglx
Steven Rostedt
maintainerPATCH 2/5 ftrace: remove wakeup functions from sched_switch tracer
In reply to Steven RostedtThe added wakeup functions inside the sched_switch tracer dirty the trace quite a bit. The sched_switch tracer is used to watch context switches. Adding wakeups to this make the flow of this trace much more complex to understand.
Perhaps we can add a way to turn on or off this tracing but for now I'm reverting the sched_switch back to its original behavior.
--- kernel/trace/trace_sched_switch.c | 92 -------------------------------------- 1 file changed, 1 insertion(+), 91 deletions(-)
kernel/trace/trace_sched_switch.c +1 -91
@@ -72,59 +72,6 @@ sched_switch_callback(void *probe_data,sched_switch_func (probe_data, __rq, prev, next); } -static void -wakeup_func (void *private,void *__rq,struct task_struct *wakee,struct -task_struct *curr) -{ -struct trace_array **ptr = private; -struct trace_array *tr = *ptr; -struct trace_array_cpu *data; -unsigned long flags; -long disabled; -int cpu; - -if (!tracer_enabled) -return ; - -tracing_record_cmdline (curr); - -local_irq_save (flags); - cpu =raw_smp_processor_id (); - data = tr->data[cpu]; - disabled =atomic_inc_return (&data->disabled); - -if (likely (disabled ==1 )) -tracing_sched_wakeup_trace (tr, data, wakee, curr, flags); - -atomic_dec (&data->disabled); -local_irq_restore (flags); -} - -static notrace void -wake_up_callback (void *probe_data,void *call_data, -const char *format,va_list *args) -{ -struct task_struct *curr; -struct task_struct *task; -struct rq *__rq; - -if (likely (!tracer_enabled)) -return ; - -/* Skip pid %d state %ld */ - (void )va_arg (*args, int); - (void )va_arg (*args, long); -/* now get the meat: "rq %p task %p rq->curr %p" */ - __rq =va_arg (*args,typeof (__rq)); - task =va_arg (*args,typeof (task)); - curr =va_arg (*args,typeof (curr)); - -tracing_record_cmdline (task); -tracing_record_cmdline (curr); - -wakeup_func (probe_data, __rq, task, curr); -} -void ftrace_special (unsigned long arg1,unsigned long arg2,unsigned long arg3) {
@@ -163,47 +110,16 @@ static int tracing_sched_register(void) {int ret; - ret =marker_probe_register ("kernel_sched_wakeup" , -"pid %d state %ld ## rq %p task %p rq->curr %p" , - wake_up_callback, - &ctx_trace); -if (ret) { -pr_info ("wakeup trace: Couldn't add marker" -" probe to kernel_sched_wakeup\n" ); -return ret; - } - - ret =marker_probe_register ("kernel_sched_wakeup_new" , -"pid %d state %ld ## rq %p task %p rq->curr %p" , - wake_up_callback, - &ctx_trace); -if (ret) { -pr_info ("wakeup trace: Couldn't add marker" -" probe to kernel_sched_wakeup_new\n" ); - goto fail_deprobe; - } - ret =marker_probe_register ("kernel_sched_schedule" ,"prev_pid %d next_pid %d prev_state %ld " "## rq %p prev %p next %p" , sched_switch_callback, &ctx_trace); -if (ret) { +if (ret)pr_info ("sched trace: Couldn't add marker" " probe to kernel_sched_schedule\n" ); - goto fail_deprobe_wake_new; - }return ret; -fail_deprobe_wake_new: -marker_probe_unregister ("kernel_sched_wakeup_new" , - wake_up_callback, - &ctx_trace); -fail_deprobe: -marker_probe_unregister ("kernel_sched_wakeup" , - wake_up_callback, - &ctx_trace); -return ret; }static void tracing_sched_unregister (void )
@@ -211,12 +127,6 @@ static void tracing_sched_unregister(voimarker_probe_unregister ("kernel_sched_schedule" , sched_switch_callback, &ctx_trace); -marker_probe_unregister ("kernel_sched_wakeup_new" , - wake_up_callback, - &ctx_trace); -marker_probe_unregister ("kernel_sched_wakeup" , - wake_up_callback, - &ctx_trace); }void tracing_start_sched_switch (void )
Re: [PATCH 2/5] ftrace: remove wakeup functions from sched_switch tracer
Quoted 8 lines · Steven Rostedt
plain text document attachment (ftrace-remove-wakeup-from-sched.patch) The added wakeup functions inside the
sched_switchtracer dirty the trace quite a bit. Thesched_switchtracer is used to watch context switches. Adding wakeups to this make the flow of this trace much more complex to understand.Perhaps we can add a way to turn on or off this tracing but for now I'm reverting the
sched_switchback to its original behavior.
Not liking this - this is very useful.
use grep already.
Steven Rostedt
maintainerPATCH 3/5 ftrace: move ftrace_special to trace.c
In reply to Steven RostedtMove the ftrace_special out of sched_switch to trace.c.
--- kernel/trace/trace.c | 27 +++++++++++++++++++++++++-- kernel/trace/trace_sched_switch.c | 24 ------------------------ 2 files changed, 25 insertions(+), 26 deletions(-)
kernel/trace/trace.c +25 -2
@@ -983,6 +983,30 @@ tracing_sched_wakeup_trace(struct trace_trace_wake_up (); } +void +ftrace_special (unsigned long arg1,unsigned long arg2,unsigned long arg3) +{ +struct trace_array *tr = &global_trace; +struct trace_array_cpu *data; +unsigned long flags; +long disabled; +int cpu; + +if (tracing_disabled || current_trace == &no_tracer || !tr->ctrl) +return ; + +local_irq_save (flags); + cpu =raw_smp_processor_id (); + data = tr->data[cpu]; + disabled =atomic_inc_return (&data->disabled); + +if (likely (disabled ==1 )) +__trace_special (tr, data, arg1, arg2, arg3); + +atomic_dec (&data->disabled); +local_irq_restore (flags); +} +#ifdef CONFIG_FTRACE static void function_trace_call (unsigned long ip,unsigned long parent_ip)
@@ -2986,8 +3010,6 @@ __init static int tracer_alloc_buffers(vint ret = -ENOMEM ;int i; - global_trace.ctrl = tracer_enabled; -/* TODO: make the number of buffers hot pluggable with CPUS */ tracing_nr_buffers =num_possible_cpus (); tracing_buffer_mask = cpu_possible_map;
@@ -3057,6 +3079,7 @@ __init static int tracer_alloc_buffers(v current_trace = &no_tracer;/* All seems OK, enable tracing */ + global_trace.ctrl = tracer_enabled; tracing_disabled =0 ;return 0 ;
kernel/trace/trace_sched_switch.c +0 -24
@@ -72,30 +72,6 @@ sched_switch_callback(void *probe_data,sched_switch_func (probe_data, __rq, prev, next); } -void -ftrace_special (unsigned long arg1,unsigned long arg2,unsigned long arg3) -{ -struct trace_array *tr = ctx_trace; -struct trace_array_cpu *data; -unsigned long flags; -long disabled; -int cpu; - -if (!tracer_enabled) -return ; - -local_irq_save (flags); - cpu =raw_smp_processor_id (); - data = tr->data[cpu]; - disabled =atomic_inc_return (&data->disabled); - -if (likely (disabled ==1 )) -__trace_special (tr, data, arg1, arg2, arg3); - -atomic_dec (&data->disabled); -local_irq_restore (flags); -} -static void sched_switch_reset (struct trace_array *tr) {int cpu;
Steven Rostedt
maintainerPATCH 4/5 ftrace: add function tracing to wake up tracing
In reply to Steven RostedtThis patch adds function tracing to the functions that are called on the CPU of the task being traced.
--- kernel/trace/trace_sched_wakeup.c | 67 +++++++++++++++++++++++++++++++++++++- 1 file changed, 66 insertions(+), 1 deletion(-)
kernel/trace/trace_sched_wakeup.c +66 -1
@@ -30,6 +30,69 @@ static DEFINE_SPINLOCK(wakeup_lock);static void __wakeup_reset (struct trace_array *tr); +#ifdef CONFIG_FTRACE +/* +* irqsoff uses its own tracer function to keep the overhead down: +*/ +static void +wakeup_tracer_call (unsigned long ip,unsigned long parent_ip) +{ +struct trace_array *tr = wakeup_trace; +struct trace_array_cpu *data; +unsigned long flags; +long disabled; +int resched; +int cpu; + +if (likely (!wakeup_task)) +return ; + + resched =need_resched (); +preempt_disable_notrace (); + + cpu =raw_smp_processor_id (); + data = tr->data[cpu]; + disabled =atomic_inc_return (&data->disabled); +if (unlikely (disabled !=1 )) + goto out; + +spin_lock_irqsave (&wakeup_lock, flags); + +if (unlikely (!wakeup_task)) + goto unlock; + +/* +* The task can't disappear because it needs to +* wake up first, and we have the wakeup_lock. +*/ +if (task_cpu (wakeup_task) != cpu) + goto unlock; + +trace_function (tr, data, ip, parent_ip, flags); + + unlock: +spin_unlock_irqrestore (&wakeup_lock, flags); + + out: +atomic_dec (&data->disabled); + +/* +* To prevent recursion from the scheduler, if the +* resched flag was set before we entered, then +* don't reschedule. +*/ +if (resched) +preempt_enable_no_resched_notrace (); +else +preempt_enable_notrace (); +} + +static struct ftrace_ops trace_ops__read_mostly = +{ + .func = wakeup_tracer_call, +}; +#endif /* CONFIG_FTRACE */ +/* * Should this new latency be reported/recorded? */
@@ -73,7 +136,7 @@ wakeup_sched_switch(void *private, voidif (next != wakeup_task)return ; -/* The task we are waitng for is waking up */ +/* The task we are waiting for is waking up */ data = tr->data[wakeup_cpu];/* disable local data, not wakeup_cpu data */
@@ -290,6 +353,7 @@ static void start_wakeup_tracer(struct tsmp_wmb (); tracer_enabled =1 ; +register_ftrace_function (&trace_ops);return ; fail_deprobe_wake_new:
@@ -305,6 +369,7 @@ fail_deprobe:static void stop_wakeup_tracer (struct trace_array *tr) { tracer_enabled =0 ; +unregister_ftrace_function (&trace_ops);marker_probe_unregister ("kernel_sched_schedule" , sched_switch_callback, &wakeup_trace);
Steven Rostedt
maintainerPATCH 5/5 ftrace: remove printks from irqsoff trace
In reply to Steven RostedtPrinting out new max latencies was fine for the old RT tracer. But for mainline it is a bit messy. We also need to test if the run queue is locked before we can do the print. This means that we may not be printing out latencies if the run queue is locked on another CPU. This produces inconsistencies in the output.
This patch simply removes the print altogether.
--- kernel/trace/trace_irqsoff.c | 16 ---------------- 1 file changed, 16 deletions(-)
kernel/trace/trace_irqsoff.c +0 -16
@@ -165,22 +165,6 @@ check_critical_timing(struct trace_arrayupdate_max_tr_single (tr, current, cpu); -if (!runqueue_is_locked ()) { -if (tracing_thresh) { -printk (KERN_INFO "(%16s-%-5d|#%d): %lu us critical" -" section violates %lu us threshold.\n" , - current->comm, current->pid, -raw_smp_processor_id (), - latency,nsecs_to_usecs (tracing_thresh)); - }else { -printk (KERN_INFO "(%16s-%-5d|#%d): new %lu us" -" maximum-latency critical section.\n" , - current->comm, current->pid, -raw_smp_processor_id (), - latency); - } - } - max_sequence++; out_unlock: