Skip to content

Commit

Permalink
---
Browse files Browse the repository at this point in the history
yaml
---
r: 121095
b: refs/heads/master
c: 7423907
h: refs/heads/master
i:
  121093: bbc8b29
  121091: c119b45
  121087: 0d6bdd5
v: v3
  • Loading branch information
Frederic Weisbecker authored and Ingo Molnar committed Nov 12, 2008
1 parent 0ca157f commit 3e8e518
Show file tree
Hide file tree
Showing 5 changed files with 145 additions and 60 deletions.
2 changes: 1 addition & 1 deletion [refs]
Original file line number Diff line number Diff line change
@@ -1,2 +1,2 @@
---
refs/heads/master: 3f5ec13696fd4a33bde42f385406cbb1d3cc96fd
refs/heads/master: 74239072830ef3f1398edeb1bc1076fc330fd4a2
31 changes: 22 additions & 9 deletions trunk/include/trace/boot.h
Original file line number Diff line number Diff line change
Expand Up @@ -2,22 +2,30 @@
#define _LINUX_TRACE_BOOT_H

/*
* Structure which defines the trace of an initcall.
* Structure which defines the trace of an initcall
* while it is called.
* You don't have to fill the func field since it is
* only used internally by the tracer.
*/
struct boot_trace {
struct boot_trace_call {
pid_t caller;
char func[KSYM_NAME_LEN];
int result;
unsigned long long duration; /* usecs */
ktime_t calltime;
ktime_t rettime;
};

/*
* Structure which defines the trace of an initcall
* while it returns.
*/
struct boot_trace_ret {
char func[KSYM_NAME_LEN];
int result;
unsigned long long duration; /* nsecs */
};

#ifdef CONFIG_BOOT_TRACER
/* Append the trace on the ring-buffer */
extern void trace_boot(struct boot_trace *it, initcall_t fn);
/* Append the traces on the ring-buffer */
extern void trace_boot_call(struct boot_trace_call *bt, initcall_t fn);
extern void trace_boot_ret(struct boot_trace_ret *bt, initcall_t fn);

/* Tells the tracer that smp_pre_initcall is finished.
* So we can start the tracing
Expand All @@ -34,7 +42,12 @@ extern void enable_boot_trace(void);
*/
extern void disable_boot_trace(void);
#else
static inline void trace_boot(struct boot_trace *it, initcall_t fn) { }
static inline
void trace_boot_call(struct boot_trace_call *bt, initcall_t fn) { }

static inline
void trace_boot_ret(struct boot_trace_ret *bt, initcall_t fn) { }

static inline void start_boot_trace(void) { }
static inline void enable_boot_trace(void) { }
static inline void disable_boot_trace(void) { }
Expand Down
32 changes: 17 additions & 15 deletions trunk/init/main.c
Original file line number Diff line number Diff line change
Expand Up @@ -704,33 +704,35 @@ core_param(initcall_debug, initcall_debug, bool, 0644);
int do_one_initcall(initcall_t fn)
{
int count = preempt_count();
ktime_t delta;
ktime_t calltime, delta, rettime;
char msgbuf[64];
struct boot_trace it;
struct boot_trace_call call;
struct boot_trace_ret ret;

if (initcall_debug) {
it.caller = task_pid_nr(current);
printk("calling %pF @ %i\n", fn, it.caller);
it.calltime = ktime_get();
call.caller = task_pid_nr(current);
printk("calling %pF @ %i\n", fn, call.caller);
calltime = ktime_get();
trace_boot_call(&call, fn);
enable_boot_trace();
}

it.result = fn();
ret.result = fn();

if (initcall_debug) {
it.rettime = ktime_get();
delta = ktime_sub(it.rettime, it.calltime);
it.duration = (unsigned long long) delta.tv64 >> 10;
printk("initcall %pF returned %d after %Ld usecs\n", fn,
it.result, it.duration);
trace_boot(&it, fn);
disable_boot_trace();
rettime = ktime_get();
delta = ktime_sub(rettime, calltime);
ret.duration = (unsigned long long) delta.tv64 >> 10;
trace_boot_ret(&ret, fn);
printk("initcall %pF returned %d after %Ld usecs\n", fn,
ret.result, ret.duration);
}

msgbuf[0] = 0;

if (it.result && it.result != -ENODEV && initcall_debug)
sprintf(msgbuf, "error code %d ", it.result);
if (ret.result && ret.result != -ENODEV && initcall_debug)
sprintf(msgbuf, "error code %d ", ret.result);

if (preempt_count() != count) {
strlcat(msgbuf, "preemption imbalance ", sizeof(msgbuf));
Expand All @@ -744,7 +746,7 @@ int do_one_initcall(initcall_t fn)
printk("initcall %pF returned with %s\n", fn, msgbuf);
}

return it.result;
return ret.result;
}


Expand Down
17 changes: 12 additions & 5 deletions trunk/kernel/trace/trace.h
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,8 @@ enum trace_type {
TRACE_SPECIAL,
TRACE_MMIO_RW,
TRACE_MMIO_MAP,
TRACE_BOOT,
TRACE_BOOT_CALL,
TRACE_BOOT_RET,
TRACE_FN_RET,

__TRACE_LAST_TYPE
Expand Down Expand Up @@ -123,9 +124,14 @@ struct trace_mmiotrace_map {
struct mmiotrace_map map;
};

struct trace_boot {
struct trace_boot_call {
struct trace_entry ent;
struct boot_trace initcall;
struct boot_trace_call boot_call;
};

struct trace_boot_ret {
struct trace_entry ent;
struct boot_trace_ret boot_ret;
};

/*
Expand Down Expand Up @@ -228,8 +234,9 @@ extern void __ftrace_bad_type(void);
TRACE_MMIO_RW); \
IF_ASSIGN(var, ent, struct trace_mmiotrace_map, \
TRACE_MMIO_MAP); \
IF_ASSIGN(var, ent, struct trace_boot, TRACE_BOOT); \
IF_ASSIGN(var, ent, struct ftrace_ret_entry, TRACE_FN_RET); \
IF_ASSIGN(var, ent, struct trace_boot_call, TRACE_BOOT_CALL);\
IF_ASSIGN(var, ent, struct trace_boot_ret, TRACE_BOOT_RET);\
IF_ASSIGN(var, ent, struct ftrace_ret_entry, TRACE_FN_RET);\
__ftrace_bad_type(); \
} while (0)

Expand Down
123 changes: 93 additions & 30 deletions trunk/kernel/trace/trace_boot.c
Original file line number Diff line number Diff line change
Expand Up @@ -58,35 +58,71 @@ static void boot_trace_init(struct trace_array *tr)
tracing_sched_switch_assign_trace(tr);
}

static enum print_line_t initcall_print_line(struct trace_iterator *iter)
static enum print_line_t
initcall_call_print_line(struct trace_iterator *iter)
{
struct trace_entry *entry = iter->ent;
struct trace_seq *s = &iter->seq;
struct trace_boot_call *field;
struct boot_trace_call *call;
u64 ts;
unsigned long nsec_rem;
int ret;

trace_assign_type(field, entry);
call = &field->boot_call;
ts = iter->ts;
nsec_rem = do_div(ts, 1000000000);

ret = trace_seq_printf(s, "[%5ld.%09ld] calling %s @ %i\n",
(unsigned long)ts, nsec_rem, call->func, call->caller);

if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
else
return TRACE_TYPE_HANDLED;
}

static enum print_line_t
initcall_ret_print_line(struct trace_iterator *iter)
{
struct trace_entry *entry = iter->ent;
struct trace_boot *field = (struct trace_boot *)entry;
struct boot_trace *it = &field->initcall;
struct trace_seq *s = &iter->seq;
struct timespec calltime = ktime_to_timespec(it->calltime);
struct timespec rettime = ktime_to_timespec(it->rettime);

if (entry->type == TRACE_BOOT) {
ret = trace_seq_printf(s, "[%5ld.%09ld] calling %s @ %i\n",
calltime.tv_sec,
calltime.tv_nsec,
it->func, it->caller);
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;

ret = trace_seq_printf(s, "[%5ld.%09ld] initcall %s "
"returned %d after %lld msecs\n",
rettime.tv_sec,
rettime.tv_nsec,
it->func, it->result, it->duration);

if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
struct trace_boot_ret *field;
struct boot_trace_ret *init_ret;
u64 ts;
unsigned long nsec_rem;
int ret;

trace_assign_type(field, entry);
init_ret = &field->boot_ret;
ts = iter->ts;
nsec_rem = do_div(ts, 1000000000);

ret = trace_seq_printf(s, "[%5ld.%09ld] initcall %s "
"returned %d after %llu msecs\n",
(unsigned long) ts,
nsec_rem,
init_ret->func, init_ret->result, init_ret->duration);

if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
else
return TRACE_TYPE_HANDLED;
}

static enum print_line_t initcall_print_line(struct trace_iterator *iter)
{
struct trace_entry *entry = iter->ent;

switch (entry->type) {
case TRACE_BOOT_CALL:
return initcall_call_print_line(iter);
case TRACE_BOOT_RET:
return initcall_ret_print_line(iter);
default:
return TRACE_TYPE_UNHANDLED;
}
return TRACE_TYPE_UNHANDLED;
}

struct tracer boot_tracer __read_mostly =
Expand All @@ -97,11 +133,10 @@ struct tracer boot_tracer __read_mostly =
.print_line = initcall_print_line,
};

void trace_boot(struct boot_trace *it, initcall_t fn)
void trace_boot_call(struct boot_trace_call *bt, initcall_t fn)
{
struct ring_buffer_event *event;
struct trace_boot *entry;
struct trace_array_cpu *data;
struct trace_boot_call *entry;
unsigned long irq_flags;
struct trace_array *tr = boot_trace;

Expand All @@ -111,18 +146,46 @@ void trace_boot(struct boot_trace *it, initcall_t fn)
/* Get its name now since this function could
* disappear because it is in the .init section.
*/
sprint_symbol(it->func, (unsigned long)fn);
sprint_symbol(bt->func, (unsigned long)fn);
preempt_disable();

event = ring_buffer_lock_reserve(tr->buffer, sizeof(*entry),
&irq_flags);
if (!event)
goto out;
entry = ring_buffer_event_data(event);
tracing_generic_entry_update(&entry->ent, 0, 0);
entry->ent.type = TRACE_BOOT_CALL;
entry->boot_call = *bt;
ring_buffer_unlock_commit(tr->buffer, event, irq_flags);

trace_wake_up();

out:
preempt_enable();
}

void trace_boot_ret(struct boot_trace_ret *bt, initcall_t fn)
{
struct ring_buffer_event *event;
struct trace_boot_ret *entry;
unsigned long irq_flags;
struct trace_array *tr = boot_trace;

if (!pre_initcalls_finished)
return;

sprint_symbol(bt->func, (unsigned long)fn);
preempt_disable();
data = tr->data[smp_processor_id()];

event = ring_buffer_lock_reserve(tr->buffer, sizeof(*entry),
&irq_flags);
if (!event)
goto out;
entry = ring_buffer_event_data(event);
tracing_generic_entry_update(&entry->ent, 0, 0);
entry->ent.type = TRACE_BOOT;
entry->initcall = *it;
entry->ent.type = TRACE_BOOT_RET;
entry->boot_ret = *bt;
ring_buffer_unlock_commit(tr->buffer, event, irq_flags);

trace_wake_up();
Expand Down

0 comments on commit 3e8e518

Please sign in to comment.