[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <48F10A9D.3030705@gmail.com>
Date: Sat, 11 Oct 2008 22:20:45 +0200
From: Frederic Weisbecker <fweisbec@...il.com>
To: Ingo Molnar <mingo@...e.hu>
CC: Steven Rostedt <rostedt@...dmis.org>, linux-kernel@...r.kernel.org,
Arjan van de Ven <arjan@...ux.intel.com>
Subject: [PATCH 4/5] tracing/fastboot: Add a time field on the sched_switch
entry
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);
}
@@ -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)
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