This defines the basics of a new boot time measurement feature. This allows logging of very accurate time measurements as the boot proceeds, by using an available microsecond counter.
To enable the feature, define CONFIG_BOOTSTAGE in your board config file. Also available is CONFIG_BOOTSTAGE_REPORT which will cause a report to be printed just before handing off to the OS.
Most IDs are not named at this stage. For that I would first like to renumber them all.
Timer summary in microseconds: Mark Elapsed Stage 0 0 reset 205,000 205,000 board_init_f 6,053,000 5,848,000 bootm_start 6,053,000 0 id=1 6,058,000 5,000 id=101 6,058,000 0 id=100 6,061,000 3,000 id=103 6,064,000 3,000 id=104 6,093,000 29,000 id=107 6,093,000 0 id=106 6,093,000 0 id=105 6,093,000 0 id=108 7,089,000 996,000 id=7 7,089,000 0 id=15 7,089,000 0 id=8 7,097,000 8,000 start_kernel
Signed-off-by: Simon Glass sjg@chromium.org --- Changes in v3: - Fix code style in bootstage_mark_name() - Make main bootstage commit title more explicit
Changes in v4: - Print times in unsigned format, and increase range - Remove guards around calls to show_boot_progress() - Sort by unsigned value to account for large time values
README | 25 ++++++++ common/Makefile | 1 + common/bootstage.c | 158 +++++++++++++++++++++++++++++++++++++++++++++++++++ include/bootstage.h | 43 ++++++++++++++ 4 files changed, 227 insertions(+), 0 deletions(-) create mode 100644 common/bootstage.c
diff --git a/README b/README index b6c9d0b..4c21924 100644 --- a/README +++ b/README @@ -2241,6 +2241,31 @@ The following options need to be configured: example, some LED's) on your board. At the moment, the following checkpoints are implemented:
+- Detailed boot stage timing + CONFIG_BOOTSTAGE + Define this option to get detailed timing of each stage + of the boot process. + + CONFIG_BOOTSTAGE_USER_COUNT + This is the number of available user bootstage records. + Each time you call bootstage_mark(BOOTSTAGE_ID_ALLOC, ...) + a new ID will be allocated from this stash. If you exceed + the limit, recording will stop. + + CONFIG_BOOTSTAGE_REPORT + Define this to print a report before boot, similar to this: + + Timer summary in microseconds: + Mark Elapsed Stage + 0 0 reset + 3,575,678 3,575,678 board_init_f start + 3,575,695 17 arch_cpu_init A9 + 3,575,777 82 arch_cpu_init done + 3,659,598 83,821 board_init_r start + 3,910,375 250,777 main_loop + 29,916,167 26,005,792 bootm_start + 30,361,327 445,160 start_kernel + Legacy uImage format:
Arg Where When diff --git a/common/Makefile b/common/Makefile index 2d9ae8c..038baf0 100644 --- a/common/Makefile +++ b/common/Makefile @@ -172,6 +172,7 @@ SPD := y endif COBJS-$(SPD) += ddr_spd.o COBJS-$(CONFIG_HWCONFIG) += hwconfig.o +COBJS-$(CONFIG_BOOTSTAGE) += bootstage.o COBJS-$(CONFIG_CONSOLE_MUX) += iomux.o COBJS-y += flash.o COBJS-$(CONFIG_CMD_KGDB) += kgdb.o kgdb_stubs.o diff --git a/common/bootstage.c b/common/bootstage.c new file mode 100644 index 0000000..d2bbe63 --- /dev/null +++ b/common/bootstage.c @@ -0,0 +1,158 @@ +/* + * Copyright (c) 2011, Google Inc. All rights reserved. + * + * See file CREDITS for list of people who contributed to this + * project. + * + * This program is free software; you can redistribute it and/or + * modify it under the terms of the GNU General Public License as + * published by the Free Software Foundation; either version 2 of + * the License, or (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, + * MA 02111-1307 USA + */ + + +/* + * This module records the progress of boot and arbitrary commands, and + * permits accurate timestamping of each. + * + * TBD: Pass timings to kernel in the FDT + */ + +#include <common.h> +#include <libfdt.h> + +DECLARE_GLOBAL_DATA_PTR; + +enum bootstage_flags { + BOOTSTAGEF_ERROR = 1 << 0, /* Error record */ + BOOTSTAGEF_ALLOC = 1 << 1, /* Allocate an id */ +}; + +struct bootstage_record { + ulong time_us; + const char *name; + int flags; /* see enum bootstage_flags */ + enum bootstage_id id; +}; + +static struct bootstage_record record[BOOTSTAGE_ID_COUNT] = { {1} }; +static int next_id = BOOTSTAGE_ID_USER; + +ulong bootstage_add_record(enum bootstage_id id, const char *name, + int flags) +{ + struct bootstage_record *rec; + ulong mark = timer_get_boot_us(); + + if (flags & BOOTSTAGEF_ALLOC) + id = next_id++; + + if (id < BOOTSTAGE_ID_COUNT) { + rec = &record[id]; + + /* Only record the first event for each */ + if (!rec->time_us) { + rec->time_us = mark; + rec->name = name; + rec->flags = flags; + rec->id = id; + } + } + + /* Tell the board about this progress */ + show_boot_progress(flags & BOOTSTAGEF_ERROR ? -id : id); + return mark; +} + + +ulong bootstage_mark(enum bootstage_id id) +{ + return bootstage_add_record(id, NULL, 0); +} + +ulong bootstage_error(enum bootstage_id id) +{ + return bootstage_add_record(id, NULL, BOOTSTAGEF_ERROR); +} + +ulong bootstage_mark_name(enum bootstage_id id, const char *name) +{ + int flags = 0; + + if (id == BOOTSTAGE_ID_ALLOC) + flags = BOOTSTAGEF_ALLOC; + return bootstage_add_record(id, name, flags); +} + +static void print_time(unsigned long us_time) +{ + char str[15], *s; + int grab = 3; + + /* We don't seem to have %'d in U-Boot */ + sprintf(str, "%12lu", us_time); + for (s = str + 3; *s; s += grab) { + if (s != str + 3) + putc(s[-1] != ' ' ? ',' : ' '); + printf("%.*s", grab, s); + grab = 3; + } +} + +static uint32_t print_time_record(enum bootstage_id id, + struct bootstage_record *rec, uint32_t prev) +{ + print_time(rec->time_us); + print_time(rec->time_us - prev); + if (rec->name) + printf(" %s\n", rec->name); + else if (id >= BOOTSTAGE_ID_USER) + printf(" user_%d\n", id - BOOTSTAGE_ID_USER); + else + printf(" id=%d\n", id); + return rec->time_us; +} + +static int h_compare_record(const void *r1, const void *r2) +{ + const struct bootstage_record *rec1 = r1, *rec2 = r2; + + return rec1->time_us > rec2->time_us ? 1 : -1; +} + +void bootstage_report(void) +{ + struct bootstage_record *rec = record; + int id; + uint32_t prev; + + puts("Timer summary in microseconds:\n"); + printf("%11s%11s %s\n", "Mark", "Elapsed", "Stage"); + + /* Fake the first record - we could get it from early boot */ + rec->name = "reset"; + rec->time_us = 0; + prev = print_time_record(BOOTSTAGE_ID_AWAKE, rec, 0); + + /* Sort records by increasing time */ + qsort(record, ARRAY_SIZE(record), sizeof(*rec), h_compare_record); + + for (id = 0; id < BOOTSTAGE_ID_COUNT; id++, rec++) { + if (rec->time_us != 0) + prev = print_time_record(rec->id, rec, prev); + } + if (next_id > BOOTSTAGE_ID_COUNT) + printf("(Overflowed internal boot id table by %d entries\n" + "- please increase CONFIG_BOOTSTAGE_USER_COUNT\n", + next_id - BOOTSTAGE_ID_COUNT); +} diff --git a/include/bootstage.h b/include/bootstage.h index b56d953..06ab2c8 100644 --- a/include/bootstage.h +++ b/include/bootstage.h @@ -26,6 +26,11 @@ #ifndef _BOOTSTAGE_H #define _BOOTSTAGE_H
+/* The number of boot stage records available for the user */ +#ifndef CONFIG_BOOTSTAGE_USER_COUNT +#define CONFIG_BOOTSTAGE_USER_COUNT 20 +#endif + /* * A list of boot stages that we know about. Each of these indicates the * state that we are at, and the action that we are about to perform. For @@ -169,6 +174,33 @@ enum bootstage_id {
BOOTSTAGE_ID_NAND_FIT_READ = 150, BOOTSTAGE_ID_NAND_FIT_READ_OK, + + /* + * These boot stages are new, higher level, and not directly related + * to the old boot progress numbers. They are useful for recording + * rough boot timing information. + */ + BOOTSTAGE_ID_AWAKE, + BOOTSTAGE_ID_START_UBOOT_F, + BOOTSTAGE_ID_START_UBOOT_R, + BOOTSTAGE_ID_USB_START, + BOOTSTAGE_ID_ETH_START, + BOOTSTAGE_ID_BOOTP_START, + BOOTSTAGE_ID_BOOTP_STOP, + BOOTSTAGE_ID_BOOTM_START, + BOOTSTAGE_ID_BOOTM_HANDOFF, + BOOTSTAGE_ID_MAIN_LOOP, + BOOTSTAGE_KERNELREAD_START, + BOOTSTAGE_KERNELREAD_STOP, + + BOOTSTAGE_ID_CPU_AWAKE, + BOOTSTAGE_ID_MAIN_CPU_AWAKE, + BOOTSTAGE_ID_MAIN_CPU_READY, + + /* a few spare for the user, from here */ + BOOTSTAGE_ID_USER, + BOOTSTAGE_ID_COUNT = BOOTSTAGE_ID_USER + CONFIG_BOOTSTAGE_USER_COUNT, + BOOTSTAGE_ID_ALLOC, };
/* @@ -189,6 +221,11 @@ ulong bootstage_mark(enum bootstage_id id);
ulong bootstage_error(enum bootstage_id id);
+ulong bootstage_mark_name(enum bootstage_id id, const char *name); + +/* Print a report about boot time */ +void bootstage_report(void); + #else /* * This is a dummy implementation which just calls show_boot_progress(), @@ -207,6 +244,12 @@ static inline ulong bootstage_error(enum bootstage_id id) return 0; }
+static inline ulong bootstage_mark_name(enum bootstage_id id, const char *name) +{ + return 0; +} + + #endif /* CONFIG_BOOTSTAGE */
#endif