aboutsummaryrefslogtreecommitdiffstats
path: root/include/trace
diff options
context:
space:
mode:
authorFrederic Weisbecker <fweisbec@gmail.com>2008-11-11 17:24:42 -0500
committerIngo Molnar <mingo@elte.hu>2008-11-12 04:17:19 -0500
commit74239072830ef3f1398edeb1bc1076fc330fd4a2 (patch)
tree60a244c6c88d9943760ded98a1a29ce018292107 /include/trace
parent3f5ec13696fd4a33bde42f385406cbb1d3cc96fd (diff)
tracing/fastboot: Use the ring-buffer timestamp for initcall entries
Impact: Split the boot tracer entries in two parts: call and return Now that we are using the sched tracer from the boot tracer, we want to use the same timestamp than the ring-buffer to have consistent time captures between sched events and initcall events. So we get rid of the old time capture by the boot tracer and split the initcall events in two parts: call and return. This way we have the ring buffer timestamp of both. An example trace: [ 27.904149584] calling net_ns_init+0x0/0x1c0 @ 1 [ 27.904429624] initcall net_ns_init+0x0/0x1c0 returned 0 after 0 msecs [ 27.904575926] calling reboot_init+0x0/0x20 @ 1 [ 27.904655399] initcall reboot_init+0x0/0x20 returned 0 after 0 msecs [ 27.904800228] calling sysctl_init+0x0/0x30 @ 1 [ 27.905142914] initcall sysctl_init+0x0/0x30 returned 0 after 0 msecs [ 27.905287211] calling ksysfs_init+0x0/0xb0 @ 1 ##### CPU 0 buffer started #### init-1 [000] 27.905395: 1:120:R + [001] 11:115:S ##### CPU 1 buffer started #### <idle>-0 [001] 27.905425: 0:140:R ==> [001] 11:115:R init-1 [000] 27.905426: 1:120:D ==> [000] 0:140:R <idle>-0 [000] 27.905431: 0:140:R + [000] 4:115:S <idle>-0 [000] 27.905451: 0:140:R ==> [000] 4:115:R ksoftirqd/0-4 [000] 27.905456: 4:115:S ==> [000] 0:140:R udevd-11 [001] 27.905458: 11:115:R + [001] 14:115:R <idle>-0 [000] 27.905459: 0:140:R + [000] 4:115:S <idle>-0 [000] 27.905462: 0:140:R ==> [000] 4:115:R udevd-11 [001] 27.905462: 11:115:R ==> [001] 14:115:R ksoftirqd/0-4 [000] 27.905467: 4:115:S ==> [000] 0:140:R <idle>-0 [000] 27.905470: 0:140:R + [000] 4:115:S <idle>-0 [000] 27.905473: 0:140:R ==> [000] 4:115:R ksoftirqd/0-4 [000] 27.905476: 4:115:S ==> [000] 0:140:R <idle>-0 [000] 27.905479: 0:140:R + [000] 4:115:S <idle>-0 [000] 27.905482: 0:140:R ==> [000] 4:115:R ksoftirqd/0-4 [000] 27.905486: 4:115:S ==> [000] 0:140:R udevd-14 [001] 27.905499: 14:120:X ==> [001] 11:115:R udevd-11 [001] 27.905506: 11:115:R + [000] 1:120:D <idle>-0 [000] 27.905515: 0:140:R ==> [000] 1:120:R udevd-11 [001] 27.905517: 11:115:S ==> [001] 0:140:R [ 27.905557107] initcall ksysfs_init+0x0/0xb0 returned 0 after 3906 msecs [ 27.905705736] calling init_jiffies_clocksource+0x0/0x10 @ 1 [ 27.905779239] initcall init_jiffies_clocksource+0x0/0x10 returned 0 after 0 msecs [ 27.906769814] calling pm_init+0x0/0x30 @ 1 [ 27.906853627] initcall pm_init+0x0/0x30 returned 0 after 0 msecs [ 27.906997803] calling pm_disk_init+0x0/0x20 @ 1 [ 27.907076946] initcall pm_disk_init+0x0/0x20 returned 0 after 0 msecs [ 27.907222556] calling swsusp_header_init+0x0/0x30 @ 1 [ 27.907294325] initcall swsusp_header_init+0x0/0x30 returned 0 after 0 msecs [ 27.907439620] calling stop_machine_init+0x0/0x50 @ 1 init-1 [000] 27.907485: 1:120:R + [000] 2:115:S init-1 [000] 27.907490: 1:120:D ==> [000] 2:115:R kthreadd-2 [000] 27.907507: 2:115:R + [001] 15:115:R <idle>-0 [001] 27.907517: 0:140:R ==> [001] 15:115:R kthreadd-2 [000] 27.907517: 2:115:D ==> [000] 0:140:R <idle>-0 [000] 27.907521: 0:140:R + [000] 4:115:S <idle>-0 [000] 27.907524: 0:140:R ==> [000] 4:115:R udevd-15 [001] 27.907527: 15:115:D + [000] 2:115:D ksoftirqd/0-4 [000] 27.907537: 4:115:S ==> [000] 2:115:R udevd-15 [001] 27.907537: 15:115:D ==> [001] 0:140:R kthreadd-2 [000] 27.907546: 2:115:R + [000] 1:120:D kthreadd-2 [000] 27.907550: 2:115:S ==> [000] 1:120:R init-1 [000] 27.907584: 1:120:R + [000] 15: 0:D init-1 [000] 27.907589: 1:120:R + [000] 2:115:S init-1 [000] 27.907593: 1:120:D ==> [000] 15: 0:R udevd-15 [000] 27.907601: 15: 0:S ==> [000] 2:115:R ##### CPU 0 buffer started #### kthreadd-2 [000] 27.907616: 2:115:R + [001] 16:115:R ##### CPU 1 buffer started #### <idle>-0 [001] 27.907620: 0:140:R ==> [001] 16:115:R kthreadd-2 [000] 27.907621: 2:115:D ==> [000] 0:140:R udevd-16 [001] 27.907625: 16:115:D + [000] 2:115:D <idle>-0 [000] 27.907628: 0:140:R + [000] 4:115:S udevd-16 [001] 27.907629: 16:115:D ==> [001] 0:140:R <idle>-0 [000] 27.907631: 0:140:R ==> [000] 4:115:R ksoftirqd/0-4 [000] 27.907636: 4:115:S ==> [000] 2:115:R kthreadd-2 [000] 27.907644: 2:115:R + [000] 1:120:D kthreadd-2 [000] 27.907647: 2:115:S ==> [000] 1:120:R init-1 [000] 27.907657: 1:120:R + [001] 16: 0:D <idle>-0 [001] 27.907666: 0:140:R ==> [001] 16: 0:R [ 27.907703862] initcall stop_machine_init+0x0/0x50 returned 0 after 0 msecs [ 27.907850704] calling filelock_init+0x0/0x30 @ 1 [ 27.907926573] initcall filelock_init+0x0/0x30 returned 0 after 0 msecs [ 27.908071327] calling init_script_binfmt+0x0/0x10 @ 1 [ 27.908165195] initcall init_script_binfmt+0x0/0x10 returned 0 after 0 msecs [ 27.908309461] calling init_elf_binfmt+0x0/0x10 @ 1 Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com> Acked-by: Steven Rostedt <rostedt@goodmis.org> Signed-off-by: Ingo Molnar <mingo@elte.hu>
Diffstat (limited to 'include/trace')
-rw-r--r--include/trace/boot.h31
1 files changed, 22 insertions, 9 deletions
diff --git a/include/trace/boot.h b/include/trace/boot.h
index 4cbe64e46cdc..6b54537eab02 100644
--- a/include/trace/boot.h
+++ b/include/trace/boot.h
@@ -2,22 +2,30 @@
2#define _LINUX_TRACE_BOOT_H 2#define _LINUX_TRACE_BOOT_H
3 3
4/* 4/*
5 * Structure which defines the trace of an initcall. 5 * Structure which defines the trace of an initcall
6 * while it is called.
6 * You don't have to fill the func field since it is 7 * You don't have to fill the func field since it is
7 * only used internally by the tracer. 8 * only used internally by the tracer.
8 */ 9 */
9struct boot_trace { 10struct boot_trace_call {
10 pid_t caller; 11 pid_t caller;
11 char func[KSYM_NAME_LEN]; 12 char func[KSYM_NAME_LEN];
12 int result; 13};
13 unsigned long long duration; /* usecs */ 14
14 ktime_t calltime; 15/*
15 ktime_t rettime; 16 * Structure which defines the trace of an initcall
17 * while it returns.
18 */
19struct boot_trace_ret {
20 char func[KSYM_NAME_LEN];
21 int result;
22 unsigned long long duration; /* nsecs */
16}; 23};
17 24
18#ifdef CONFIG_BOOT_TRACER 25#ifdef CONFIG_BOOT_TRACER
19/* Append the trace on the ring-buffer */ 26/* Append the traces on the ring-buffer */
20extern void trace_boot(struct boot_trace *it, initcall_t fn); 27extern void trace_boot_call(struct boot_trace_call *bt, initcall_t fn);
28extern void trace_boot_ret(struct boot_trace_ret *bt, initcall_t fn);
21 29
22/* Tells the tracer that smp_pre_initcall is finished. 30/* Tells the tracer that smp_pre_initcall is finished.
23 * So we can start the tracing 31 * So we can start the tracing
@@ -34,7 +42,12 @@ extern void enable_boot_trace(void);
34 */ 42 */
35extern void disable_boot_trace(void); 43extern void disable_boot_trace(void);
36#else 44#else
37static inline void trace_boot(struct boot_trace *it, initcall_t fn) { } 45static inline
46void trace_boot_call(struct boot_trace_call *bt, initcall_t fn) { }
47
48static inline
49void trace_boot_ret(struct boot_trace_ret *bt, initcall_t fn) { }
50
38static inline void start_boot_trace(void) { } 51static inline void start_boot_trace(void) { }
39static inline void enable_boot_trace(void) { } 52static inline void enable_boot_trace(void) { }
40static inline void disable_boot_trace(void) { } 53static inline void disable_boot_trace(void) { }
generated by cgit v1.2.2 (git 2.25.0) at 2024-11-24 12:27:09 -0500