| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Tue, 23 Mar 2010 21:19:16 -0400
From: Steven Rostedt <rostedt@...dmis.org>
To: Jiri Olsa <jolsa@...hat.com>
Cc: linux-kernel@...r.kernel.org
Subject: Re: [PATCHv2 2/4] tracing: graph output support for irqsoff tracer
On Wed, 2010-03-10 at 08:51 +0100, Jiri Olsa wrote:
> @@ -993,14 +991,6 @@ print_graph_comment(struct trace_seq *s, struct trace_entry *ent,
> if (ret != TRACE_TYPE_HANDLED)
> return ret;
> break;
> - default:
> - event = ftrace_find_event(ent->type);
> - if (!event)
> - return TRACE_TYPE_UNHANDLED;
> -
> - ret = event->trace(iter, sym_flags);
> - if (ret != TRACE_TYPE_HANDLED)
> - return ret;
> }
>
This has the same effect as the problem with the first patch:
was:
2) | _raw_spin_unlock_irqrestore() {
2) | /* lock_release: ffffffff816969a8 random_read_wait.lock */
2) 6.022 us | }
2) + 27.632 us | }
2) 2.939 us | kill_fasync();
2) | _raw_spin_unlock_irqrestore() {
2) | /* lock_release: ffffffff816967f0 &input_pool.lock */
2) 5.471 us | }
2) + 56.740 us | }
2) + 88.357 us | }
2) + 94.026 us | }
is now:
2) | _raw_spin_unlock_irqrestore() {
<idle>-0 [002] 411.798721: lock_release: ffffffff816969a8 random_read_wait.lock
2) 6.022 us | }
2) + 27.632 us | }
2) 2.939 us | kill_fasync();
2) | _raw_spin_unlock_irqrestore() {
<idle>-0 [002] 411.798741: lock_release: ffffffff816967f0 &input_pool.lock
2) 5.471 us | }
2) + 56.740 us | }
2) + 88.357 us | }
2) + 94.026 us | }
Please, before you apply any patch do the following:
(assuming debugfs is at /debug)
# echo 1 > /debug/tracing/events/enable
# echo function_graph > /debug/tracing/current_tracer
# cat /debug/tracing/trace
Examine what you see.
Then apply all your patches, and repeat the above. Make sure the
formatting is the same.
Thanks,
-- Steve
> /* Strip ending newline */
> @@ -1066,8 +1056,11 @@ print_graph_function(struct trace_iterator *iter)
> trace_assign_type(field, entry);
> return print_graph_return(&field->ret, s, entry, iter);
> }
> - default:
> + case TRACE_BPRINT:
> + case TRACE_PRINT:
> return print_graph_comment(s, entry, iter);
> + default:
> + return TRACE_TYPE_UNHANDLED;
> }
>
> return TRACE_TYPE_HANDLED;
> @@ -1101,7 +1094,7 @@ static void print_lat_header(struct seq_file *s)
> seq_printf(s, "#%.*s|||| / \n", size, spaces);
> }
>
> -static void print_graph_headers(struct seq_file *s)
> +void print_graph_headers(struct seq_file *s)
> {
> int lat = trace_flags & TRACE_ITER_LATENCY_FMT;
>
> @@ -1137,7 +1130,7 @@ static void print_graph_headers(struct seq_file *s)
> seq_printf(s, " | | | |\n");
> }
>
> -static void graph_trace_open(struct trace_iterator *iter)
> +void graph_trace_open(struct trace_iterator *iter)
> {
> /* pid and depth on the last trace processed */
> struct fgraph_data *data;
> @@ -1172,7 +1165,7 @@ static void graph_trace_open(struct trace_iterator *iter)
> pr_warning("function graph tracer: not enough memory\n");
> }
>
> -static void graph_trace_close(struct trace_iterator *iter)
> +void graph_trace_close(struct trace_iterator *iter)
> {
> struct fgraph_data *data = iter->private;
>
> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
> index 2974bc7..d0c6d6c 100644
> --- a/kernel/trace/trace_irqsoff.c
> +++ b/kernel/trace/trace_irqsoff.c
> @@ -34,6 +34,9 @@ static int trace_type __read_mostly;
>
> static int save_lat_flag;
>
> +static void stop_irqsoff_tracer(struct trace_array *tr, int graph);
> +static int start_irqsoff_tracer(struct trace_array *tr, int graph);
> +
> #ifdef CONFIG_PREEMPT_TRACER
> static inline int
> preempt_trace(void)
> @@ -55,6 +58,23 @@ irq_trace(void)
> # define irq_trace() (0)
> #endif
>
> +#define TRACE_DISPLAY_GRAPH 1
> +
> +static struct tracer_opt trace_opts[] = {
> +#ifdef CONFIG_FUNCTION_GRAPH_TRACER
> + /* display latency trace as call graph */
> + { TRACER_OPT(display-graph, TRACE_DISPLAY_GRAPH) },
> +#endif
> + { } /* Empty entry */
> +};
> +
> +static struct tracer_flags tracer_flags = {
> + .val = 0,
> + .opts = trace_opts,
> +};
> +
> +#define is_graph() (tracer_flags.val & TRACE_DISPLAY_GRAPH)
> +
> /*
> * Sequence count - we record it when starting a measurement and
> * skip the latency if the sequence has changed - some other section
> @@ -108,6 +128,109 @@ static struct ftrace_ops trace_ops __read_mostly =
> };
> #endif /* CONFIG_FUNCTION_TRACER */
>
> +#ifdef CONFIG_FUNCTION_GRAPH_TRACER
> +static int irqsoff_set_flag(u32 old_flags, u32 bit, int set)
> +{
> + int cpu;
> +
> + if (!(bit & TRACE_DISPLAY_GRAPH))
> + return -EINVAL;
> +
> + if (!(is_graph() ^ set))
> + return 0;
> +
> + stop_irqsoff_tracer(irqsoff_trace, !set);
> +
> + for_each_possible_cpu(cpu)
> + per_cpu(tracing_cpu, cpu) = 0;
> +
> + tracing_max_latency = 0;
> + tracing_reset_online_cpus(irqsoff_trace);
> +
> + return start_irqsoff_tracer(irqsoff_trace, set);
> +}
> +
> +static int irqsoff_graph_entry(struct ftrace_graph_ent *trace)
> +{
> + struct trace_array *tr = irqsoff_trace;
> + struct trace_array_cpu *data;
> + unsigned long flags;
> + long disabled;
> + int ret;
> + int cpu;
> + int pc;
> +
> + cpu = raw_smp_processor_id();
> + if (likely(!per_cpu(tracing_cpu, cpu)))
> + return 0;
> +
> + local_save_flags(flags);
> + /* slight chance to get a false positive on tracing_cpu */
> + if (!irqs_disabled_flags(flags))
> + return 0;
> +
> + data = tr->data[cpu];
> + disabled = atomic_inc_return(&data->disabled);
> +
> + if (likely(disabled == 1)) {
> + pc = preempt_count();
> + ret = __trace_graph_entry(tr, trace, flags, pc);
> + } else
> + ret = 0;
> +
> + atomic_dec(&data->disabled);
> + return ret;
> +}
> +
> +static void irqsoff_graph_return(struct ftrace_graph_ret *trace)
> +{
> + struct trace_array *tr = irqsoff_trace;
> + struct trace_array_cpu *data;
> + unsigned long flags;
> + long disabled;
> + int cpu;
> + int pc;
> +
> + cpu = raw_smp_processor_id();
> + if (likely(!per_cpu(tracing_cpu, cpu)))
> + return;
> +
> + local_save_flags(flags);
> + /* slight chance to get a false positive on tracing_cpu */
> + if (!irqs_disabled_flags(flags))
> + return;
> +
> + data = tr->data[cpu];
> + disabled = atomic_inc_return(&data->disabled);
> +
> + if (likely(disabled == 1)) {
> + pc = preempt_count();
> + __trace_graph_return(tr, trace, flags, pc);
> + }
> +
> + atomic_dec(&data->disabled);
> +}
> +
> +static void irqsoff_trace_open(struct trace_iterator *iter)
> +{
> + if (is_graph())
> + graph_trace_open(iter);
> +
> +}
> +
> +static void irqsoff_trace_close(struct trace_iterator *iter)
> +{
> + if (iter->private)
> + graph_trace_close(iter);
> +}
> +
> +#else
> +static int irqsoff_set_flag(u32 old_flags, u32 bit, int set)
> +{
> + return -EINVAL;
> +}
> +#endif /* CONFIG_FUNCTION_GRAPH_TRACER */
> +
> /*
> * Should this new latency be reported/recorded?
> */
> @@ -347,19 +470,36 @@ void trace_preempt_off(unsigned long a0, unsigned long a1)
> }
> #endif /* CONFIG_PREEMPT_TRACER */
>
> -static void start_irqsoff_tracer(struct trace_array *tr)
> +static int start_irqsoff_tracer(struct trace_array *tr, int graph)
> {
> - register_ftrace_function(&trace_ops);
> - if (tracing_is_enabled())
> + int ret = 0;
> +
> + if (!graph)
> + ret = register_ftrace_function(&trace_ops);
> +#ifdef CONFIG_FUNCTION_GRAPH_TRACER
> + else
> + ret = register_ftrace_graph(&irqsoff_graph_return,
> + &irqsoff_graph_entry);
> +#endif
> +
> + if (!ret && tracing_is_enabled())
> tracer_enabled = 1;
> else
> tracer_enabled = 0;
> +
> + return ret;
> }
>
> -static void stop_irqsoff_tracer(struct trace_array *tr)
> +static void stop_irqsoff_tracer(struct trace_array *tr, int graph)
> {
> tracer_enabled = 0;
> - unregister_ftrace_function(&trace_ops);
> +
> + if (!graph)
> + unregister_ftrace_function(&trace_ops);
> +#ifdef CONFIG_FUNCTION_GRAPH_TRACER
> + else
> + unregister_ftrace_graph();
> +#endif
> }
>
> static void __irqsoff_tracer_init(struct trace_array *tr)
> @@ -372,12 +512,14 @@ static void __irqsoff_tracer_init(struct trace_array *tr)
> /* make sure that the tracer is visible */
> smp_wmb();
> tracing_reset_online_cpus(tr);
> - start_irqsoff_tracer(tr);
> +
> + if (start_irqsoff_tracer(tr, is_graph()))
> + printk(KERN_ERR "failed to start irqsoff tracer\n");
> }
>
> static void irqsoff_tracer_reset(struct trace_array *tr)
> {
> - stop_irqsoff_tracer(tr);
> + stop_irqsoff_tracer(tr, is_graph());
>
> if (!save_lat_flag)
> trace_flags &= ~TRACE_ITER_LATENCY_FMT;
> @@ -409,9 +551,15 @@ static struct tracer irqsoff_tracer __read_mostly =
> .start = irqsoff_tracer_start,
> .stop = irqsoff_tracer_stop,
> .print_max = 1,
> + .flags = &tracer_flags,
> + .set_flag = irqsoff_set_flag,
> #ifdef CONFIG_FTRACE_SELFTEST
> .selftest = trace_selftest_startup_irqsoff,
> #endif
> +#ifdef CONFIG_FUNCTION_GRAPH_TRACER
> + .open = irqsoff_trace_open,
> + .close = irqsoff_trace_close,
> +#endif
> };
> # define register_irqsoff(trace) register_tracer(&trace)
> #else
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists