| 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
| ||
|
Message-ID: <alpine.DEB.1.10.0810111644440.19507@gandalf.stny.rr.com>
Date: Sat, 11 Oct 2008 16:45:33 -0400 (EDT)
From: Steven Rostedt <rostedt@...dmis.org>
To: Frederic Weisbecker <fweisbec@...il.com>
cc: Ingo Molnar <mingo@...e.hu>, linux-kernel@...r.kernel.org,
Arjan van de Ven <arjan@...ux.intel.com>
Subject: Re: [PATCH 4/5] tracing/fastboot: Add a time field on the sched_switch
entry
On Sat, 11 Oct 2008, Frederic Weisbecker wrote:
> Add a time field on the sched_switch entry to have a better
> view of the sched events during initcalls.
> Also make the boot tracer able to handle the sched_switches
> events.
>
> Signed-off-by: Frederic Weisbecker <fweisbec@...il.com>
> Cc: Arjan van de Ven <arjan@...ux.intel.com>
> Cc: Steven Rostedt <rostedt@...dmis.org>
> ---
> kernel/trace/trace.c | 4 +-
> kernel/trace/trace.h | 2 +
> kernel/trace/trace_boot.c | 101 +++++++++++++++++++++++++++++++++++---------
> 3 files changed, 85 insertions(+), 22 deletions(-)
>
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index acc21bb..e7d659a 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -622,7 +622,7 @@ static void trace_save_cmdline(struct task_struct *tsk)
> spin_unlock(&trace_cmdline_lock);
> }
>
> -static char *trace_find_cmdline(int pid)
> +char *trace_find_cmdline(int pid)
> {
> char *cmdline = "<...>";
> unsigned map;
> @@ -799,6 +799,7 @@ tracing_sched_switch_trace(struct trace_array *tr,
> entry->next_prio = next->prio;
> entry->next_state = next->state;
> entry->next_cpu = task_cpu(next);
> + entry->time = cpu_clock(raw_smp_processor_id());
> ring_buffer_unlock_commit(tr->buffer, event, irq_flags);
> ftrace_trace_stack(tr, data, flags, 5, pc);
NACK. We already have a time field in the trace buffer.
> }
> @@ -828,6 +829,7 @@ tracing_sched_wakeup_trace(struct trace_array *tr,
> entry->next_prio = wakee->prio;
> entry->next_state = wakee->state;
> entry->next_cpu = task_cpu(wakee);
> + entry->time = cpu_clock(raw_smp_processor_id());
> ring_buffer_unlock_commit(tr->buffer, event, irq_flags);
> ftrace_trace_stack(tr, data, flags, 6, pc);
>
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index d45a3cd..707620c 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -63,6 +63,7 @@ struct ctx_switch_entry {
> unsigned char next_prio;
> unsigned char next_state;
> unsigned int next_cpu;
> + unsigned long long time;
> };
>
> /*
> @@ -392,6 +393,7 @@ extern ssize_t trace_seq_to_user(struct trace_seq *s, char __user *ubuf,
> size_t cnt);
> extern long ns2usecs(cycle_t nsec);
> extern int trace_vprintk(unsigned long ip, const char *fmt, va_list args);
> +extern char *trace_find_cmdline(int pid);
>
> extern unsigned long trace_flags;
>
> diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c
> index 20d326b..316085e 100644
> --- a/kernel/trace/trace_boot.c
> +++ b/kernel/trace/trace_boot.c
> @@ -3,6 +3,8 @@
> *
> * Copyright (C) 2008 Frederic Weisbecker <fweisbec@...il.com>
> *
> + * Some parts of code (IE: sched_switch_print_line function)
> + * have been borrowed from trace.c
> */
>
> #include <linux/init.h>
> @@ -14,6 +16,7 @@
>
> static struct trace_array *boot_trace;
> static bool pre_initcalls_finished;
> +static const char state_to_char[] = TASK_STATE_TO_CHAR_STR;
>
> /* Tells the boot tracer that the pre_smp_initcalls are finished.
> * So we are ready .
> @@ -71,26 +74,82 @@ static enum print_line_t initcall_print_line(struct trace_iterator *iter)
iter->ts has the time value already for you.
-- Steve
> unsigned long sec, nsec_rem;
> unsigned long long duration = it->rettime - it->calltime;
>
> - if (entry->type == TRACE_BOOT) {
> - nsec_rem = do_div(it->calltime, 1000000000);
> - sec = (unsigned long) it->calltime;
> - ret = trace_seq_printf(s, "[%5lu.%09lu] calling %s @ %i\n",
> - sec, nsec_rem, it->func, it->caller);
> - if (!ret)
> - return TRACE_TYPE_PARTIAL_LINE;
> -
> - nsec_rem = do_div(it->rettime, 1000000000);
> - sec = (unsigned long) it->rettime;
> - do_div(duration, 1000);
> - ret = trace_seq_printf(s, "[%5lu.%09lu] initcall %s "
> - "returned %d after %lld msecs\n",
> - sec, nsec_rem, it->func, it->result,
> - duration);
> -
> - if (!ret)
> - return TRACE_TYPE_PARTIAL_LINE;
> - return TRACE_TYPE_HANDLED;
> - }
> + nsec_rem = do_div(it->calltime, 1000000000);
> + sec = (unsigned long) it->calltime;
> + ret = trace_seq_printf(s, "[%5lu.%09lu] calling %s @ %i\n",
> + sec, nsec_rem, it->func, it->caller);
> + if (!ret)
> + return TRACE_TYPE_PARTIAL_LINE;
> +
> + nsec_rem = do_div(it->rettime, 1000000000);
> + sec = (unsigned long) it->rettime;
> + do_div(duration, 1000);
> + ret = trace_seq_printf(s, "[%5lu.%09lu] initcall %s "
> + "returned %d after %llu msecs\n",
> + sec, nsec_rem, it->func, it->result,
> + duration);
> +
> + if (!ret)
> + return TRACE_TYPE_PARTIAL_LINE;
> +
> + return TRACE_TYPE_HANDLED;
> +}
> +
> +static enum print_line_t sched_switch_print_line(struct trace_iterator *iter)
> +{
> + int ret;
> + struct trace_entry *entry = iter->ent;
> + struct ctx_switch_entry *field;
> + struct trace_seq *s = &iter->seq;
> + int S, T;
> + char *comm;
> + unsigned long sec, nsec_rem;
> +
> + trace_assign_type(field, entry);
> + nsec_rem = do_div(field->time, 1000000000);
> + sec = (unsigned long) field->time;
> +
> + comm = trace_find_cmdline(iter->ent->pid);
> +
> + ret = trace_seq_printf(s, "[%5lu.%09lu] ",
> + sec, nsec_rem);
> +
> + ret = trace_seq_printf(s, "%16s-%-5d ", comm, entry->pid);
> + if (!ret)
> + return TRACE_TYPE_PARTIAL_LINE;
> + ret = trace_seq_printf(s, "[%03d] ", iter->cpu);
> + if (!ret)
> + return TRACE_TYPE_PARTIAL_LINE;
> +
> + if (!ret)
> + return TRACE_TYPE_PARTIAL_LINE;
> +
> + S = field->prev_state < sizeof(state_to_char) ?
> + state_to_char[field->prev_state] : 'X';
> + T = field->next_state < sizeof(state_to_char) ?
> + state_to_char[field->next_state] : 'X';
> + ret = trace_seq_printf(s, " %5d:%3d:%c %s [%03d] %5d:%3d:%c\n",
> + field->prev_pid,
> + field->prev_prio,
> + S,
> + entry->type == TRACE_CTX ? "==>" : " +",
> + field->next_cpu,
> + field->next_pid,
> + field->next_prio,
> + T);
> + if (!ret)
> + return TRACE_TYPE_PARTIAL_LINE;
> + return TRACE_TYPE_HANDLED;
> +}
> +
> +static enum print_line_t boot_trace_print_line(struct trace_iterator *iter)
> +{
> + struct trace_entry *entry = iter->ent;
> +
> + if (entry->type == TRACE_BOOT)
> + return initcall_print_line(iter);
> + if (entry->type == TRACE_CTX || entry->type == TRACE_WAKE)
> + return sched_switch_print_line(iter);
> return TRACE_TYPE_UNHANDLED;
> }
>
> @@ -100,7 +159,7 @@ struct tracer boot_tracer __read_mostly =
> .init = boot_trace_init,
> .reset = reset_boot_trace,
> .ctrl_update = boot_trace_ctrl_update,
> - .print_line = initcall_print_line,
> + .print_line = boot_trace_print_line,
> };
>
> void trace_boot(struct boot_trace *it, initcall_t fn)
>
>
--
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