[U-Boot] [RFC PATCH 0/15] RFC: Add tracing functionality to U-Boot

This series adds a tracing feature to U-Boot which is useful for profiling boot time and other purposes.
The core trace library relies on standard gcc function instrumentation and a microsecond timer which should work correctly on almost any architecture. Generic board is used to avoid the need to add the same code in multiple places (CONFIG_SYS_GENERIC_BOARD).
Tracing must be built into the U-Boot image at build time, but can be paused and resumed while running. A trace buffer is used to collect trace information. This buffer can then be transmitted to a host for processing. A host-based processing tool is provided which converts the data to the same format used by Linux, and that can be read by the pytimechart GUI tool.
A U-Boot 'trace' command provides access to the trace information, including support for writing it to memory in a few forms.
Support is provided for stopping tracing at the last possible moment in the bootm process (just before U-Boot jumps to the OS). This is done with a new 'fake go' command, which allows bootm to go through the motions of an OS boot without actually committing to it. Once the 'fake go' is complete, U-Boot can stop tracing and continue execution to transmit the trace information to the host, before jumping to the OS for real.
The system is tested on sandbox and has previously worked on ARM Tegra and Exynos machines. A simple test script is provided for sandbox, along with documentation on how to use the feature.
This feature has been successfully used alongside bootstage to locate bottlenecks and reduce overall boot time.
Because of the bootm changes this series sits on top of the image improvements that were done for verified boot. This series is available at:
http://git.denx.de/u-boot-x86.git
in branch 'trace'.
Simon Glass (15): bootstage; Correct printf types Add function to print a number with grouped digits Add trace library Add a trace command Support tracing in config.mk when enabled Add trace support to generic board Add proftool to decode profile data sandbox: Support trace feature Add a simple test for sandbox trace Clarify bootm OS arguments Refactor the bootm command to reduce code duplication Add a 'fake' go command to the bootm command arm: Implement the 'fake' go command Show stdout on error in fit-test exynos: Avoid function instrumentation for microsecond timer
Makefile | 3 +- arch/arm/cpu/armv7/s5p-common/timer.c | 2 +- arch/arm/include/asm/arch-exynos/cpu.h | 10 +- arch/arm/lib/bootm.c | 33 +- arch/microblaze/lib/bootm.c | 4 +- arch/nios2/lib/bootm.c | 4 +- arch/openrisc/lib/bootm.c | 4 +- arch/sandbox/cpu/cpu.c | 2 +- arch/sandbox/cpu/os.c | 2 +- common/Makefile | 1 + common/board_f.c | 15 + common/board_r.c | 11 + common/bootstage.c | 26 +- common/cmd_bootm.c | 517 ++++++++++++++-------------- common/cmd_trace.c | 133 +++++++ common/image-fdt.c | 13 +- common/image.c | 22 +- config.mk | 11 +- doc/README.trace | 361 +++++++++++++++++++ include/asm-generic/global_data.h | 3 + include/common.h | 4 + include/configs/sandbox.h | 13 + include/image.h | 17 +- include/trace.h | 125 +++++++ include/vsprintf.h | 11 + lib/Makefile | 1 + lib/trace.c | 378 ++++++++++++++++++++ lib/vsprintf.c | 16 + test/image/test-fit.py | 19 +- test/trace/test-trace.sh | 88 +++++ tools/.gitignore | 1 + tools/Makefile | 6 + tools/proftool.c | 611 +++++++++++++++++++++++++++++++++ 33 files changed, 2133 insertions(+), 334 deletions(-) create mode 100644 common/cmd_trace.c create mode 100644 doc/README.trace create mode 100644 include/trace.h create mode 100644 lib/trace.c create mode 100755 test/trace/test-trace.sh create mode 100644 tools/proftool.c

The unstash code is a bit loose with its printf() types, which gives warnings on sandbox. Correct this.
Signed-off-by: Simon Glass sjg@chromium.org --- common/bootstage.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/common/bootstage.c b/common/bootstage.c index a1e0939..d0ea632 100644 --- a/common/bootstage.c +++ b/common/bootstage.c @@ -401,9 +401,9 @@ int bootstage_unstash(void *base, int size) }
if (hdr->count * sizeof(*rec) > hdr->size) { - debug("%s: Bootstage has %d records needing %d bytes, but " + debug("%s: Bootstage has %d records needing %lu bytes, but " "only %d bytes is available\n", __func__, hdr->count, - hdr->count * sizeof(*rec), hdr->size); + (ulong)hdr->count * sizeof(*rec), hdr->size); return -1; }

Move bootstage's numbering printing code into a generic place so that it can be used by tracing also.
Signed-off-by: Simon Glass sjg@chromium.org --- common/bootstage.c | 22 ++++------------------ include/vsprintf.h | 11 +++++++++++ lib/vsprintf.c | 16 ++++++++++++++++ 3 files changed, 31 insertions(+), 18 deletions(-)
diff --git a/common/bootstage.c b/common/bootstage.c index d0ea632..02c3633 100644 --- a/common/bootstage.c +++ b/common/bootstage.c @@ -47,6 +47,7 @@ static int next_id = BOOTSTAGE_ID_USER; enum { BOOTSTAGE_VERSION = 0, BOOTSTAGE_MAGIC = 0xb00757a3, + BOOTSTAGE_DIGITS = 9, };
struct bootstage_hdr { @@ -121,21 +122,6 @@ uint32_t bootstage_accum(enum bootstage_id id) return duration; }
-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; - } -} - /** * Get a record name as a printable string * @@ -164,10 +150,10 @@ static uint32_t print_time_record(enum bootstage_id id,
if (prev == -1U) { printf("%11s", ""); - print_time(rec->time_us); + print_grouped_ull(rec->time_us, BOOTSTAGE_DIGITS); } else { - print_time(rec->time_us); - print_time(rec->time_us - prev); + print_grouped_ull(rec->time_us, BOOTSTAGE_DIGITS); + print_grouped_ull(rec->time_us - prev, BOOTSTAGE_DIGITS); } printf(" %s\n", get_record_name(buf, sizeof(buf), rec));
diff --git a/include/vsprintf.h b/include/vsprintf.h index 651077c..6568854 100644 --- a/include/vsprintf.h +++ b/include/vsprintf.h @@ -178,4 +178,15 @@ int vscnprintf(char *buf, size_t size, const char *fmt, va_list args); #define vscnprintf(buf, size, fmt, args...) vsprintf(buf, fmt, ##args) #endif /* CONFIG_SYS_VSNPRINTF */
+/** + * print_grouped_ull() - print a value with digits grouped by ',' + * + * This prints a value with grouped digits, like 12,345,678 to make it easier + * to read. + * + * @val: Value to print + * @digits: Number of digiits to print + */ +void print_grouped_ull(unsigned long long int_val, int digits); + #endif diff --git a/lib/vsprintf.c b/lib/vsprintf.c index 533a96b..82e5c13 100644 --- a/lib/vsprintf.c +++ b/lib/vsprintf.c @@ -870,3 +870,19 @@ char *simple_itoa(ulong i) } while (i > 0); return p + 1; } + +/* We don't seem to have %'d in U-Boot */ +void print_grouped_ull(unsigned long long int_val, int digits) +{ + char str[21], *s; + int grab = 3; + + digits = (digits + 2) / 3; + sprintf(str, "%*llu", digits * 3, int_val); + for (s = str; *s; s += grab) { + if (s != str) + putc(s[-1] != ' ' ? ',' : ' '); + printf("%.*s", grab, s); + grab = 3; + } +}

Add a library which supports tracing of execution using built-in gcc features and a microsecond timer. This can be used to record a list of function which are executed, along with a timestamp for each. Later this information can be sent to the host for processing.
Signed-off-by: Simon Glass sjg@chromium.org --- doc/README.trace | 361 ++++++++++++++++++++++++++++++++++++++++++++++++++++ include/common.h | 4 + include/trace.h | 125 ++++++++++++++++++ lib/Makefile | 1 + lib/trace.c | 378 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 869 insertions(+) create mode 100644 doc/README.trace create mode 100644 include/trace.h create mode 100644 lib/trace.c
diff --git a/doc/README.trace b/doc/README.trace new file mode 100644 index 0000000..b535c06 --- /dev/null +++ b/doc/README.trace @@ -0,0 +1,361 @@ +# +# Copyright (c) 2013 The Chromium OS Authors. +# +# 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 Foundatio; 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 +# + +Tracing in U-Boot +================= + +U-Boot supports a simple tracing feature which allows a record of excecution +to be collected and sent to a host machine for analysis. At present the +main use for this is to profile boot time. + + +Overview +-------- + +The trace feature uses GCC's instrument-functions feature to trace all +function entry/exit points. These are then recorded in a memory buffer. +The memory buffer can be saved to the host over a network link using +tftpput or by writing to an attached memory device such as MMC. + +On the host, the file is first converted with a tool called 'proftool', +which extracts useful information from it. The resulting trace output +resembles that emitted by Linux's ftrace feature, so can be visually +displayed by pytimechart. + + +Quick-start using Sandbox +------------------------- + +Sandbox is a build of U-Boot that can run under Linux so it is a convenient +way of trying out tracing before you use it on your actual board. To do +this, follow these steps: + +Add the following to include/configs/sandbox.h (if not already there) + +#define CONFIG_TRACE +#define CONFIG_CMD_TRACE +#define CONFIG_TRACE_BUFFER_SIZE (16 << 20) +#define CONFIG_TRACE_EARLY_SIZE (8 << 20) +#define CONFIG_TRACE_EARLY +#define CONFIG_TRACE_EARLY_ADDR 0x00100000 + +Build sandbox U-Boot with tracing enabled: + +$ make FTRACE=1 O=sandbox sandbox_config +$ make FTRACE=1 O=sandbox + +Run sandbox, wait for a bit of trace information to appear, and then capture +a trace: + +$ ./sandbox/u-boot + + +U-Boot 2013.04-rc2-00100-ga72fcef (Apr 17 2013 - 19:25:24) + +DRAM: 128 MiB +trace: enabled +Using default environment + +In: serial +Out: serial +Err: serial +=>trace stats + 671,406 function sites + 69,712 function calls + 0 untracked function calls + 73,373 traced function calls + 16 maximum observed call depth + 15 call depth limit + 66,491 calls not traced due to depth +=>trace stats + 671,406 function sites + 1,279,450 function calls + 0 untracked function calls + 950,490 traced function calls (333217 dropped due to overflow) + 16 maximum observed call depth + 15 call depth limit + 1,275,767 calls not traced due to depth +=>trace calls 0 e00000 +Call list dumped to 00000000, size 0xae0a40 +=>print +baudrate=115200 +profbase=0 +profoffset=ae0a40 +profsize=e00000 +stderr=serial +stdin=serial +stdout=serial + +Environment size: 117/8188 bytes +=>sb save host 0 trace 0 ${profoffset} +11405888 bytes written in 10 ms (1.1 GiB/s) +=>reset + + +Then run proftool to convert the trace information to ftrace format. + +$ ./sandbox/tools/proftool -m sandbox/System.map -p trace dump-ftrace >trace.txt + +Finally run pytimechart to display it: + +$ pytimechart trace.txt + +Using this tool you can zoom and pan across the trace, with the function +calls on the left and little marks representing the start and end of each +function. + + +CONFIG Options +-------------- + +- CONFIG_TRACE + Enables the trace feature in U-Boot. + +- CONFIG_CMD_TRACE + Enables the trace command. + +- CONFIG_TRACE_BUFFER_SIZE + Size of trace buffer to allocate for U-Boot. This buffer is + used after relocation, as a place to put function tracing + information. The address of the buffer is determined by + the relocation code. + +- CONFIG_TRACE_EARLY + Define this to start tracing early, before relocation. + +- CONFIG_TRACE_EARLY_SIZE + Size of 'early' trace buffer. Before U-Boot has relocated + it doesn't have a proper trace buffer. On many boards + you can define an area of memory to use for the trace + buffer until the 'real' trace buffer is available after + relocation. The contents of this buffer are then copied to + the real buffer. + +- CONFIG_TRACE_EARLY_ADDR + Address of early trace buffer + + +Building U-Boot with Tracing Enabled +------------------------------------ + +Pass 'FTRACE=1' to the U-Boot Makefile to actually instrument the code. +This is kept as a separate option so that it is easy to enable/disable +instrumenting from the command line instead of having to change board +config files. + + +Collecting Trace Data +--------------------- + +When you run U-Boot on your board it will collect trace data up to the +limit of the trace buffer size you have specified. Once that is exhausted +no more data will be collected. + +Collecting trace data has an affect on execution time/performance. You +will notice this particularly with trvial functions - the overhead of +recording their execution may even exceed their normal execution time. +In practice this doesn't matter much so long as you are aware of the +effect. Once you have done your optimisations, turn off tracing before +doing end-to-end timing. + +The best time to start tracing is right at the beginning of U-Boot. The +best time to stop tracing is right at the end. In practice it is hard +to achieve these ideals. + +This implementation enables tracing early in board_init_f(). This means +that it captures most of the board init process, missing only the +early architecture-specific init. However, it also misses the entire +SPL stage if there is one. + +U-Boot typically ends with a 'bootm' command which loads and runs an +OS. There is useful trace data in the execution of that bootm +command. Therefore this implementation provides a way to collect trace +data after bootm has finished processing, but just before it jumps to +the OS. In practical terms, U-Boot runs the 'fakegocmd' environment +variable at this point. This variable should have a short script which +collects the trace data and writes it somewhere. + +Trace data collection relies on a microsecond timer, accesed through +timer_get_us(). So the first think you should do is make sure that +this produces sensible results for your board. Suitable sources for +this timer include high resolution timers, PWMs or profile timers if +available. Most modern SOCs have a suitable timer for this. Make sure +that you mark this timer (and anything it calls) with +__attribute__((no_instrument_function)) so that the trace library can +use it without causing an infinite loop. + + +Commands +-------- + +The trace command has variable sub-commands: + +- stats + Display tracing statistics + +- pause + Pause tracing + +- resume + Resume tracing + +- funclist [<addr> <size>] + Dump a list of functions into the buffer + +- calls [<addr> <size>] + Dump function call trace into buffer + +If the address and size are not given, these are obtained from environment +variables (see below). In any case the environment variables are updated +after the command runs. + + +Environment Variables +--------------------- + +The following are used: + +- profbase + Base address of trace output buffer + +- profoffset + Offset of first unwritten byte in trace output buffer + +- profsize + Size of trace output buffer + +All of these are set by the 'trace calls' command. + +These variables keep track of the amount of data written to the trace +output buffer by the 'trace' command. The trace commands which write data +to the output buffer can use these to specify the buffer to write to, and +update profoffset each time. This allows successive commands to append data +to the same buffer, for example: + + trace funclist 10000 e00000 + trace calls + +(the latter command appends more data to the buffer). + + +- fakegocmd + Specifies commands to run just before booting the OS. This + is a useful time to write the trace data to the host for + processing. + + +Writing Out Trace Data +---------------------- + +Once the trace data is in an output buffer in memory there are various ways +to transmit it to the host. Notably you can use tftput to send the data +over a network link: + +fakegocmd=trace pause; usb start; set autoload n; bootp; + trace calls 10000000 1000000; + tftpput ${profbase} ${profoffset} 192.168.1.4:/tftpboot/calls + +This starts up USB (to talk to an attached USB Ethernet dongle), writes +a trace log to address 10000000 and sends it to a host machine using +TFTP. After this, U-Boot will boot the OS normally, albeit a little +later. + + +Converting Trace Output Data +---------------------------- + +The trace output data is kept in a binary format which is not documented +here. To convert it into something useful, you can use proftool. + +This tool must be given the U-Boot map file and the trace data received +from running that U-Boot. It produces a text output file. + +Options + -m <map_file> + Specify U-Boot map file + + -p <trace_file> + Specifiy profile/trace file + +Commands: + +- dump-ftrace + Write a text dump of the file in Linux ftrace format to stdout + + +Viewing the Trace Data +---------------------- + +You can use pytimechart for this (sudo apt-get pytimechart might work on +your Debian-style machine, and use your favourite search engine to obtain +documentation). It expects the file to have a .txt extension. The program +has terse user interface but is very convenient for viewing U-Boot +profile information. + + +Workflow Suggestions +-------------------- + +The following suggestions may be helpful if you are trying to reduce boot +time: + +1. Enable CONFIG_BOOTSTAGE and CONFIG_BOOTSTAGE_REPORT. This should get +you are helpful overall snapshot of the boot time. + +2. Build U-Boot with tracing and run it. Note the difference in boot time +(it is common for tracing to add 10% to the time) + +3. Collect the trace information as descibed above. Use this to find where +all the time is being spent. + +4. Take a look at that code and see if you can optimise it. Perhaps it is +possible to speed up the initialisation of a device, or remove an unused +feature. + +5. Rebuild, run and collect again. Compare your results. + +6. Keep going until you run out of steam, or your boot is fast enough. + + +Configuring Trace +----------------- + +There are a few parameters in the code that you may want to consider. +There is a function call depth limit (set to 15 by default). When the +stack depth goes above this then no tracing information is recorded. +The maximum depth reached is recorded and displayed by the 'trace stats' +command. + + +Future Work +----------- + +Tracing could be a little tidier in some areas, for example providing +run-time configuration options for trace. + +Some other features that might be useful: + +- Trace filter to select which functions are recorded +- Sample-based profiling using a timer interrupt +- Better control over trace depth +- Compression of trace information + + +Simon Glass sjg@chromium.org +April 2013 diff --git a/include/common.h b/include/common.h index 8003b62..26b7f3a 100644 --- a/include/common.h +++ b/include/common.h @@ -745,6 +745,10 @@ void irq_install_handler(int, interrupt_handler_t *, void *); void irq_free_handler (int); void reset_timer (void); ulong get_timer (ulong base); + +/* Return value of monotonic microsecond timer */ +unsigned long timer_get_us(void); + void enable_interrupts (void); int disable_interrupts (void);
diff --git a/include/trace.h b/include/trace.h new file mode 100644 index 0000000..8082466 --- /dev/null +++ b/include/trace.h @@ -0,0 +1,125 @@ +/* + * Copyright (c) 2012 The Chromium OS Authors. + * + * 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 + */ + +#ifndef __TRACE_H +#define __TRACE_H + +enum { + /* + * This affects the granularity of our trace. We can bin function + * entry points into groups on the basis that functions typically + * have a minimum size, so entry points can't appear any closer + * than this to each other. + * + * The value here assumes a minimum instruction size of 4 bytes, + * or that instructions are 2 bytes but there are at least 2 of + * them in every function. + * + * Increasing this value reduces the number of functions we can + * resolve, but reduces the size of the uintptr_t array used for + * our function list, which is the length of the code divided by + * this value. + */ + FUNC_SITE_SIZE = 4, /* distance between function sites */ +}; + +enum trace_chunk_type { + TRACE_CHUNK_FUNCS, + TRACE_CHUNK_CALLS, +}; + +/* A trace record for a function, as written to the profile output file */ +struct trace_output_func { + uint32_t offset; /* Function offset into code */ + uint32_t call_count; /* Number of times called */ +}; + +/* A header at the start of the trace output buffer */ +struct trace_output_hdr { + enum trace_chunk_type type; /* Record type */ + uint32_t rec_count; /* Number of records */ +}; + +/* Print statistics about traced function calls */ +void trace_print_stats(void); + +/** + * Dump a list of functions and call counts into a buffer + * + * Each record in the buffer is a struct trace_func_stats. The 'needed' + * parameter returns the number of bytes needed to complete the operation, + * which may be more than buff_size if your buffer is too small. + * + * @param buff Buffer in which to place data, or NULL to count size + * @param buff_size Size of buffer + * @param needed Returns number of bytes used / needed + * @return 0 if ok, -1 on error (buffer exhausted) + */ +int trace_list_functions(void *buff, int buff_size, unsigned *needed); + +/* Flags for ftrace_record */ +enum ftrace_flags { + FUNCF_EXIT = 0UL << 30, + FUNCF_ENTRY = 1UL << 30, + FUNCF_TEXTBASE = 2UL << 30, + + FUNCF_TIMESTAMP_MASK = 0x3fffffff, +}; + +#define TRACE_CALL_TYPE(call) ((call)->flags & 0xc0000000UL) + +/* Information about a single function entry/exit */ +struct trace_call { + uint32_t func; /* Function offset */ + uint32_t caller; /* Caller function offset */ + uint32_t flags; /* Flags and timestamp */ +}; + +int trace_list_calls(void *buff, int buff_size, unsigned int *needed); + +/** + * Turn function tracing on and off + * + * Don't enable trace if it has not been initialised. + * + * @param enabled 1 to enable trace, 0 to disable + */ +void trace_set_enabled(int enabled); + +#ifdef CONFIG_TRACE_EARLY +int trace_early_init(void); +#else +static inline int trace_early_init(void) +{ + return 0; +} +#endif + +/** + * Init the trace system + * + * This should be called after relocation with a suitably large buffer + * (typically as large as the U-Boot text area) + * + * @param buff Pointer to trace buffer + * @param buff_size Size of trace buffer + */ +int trace_init(void *buff, size_t buff_size); + +#endif diff --git a/lib/Makefile b/lib/Makefile index e901cc7..b681113 100644 --- a/lib/Makefile +++ b/lib/Makefile @@ -74,6 +74,7 @@ COBJS-y += div64.o COBJS-y += linux_string.o COBJS-y += string.o COBJS-y += time.o +COBJS-$(CONFIG_TRACE) += trace.o COBJS-$(CONFIG_BOOTP_PXE) += uuid.o COBJS-y += vsprintf.o COBJS-$(CONFIG_RANDOM_MACADDR) += rand.o diff --git a/lib/trace.c b/lib/trace.c new file mode 100644 index 0000000..1c0a40e --- /dev/null +++ b/lib/trace.c @@ -0,0 +1,378 @@ +/* + * Copyright (c) 2012 The Chromium OS Authors. + * + * 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 + */ + +#include <common.h> +#include <trace.h> +#include <asm/io.h> +#include <asm/sections.h> + +DECLARE_GLOBAL_DATA_PTR; + +static char trace_enabled __attribute__((section(".data"))); +static char trace_inited __attribute__((section(".data"))); + +/* The header block at the start of the trace memory area */ +struct trace_hdr { + int func_count; /* Total number of function call sites */ + u64 call_count; /* Total number of tracked function calls */ + u64 untracked_count; /* Total number of untracked function calls */ + int funcs_used; /* Total number of functions used */ + + /* + * Call count for each function. This is indexed by the word offset + * of the function from gd->relocaddr + */ + uintptr_t *call_accum; + + /* Function trace list */ + struct trace_call *ftrace; /* The function call records */ + ulong ftrace_size; /* Num. of ftrace records we have space for */ + ulong ftrace_count; /* Num. of ftrace records written */ + ulong ftrace_too_deep_count; /* Functions that were too deep */ + + int depth; + int depth_limit; + int max_depth; +}; + +static struct trace_hdr *hdr; /* Pointer to start of trace buffer */ + +static inline uintptr_t __attribute__((no_instrument_function)) + func_ptr_to_num(void *func_ptr) +{ + uintptr_t offset = (uintptr_t)func_ptr; + +#ifdef CONFIG_SANDBOX + offset -= (uintptr_t)&_init; +#else + if (gd->flags & GD_FLG_RELOC) + offset -= gd->relocaddr; + else + offset -= CONFIG_SYS_TEXT_BASE; +#endif + return offset / FUNC_SITE_SIZE; +} + +static void __attribute__((no_instrument_function)) add_ftrace(void *func_ptr, + void *caller, ulong flags) +{ + if (hdr->depth > hdr->depth_limit) { + hdr->ftrace_too_deep_count++; + return; + } + if (hdr->ftrace_count < hdr->ftrace_size) { + struct trace_call *rec = &hdr->ftrace[hdr->ftrace_count]; + + rec->func = func_ptr_to_num(func_ptr); + rec->caller = func_ptr_to_num(caller); + rec->flags = flags | (timer_get_us() & FUNCF_TIMESTAMP_MASK); + } + hdr->ftrace_count++; +} + +static void __attribute__((no_instrument_function)) add_textbase(void) +{ + if (hdr->ftrace_count < hdr->ftrace_size) { + struct trace_call *rec = &hdr->ftrace[hdr->ftrace_count]; + + rec->func = CONFIG_SYS_TEXT_BASE; + rec->caller = 0; + rec->flags = FUNCF_TEXTBASE; + } + hdr->ftrace_count++; +} + +/** + * This is called on every function entry + * + * We add to our tally for this function and add to the list of called + * functions. + * + * @param func_ptr Pointer to function being entered + * @param caller Pointer to function which called this function + */ +void __attribute__((no_instrument_function)) __cyg_profile_func_enter( + void *func_ptr, void *caller) +{ + if (trace_enabled) { + int func; + + add_ftrace(func_ptr, caller, FUNCF_ENTRY); + func = func_ptr_to_num(func_ptr); + if (func < hdr->func_count) { + hdr->call_accum[func]++; + hdr->call_count++; + } else { + hdr->untracked_count++; + } + hdr->depth++; + if (hdr->depth > hdr->depth_limit) + hdr->max_depth = hdr->depth; + } +} + +/** + * This is called on every function exit + * + * We do nothing here. + * + * @param func_ptr Pointer to function being entered + * @param caller Pointer to function which called this function + */ +void __attribute__((no_instrument_function)) __cyg_profile_func_exit( + void *func_ptr, void *caller) +{ + if (trace_enabled) { + add_ftrace(func_ptr, caller, FUNCF_EXIT); + hdr->depth--; + } +} + +/** + * Produce a list of called functions + * + * The information is written into the supplied buffer - a header followed + * by a list of function records. + * + * @param buff Buffer to place list into + * @param buff_size Size of buffer + * @param needed Returns size of buffer needed, which may be + * greater than buff_size if we ran out of space. + * @return 0 if ok, -1 if space was exhausted + */ +int trace_list_functions(void *buff, int buff_size, unsigned int *needed) +{ + struct trace_output_hdr *output_hdr = NULL; + void *end, *ptr = buff; + int func; + int upto; + + end = buff ? buff + buff_size : NULL; + + /* Place some header information */ + if (ptr + sizeof(struct trace_output_hdr) < end) + output_hdr = ptr; + ptr += sizeof(struct trace_output_hdr); + + /* Add information about each function */ + for (func = upto = 0; func < hdr->func_count; func++) { + int calls = hdr->call_accum[func]; + + if (!calls) + continue; + + if (ptr + sizeof(struct trace_output_func) < end) { + struct trace_output_func *stats = ptr; + + stats->offset = func * FUNC_SITE_SIZE; + stats->call_count = calls; + upto++; + } + ptr += sizeof(struct trace_output_func); + } + + /* Update the header */ + if (output_hdr) { + output_hdr->rec_count = upto; + output_hdr->type = TRACE_CHUNK_FUNCS; + } + + /* Work out how must of the buffer we used */ + *needed = ptr - buff; + if (ptr > end) + return -1; + return 0; +} + +int trace_list_calls(void *buff, int buff_size, unsigned *needed) +{ + struct trace_output_hdr *output_hdr = NULL; + void *end, *ptr = buff; + int rec, upto; + int count; + + end = buff ? buff + buff_size : NULL; + + /* Place some header information */ + if (ptr + sizeof(struct trace_output_hdr) < end) + output_hdr = ptr; + ptr += sizeof(struct trace_output_hdr); + + /* Add information about each call */ + count = hdr->ftrace_count; + if (count > hdr->ftrace_size) + count = hdr->ftrace_size; + for (rec = upto = 0; rec < count; rec++) { + if (ptr + sizeof(struct trace_call) < end) { + struct trace_call *call = &hdr->ftrace[rec]; + struct trace_call *out = ptr; + + out->func = call->func * FUNC_SITE_SIZE; + out->caller = call->caller * FUNC_SITE_SIZE; + out->flags = call->flags; + upto++; + } + ptr += sizeof(struct trace_call); + } + + /* Update the header */ + if (output_hdr) { + output_hdr->rec_count = upto; + output_hdr->type = TRACE_CHUNK_CALLS; + } + + /* Work out how must of the buffer we used */ + *needed = ptr - buff; + if (ptr > end) + return -1; + return 0; +} + +/* Print basic information about tracing */ +void trace_print_stats(void) +{ + ulong count; + +#ifndef FTRACE + puts("Warning: make U-Boot with FTRACE to enable function instrumenting.\n"); + puts("You will likely get zeroed data here\n"); +#endif + if (!trace_inited) { + printf("Trace is disabled\n"); + return; + } + print_grouped_ull(hdr->func_count, 10); + puts(" function sites\n"); + print_grouped_ull(hdr->call_count, 10); + puts(" function calls\n"); + print_grouped_ull(hdr->untracked_count, 10); + puts(" untracked function calls\n"); + count = min(hdr->ftrace_count, hdr->ftrace_size); + print_grouped_ull(count, 10); + puts(" traced function calls"); + if (hdr->ftrace_count > hdr->ftrace_size) { + printf(" (%lu dropped due to overflow)", + hdr->ftrace_count - hdr->ftrace_size); + } + puts("\n"); + printf("%15d maximum observed call depth\n", hdr->max_depth); + printf("%15d call depth limit\n", hdr->depth_limit); + print_grouped_ull(hdr->ftrace_too_deep_count, 10); + puts(" calls not traced due to depth\n"); +} + +void __attribute__((no_instrument_function)) trace_set_enabled(int enabled) +{ + trace_enabled = enabled != 0; +} + +/** + * Init the tracing system ready for used, and enable it + * + * @param buff Pointer to trace buffer + * @param buff_size Size of trace buffer + */ +int __attribute__((no_instrument_function)) trace_init(void *buff, + size_t buff_size) +{ + ulong func_count = gd->mon_len / FUNC_SITE_SIZE; + size_t needed; + int was_disabled = !trace_enabled; + + if (!was_disabled) { +#ifdef CONFIG_TRACE_EARLY + char *end; + ulong used; + + /* + * Copy over the early trace data if we have it. Disable + * tracing while we are doing this. + */ + trace_enabled = 0; + hdr = map_sysmem(CONFIG_TRACE_EARLY_ADDR, + CONFIG_TRACE_EARLY_SIZE); + end = (char *)&hdr->ftrace[hdr->ftrace_count]; + used = end - (char *)hdr; + printf("trace: copying %08lx bytes of early data from %x to %08lx\n", + used, CONFIG_TRACE_EARLY_ADDR, map_to_sysmem(buff)); + memcpy(buff, hdr, used); +#else + puts("trace: already enabled\n"); + return -1; +#endif + } + hdr = (struct trace_hdr *)buff; + needed = sizeof(*hdr) + func_count * sizeof(uintptr_t); + if (needed > buff_size) { + printf("trace: buffer size %zd bytes: at least %zd needed\n", + buff_size, needed); + return -1; + } + + if (was_disabled) + memset(hdr, '\0', needed); + hdr->func_count = func_count; + hdr->call_accum = (uintptr_t *)(hdr + 1); + + /* Use any remaining space for the timed function trace */ + hdr->ftrace = (struct trace_call *)(buff + needed); + hdr->ftrace_size = (buff_size - needed) / sizeof(*hdr->ftrace); + add_textbase(); + + puts("trace: enabled\n"); + hdr->depth_limit = 15; + trace_enabled = 1; + trace_inited = 1; + return 0; +} + +#ifdef CONFIG_TRACE_EARLY +int __attribute__((no_instrument_function)) trace_early_init(void) +{ + ulong func_count = gd->mon_len / FUNC_SITE_SIZE; + size_t buff_size = CONFIG_TRACE_EARLY_SIZE; + size_t needed; + + /* We can ignore additional calls to this function */ + if (trace_enabled) + return 0; + + hdr = map_sysmem(CONFIG_TRACE_EARLY_ADDR, CONFIG_TRACE_EARLY_SIZE); + needed = sizeof(*hdr) + func_count * sizeof(uintptr_t); + if (needed > buff_size) { + printf("trace: buffer size is %zd bytes, at least %zd needed\n", + buff_size, needed); + return -1; + } + + memset(hdr, '\0', needed); + hdr->call_accum = (uintptr_t *)(hdr + 1); + hdr->func_count = func_count; + + /* Use any remaining space for the timed function trace */ + hdr->ftrace = (struct trace_call *)((char *)hdr + needed); + hdr->ftrace_size = (buff_size - needed) / sizeof(*hdr->ftrace); + add_textbase(); + hdr->depth_limit = 200; + printf("trace: early enable at %08x\n", CONFIG_TRACE_EARLY_ADDR); + + trace_enabled = 1; + return 0; +} +#endif

Add a trace command with sub-commands to start/stop tracing, print out statistics and dump trace information to memory for later upload to a host.
Signed-off-by: Simon Glass sjg@chromium.org --- common/Makefile | 1 + common/cmd_trace.c | 133 +++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 134 insertions(+) create mode 100644 common/cmd_trace.c
diff --git a/common/Makefile b/common/Makefile index 444d546..03aa026 100644 --- a/common/Makefile +++ b/common/Makefile @@ -169,6 +169,7 @@ COBJS-$(CONFIG_CMD_SPIBOOTLDR) += cmd_spibootldr.o COBJS-$(CONFIG_CMD_STRINGS) += cmd_strings.o COBJS-$(CONFIG_CMD_TERMINAL) += cmd_terminal.o COBJS-$(CONFIG_CMD_TIME) += cmd_time.o +COBJS-$(CONFIG_CMD_TRACE) += cmd_trace.o COBJS-$(CONFIG_SYS_HUSH_PARSER) += cmd_test.o COBJS-$(CONFIG_CMD_TPM) += cmd_tpm.o COBJS-$(CONFIG_CMD_TSI148) += cmd_tsi148.o diff --git a/common/cmd_trace.c b/common/cmd_trace.c new file mode 100644 index 0000000..cf109e3 --- /dev/null +++ b/common/cmd_trace.c @@ -0,0 +1,133 @@ +/* + * Copyright (c) 2011 The Chromium OS Authors. + * + * 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 + */ + +#include <common.h> +#include <command.h> +#include <trace.h> +#include <asm/io.h> + +static int get_args(int argc, char * const argv[], char **buff, + size_t *buff_ptr, size_t *buff_size) +{ + if (argc < 2) + return -1; + if (argc < 4) { + *buff_size = getenv_ulong("profsize", 16, 0); + *buff = map_sysmem(getenv_ulong("profbase", 16, 0), + *buff_size); + *buff_ptr = getenv_ulong("profoffset", 16, 0); + } else { + *buff_size = simple_strtoul(argv[3], NULL, 16); + *buff = map_sysmem(simple_strtoul(argv[2], NULL, 16), + *buff_size); + *buff_ptr = 0; + }; + return 0; +} + +static int create_func_list(int argc, char * const argv[]) +{ + size_t buff_size, avail, buff_ptr, used; + unsigned int needed; + char *buff; + int err; + + if (get_args(argc, argv, &buff, &buff_ptr, &buff_size)) + return -1; + + avail = buff_size - buff_ptr; + err = trace_list_functions(buff + buff_ptr, avail, &needed); + if (err) + printf("Error: truncated (%#x bytes needed)\n", needed); + used = min(avail, needed); + printf("Function trace dumped to %08lx, size %#zx\n", + map_to_sysmem(buff + buff_ptr), used); + setenv_hex("profbase", map_to_sysmem(buff)); + setenv_hex("profsize", buff_size); + setenv_hex("profoffset", buff_ptr + used); + + return 0; +} + +static int create_call_list(int argc, char * const argv[]) +{ + size_t buff_size, avail, buff_ptr, used; + unsigned int needed; + char *buff; + int err; + + if (get_args(argc, argv, &buff, &buff_ptr, &buff_size)) + return -1; + + avail = buff_size - buff_ptr; + err = trace_list_calls(buff + buff_ptr, avail, &needed); + if (err) + printf("Error: truncated (%#x bytes needed)\n", needed); + used = min(avail, needed); + printf("Call list dumped to %08lx, size %#zx\n", + map_to_sysmem(buff + buff_ptr), used); + + setenv_hex("profbase", map_to_sysmem(buff)); + setenv_hex("profsize", buff_size); + setenv_hex("profoffset", buff_ptr + used); + + return 0; +} + +int do_trace(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) +{ + const char *cmd = argc < 2 ? NULL : argv[1]; + + if (!cmd) + return cmd_usage(cmdtp); + switch (*cmd) { + case 'p': + trace_set_enabled(0); + break; + case 'c': + if (create_call_list(argc, argv)) + return cmd_usage(cmdtp); + break; + case 'r': + trace_set_enabled(1); + break; + case 'f': + if (create_func_list(argc, argv)) + return cmd_usage(cmdtp); + break; + case 's': + trace_print_stats(); + break; + default: + return CMD_RET_USAGE; + } + + return 0; +} + +U_BOOT_CMD( + trace, 4, 1, do_trace, + "trace utility commands", + "stats - display tracing statistics\n" + "trace pause - pause tracing\n" + "trace resume - resume tracing\n" + "trace funclist [<addr> <size>] - dump function list into buffer\n" + "trace calls [<addr> <size>] " + "- dump function call trace into buffer" +);

Use -finstrument-functions when tracing is enabled (make FTRACE=1). Tracing is not currently supported by SPL even if sufficient memory is available.
When tracing is enabled, we #define FTRACE. This can be used by board config files to conditionally enable the tracing options.
Signed-off-by: Simon Glass sjg@chromium.org --- config.mk | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-)
diff --git a/config.mk b/config.mk index 16a4fdb..63e7106 100644 --- a/config.mk +++ b/config.mk @@ -265,6 +265,16 @@ CFLAGS += $(CFLAGS_WARN) CFLAGS_STACK := $(call cc-option,-fstack-usage) CFLAGS += $(CFLAGS_STACK)
+BCURDIR = $(subst $(SRCTREE)/,,$(CURDIR:$(obj)%=%)) + +ifeq ($(findstring examples/,$(BCURDIR)),) +ifeq ($(CONFIG_SPL_BUILD),) +ifdef FTRACE +CFLAGS += -finstrument-functions -DFTRACE +endif +endif +endif + # $(CPPFLAGS) sets -g, which causes gcc to pass a suitable -g<format> # option to the assembler. AFLAGS_DEBUG := @@ -327,7 +337,6 @@ export CONFIG_SYS_TEXT_BASE PLATFORM_CPPFLAGS PLATFORM_RELFLAGS CPPFLAGS CFLAGS #########################################################################
# Allow boards to use custom optimize flags on a per dir/file basis -BCURDIR = $(subst $(SRCTREE)/,,$(CURDIR:$(obj)%=%)) ALL_AFLAGS = $(AFLAGS) $(AFLAGS_$(BCURDIR)/$(@F)) $(AFLAGS_$(BCURDIR)) ALL_CFLAGS = $(CFLAGS) $(CFLAGS_$(BCURDIR)/$(@F)) $(CFLAGS_$(BCURDIR)) EXTRA_CPPFLAGS = $(CPPFLAGS_$(BCURDIR)/$(@F)) $(CPPFLAGS_$(BCURDIR))

Add hooks for tracing to generic board, including:
- allow early tracing to start early as possible in U-Boot - reserve memory for trace buffer - copy early trace buffer to main trace buffer after relocation - setup full tracing support after relocation
Signed-off-by: Simon Glass sjg@chromium.org --- common/board_f.c | 15 +++++++++++++++ common/board_r.c | 11 +++++++++++ include/asm-generic/global_data.h | 3 +++ 3 files changed, 29 insertions(+)
diff --git a/common/board_f.c b/common/board_f.c index 3a6638f..7c7b5fb 100644 --- a/common/board_f.c +++ b/common/board_f.c @@ -53,6 +53,7 @@ #include <os.h> #include <post.h> #include <spi.h> +#include <trace.h> #include <watchdog.h> #include <asm/errno.h> #include <asm/io.h> @@ -501,6 +502,18 @@ static int reserve_lcd(void) } #endif /* CONFIG_LCD */
+static int reserve_trace(void) +{ +#ifdef CONFIG_TRACE + gd->dest_addr -= CONFIG_TRACE_BUFFER_SIZE; + gd->trace_buff = map_sysmem(gd->dest_addr, CONFIG_TRACE_BUFFER_SIZE); + debug("Reserving %dk for trace data at: %08lx\n", + CONFIG_TRACE_BUFFER_SIZE >> 10, gd->dest_addr); +#endif + + return 0; +} + #if defined(CONFIG_VIDEO) && (!defined(CONFIG_PPC) || defined(CONFIG_8xx)) \ && !defined(CONFIG_ARM) && !defined(CONFIG_X86) static int reserve_video(void) @@ -839,6 +852,7 @@ static init_fnc_t init_sequence_f[] = { #ifdef CONFIG_SANDBOX setup_ram_buf, #endif + trace_early_init, setup_fdt, setup_mon_len, #if defined(CONFIG_MPC85xx) || defined(CONFIG_MPC86xx) @@ -990,6 +1004,7 @@ static init_fnc_t init_sequence_f[] = { #ifdef CONFIG_LCD reserve_lcd, #endif + reserve_trace, /* TODO: Why the dependency on CONFIG_8xx? */ #if defined(CONFIG_VIDEO) && (!defined(CONFIG_PPC) || defined(CONFIG_8xx)) \ && !defined(CONFIG_ARM) && !defined(CONFIG_X86) diff --git a/common/board_r.c b/common/board_r.c index f801e41..b745749 100644 --- a/common/board_r.c +++ b/common/board_r.c @@ -58,6 +58,7 @@ #include <serial.h> #include <spi.h> #include <stdio_dev.h> +#include <trace.h> #include <watchdog.h> #ifdef CONFIG_ADDR_MAP #include <asm/mmu.h> @@ -106,6 +107,15 @@ static int initr_secondary_cpu(void) return 0; }
+static int initr_trace(void) +{ +#ifdef CONFIG_TRACE + trace_init(gd->trace_buff, CONFIG_TRACE_BUFFER_SIZE); +#endif + + return 0; +} + static int initr_reloc(void) { gd->flags |= GD_FLG_RELOC; /* tell others: relocation done */ @@ -711,6 +721,7 @@ static int run_main_loop(void) * TODO: perhaps reset the watchdog in the initcall function after each call? */ init_fnc_t init_sequence_r[] = { + initr_trace, initr_reloc, /* TODO: could x86/PPC have this also perhaps? */ #ifdef CONFIG_ARM diff --git a/include/asm-generic/global_data.h b/include/asm-generic/global_data.h index 5416f46..bd29ab6 100644 --- a/include/asm-generic/global_data.h +++ b/include/asm-generic/global_data.h @@ -85,6 +85,9 @@ typedef struct global_data { unsigned long fdt_size; /* Space reserved for relocated FDT */ void **jt; /* jump table */ char env_buf[32]; /* buffer for getenv() before reloc. */ +#ifdef CONFIG_TRACE + void *trace_buff; /* The trace buffer */ +#endif struct arch_global_data arch; /* architecture-specific data */ } gd_t; #endif

This tool provides the facility to decode U-Boot trace data and write out a text file in Linux ftrace format for use with pytimechart.
Signed-off-by: Simon Glass sjg@chromium.org --- Makefile | 3 +- tools/.gitignore | 1 + tools/Makefile | 6 + tools/proftool.c | 611 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 620 insertions(+), 1 deletion(-) create mode 100644 tools/proftool.c
diff --git a/Makefile b/Makefile index 42f2b02..948e268 100644 --- a/Makefile +++ b/Makefile @@ -819,7 +819,8 @@ clean: $(obj)tools/mk{smdk5250,}spl \ $(obj)tools/mxsboot \ $(obj)tools/ncb $(obj)tools/ubsha1 \ - $(obj)tools/kernel-doc/docproc + $(obj)tools/kernel-doc/docproc \ + $(obj)tools/proftool @rm -f $(obj)board/cray/L1/{bootscript.c,bootscript.image} \ $(obj)board/matrix_vision/*/bootscript.img \ $(obj)board/voiceblue/eeprom \ diff --git a/tools/.gitignore b/tools/.gitignore index 9bce719..a7fee26 100644 --- a/tools/.gitignore +++ b/tools/.gitignore @@ -9,6 +9,7 @@ /mxsboot /ncb /ncp +/proftool /ubsha1 /xway-swap-bytes /*.exe diff --git a/tools/Makefile b/tools/Makefile index 26eb500..569dc77 100644 --- a/tools/Makefile +++ b/tools/Makefile @@ -74,6 +74,7 @@ BIN_FILES-$(CONFIG_MX28) += mxsboot$(SFX) BIN_FILES-$(CONFIG_NETCONSOLE) += ncb$(SFX) BIN_FILES-$(CONFIG_SHA1_CHECK_UB_IMG) += ubsha1$(SFX) BIN_FILES-$(CONFIG_KIRKWOOD) += kwboot$(SFX) +BIN_FILES-y += proftool(SFX)
# Source files which exist outside the tools directory EXT_OBJ_FILES-$(CONFIG_BUILD_ENVCRC) += common/env_embedded.o @@ -87,6 +88,7 @@ EXT_OBJ_FILES-y += lib/sha1.o OBJ_FILES-$(CONFIG_LCD_LOGO) += bmp_logo.o OBJ_FILES-$(CONFIG_VIDEO_LOGO) += bmp_logo.o NOPED_OBJ_FILES-y += default_image.o +NOPED_OBJ_FILES-y += proftool.o OBJ_FILES-$(CONFIG_BUILD_ENVCRC) += envcrc.o NOPED_OBJ_FILES-y += fit_image.o OBJ_FILES-$(CONFIG_CMD_NET) += gen_eth_addr.o @@ -187,6 +189,10 @@ $(obj)bmp_logo$(SFX): $(obj)bmp_logo.o $(HOSTCC) $(HOSTCFLAGS) $(HOSTLDFLAGS) -o $@ $^ $(HOSTSTRIP) $@
+$(obj)proftool(SFX): $(obj)proftool.o + $(HOSTCC) $(HOSTCFLAGS) $(HOSTLDFLAGS) -o $@ $^ + $(HOSTSTRIP) $@ + $(obj)envcrc$(SFX): $(obj)crc32.o $(obj)env_embedded.o $(obj)envcrc.o $(obj)sha1.o $(HOSTCC) $(HOSTCFLAGS) $(HOSTLDFLAGS) -o $@ $^
diff --git a/tools/proftool.c b/tools/proftool.c new file mode 100644 index 0000000..a48ed28 --- /dev/null +++ b/tools/proftool.c @@ -0,0 +1,611 @@ +/* + * Copyright (c) 2013 Google, Inc + * + * 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 + */ + +/* Decode and dump U-Boot profiling information */ + +#include <assert.h> +#include <ctype.h> +#include <limits.h> +#include <regex.h> +#include <stdarg.h> +#include <stdio.h> +#include <stdlib.h> +#include <string.h> +#include <unistd.h> +#include <sys/param.h> + +#include <compiler.h> +#include <trace.h> + +#define MAX_LINE_LEN 500 + +enum { + FUNCF_TRACE = 1 << 0, /* Include this function in trace */ +}; + +struct func_info { + unsigned long offset; + const char *name; + unsigned long code_size; + unsigned long call_count; + unsigned flags; + /* the section this function is in */ + struct objsection_info *objsection; +}; + +enum trace_line_type { + TRACE_LINE_INCLUDE, + TRACE_LINE_EXCLUDE, +}; + +struct trace_configline_info { + struct trace_configline_info *next; + enum trace_line_type type; + const char *name; /* identifier name / wildcard */ + regex_t regex; /* Regex to use if name starts with / */ +}; + +/* The contents of the trace config file */ +struct trace_configline_info *trace_config_head; + +struct func_info *func_list; +int func_count; +struct trace_call *call_list; +int call_count; +int verbose; /* Verbosity level 0=none, 1=warn, 2=notice, 3=info, 4=debug */ +unsigned long text_offset; /* text address of first function */ + +static void outf(int level, const char *fmt, ...) + __attribute__ ((format (__printf__, 2, 3))); +#define error(fmt, b...) outf(0, fmt, ##b) +#define warn(fmt, b...) outf(1, fmt, ##b) +#define notice(fmt, b...) outf(2, fmt, ##b) +#define info(fmt, b...) outf(3, fmt, ##b) +#define debug(fmt, b...) outf(4, fmt, ##b) + + +static void outf(int level, const char *fmt, ...) +{ + if (verbose >= level) { + va_list args; + + va_start(args, fmt); + vfprintf(stderr, fmt, args); + va_end(args); + } +} + +static void usage(void) +{ + fprintf(stderr, + "Usage: proftool -cds -v3 <cmd> <profdata>\n" + "\n" + "Commands\n" + " dump-ftrace\t\tDump out textual data in ftrace format\n" + "\n" + "Options:\n" + " -m <map>\tSpecify Systen.map file\n" + " -t <trace>\tSpecific trace data file (from U-Boot)\n" + " -v <0-4>\tSpecify verbosity\n"); + exit(EXIT_FAILURE); +} + +static int h_cmp_offset(const void *v1, const void *v2) +{ + const struct func_info *f1 = v1, *f2 = v2; + + return (f1->offset / FUNC_SITE_SIZE) - (f2->offset / FUNC_SITE_SIZE); +} + +static int read_system_map(FILE *fin) +{ + unsigned long offset, start = 0; + struct func_info *func; + char buff[MAX_LINE_LEN]; + char symtype; + char symname[MAX_LINE_LEN + 1]; + int linenum; + int alloced; + + for (linenum = 1, alloced = func_count = 0;; linenum++) { + int fields = 0; + + if (fgets(buff, sizeof(buff), fin)) + fields = sscanf(buff, "%lx %c %100s\n", &offset, + &symtype, symname); + if (fields == 2) { + continue; + } else if (feof(fin)) { + break; + } else if (fields < 2) { + error("Map file line %d: invalid format\n", linenum); + return 1; + } + + /* Must be a text symbol */ + symtype = tolower(symtype); + if (symtype != 't' && symtype != 'w') + continue; + + if (func_count == alloced) { + alloced += 256; + func_list = realloc(func_list, + sizeof(struct func_info) * alloced); + assert(func_list); + } + if (!func_count) + start = offset; + + func = &func_list[func_count++]; + memset(func, '\0', sizeof(*func)); + func->offset = offset - start; + func->name = strdup(symname); + func->flags = FUNCF_TRACE; /* trace by default */ + + /* Update previous function's code size */ + if (func_count > 1) + func[-1].code_size = func->offset - func[-1].offset; + } + notice("%d functions found in map file\n", func_count); + text_offset = start; + return 0; +} + +static int read_data(FILE *fin, void *buff, int size) +{ + int err; + + err = fread(buff, 1, size, fin); + if (!err) + return 1; + if (err != size) { + error("Cannot read profile file at pos %ld\n", ftell(fin)); + return -1; + } + return 0; +} + +static struct func_info *find_func_by_offset(uint32_t offset) +{ + struct func_info key, *found; + + key.offset = offset; + found = bsearch(&key, func_list, func_count, sizeof(struct func_info), + h_cmp_offset); + + return found; +} + +/* This finds the function which contains the given offset */ +static struct func_info *find_caller_by_offset(uint32_t offset) +{ + int low; /* least function that could be a match */ + int high; /* greated function that could be a match */ + struct func_info key; + + low = 0; + high = func_count - 1; + key.offset = offset; + while (high > low + 1) { + int mid = (low + high) / 2; + int result; + + result = h_cmp_offset(&key, &func_list[mid]); + if (result > 0) + low = mid; + else if (result < 0) + high = mid; + else + return &func_list[mid]; + } + + return low >= 0 ? &func_list[low] : NULL; +} + +static int read_calls(FILE *fin, int count) +{ + struct trace_call *call_data; + int i; + + notice("call count: %d\n", count); + call_list = (struct trace_call *)calloc(count, sizeof(*call_data)); + if (!call_list) { + error("Cannot allocate call_list\n"); + return -1; + } + call_count = count; + + call_data = call_list; + for (i = 0; i < count; i++, call_data++) { + if (read_data(fin, call_data, sizeof(*call_data))) + return 1; + } + return 0; +} + +static int read_profile(FILE *fin, int *not_found) +{ + struct trace_output_hdr hdr; + + *not_found = 0; + while (!feof(fin)) { + int err; + + err = read_data(fin, &hdr, sizeof(hdr)); + if (err == 1) + break; /* EOF */ + else if (err) + return 1; + + switch (hdr.type) { + case TRACE_CHUNK_FUNCS: + /* Ignored at present */ + break; + + case TRACE_CHUNK_CALLS: + if (read_calls(fin, hdr.rec_count)) + return 1; + break; + } + } + return 0; +} + +static int read_map_file(const char *fname) +{ + FILE *fmap; + int err = 0; + + fmap = fopen(fname, "r"); + if (!fmap) { + error("Cannot open map file '%s'\n", fname); + return 1; + } + if (fmap) { + err = read_system_map(fmap); + fclose(fmap); + } + return err; +} + +static int read_profile_file(const char *fname) +{ + int not_found = INT_MAX; + FILE *fprof; + int err; + + fprof = fopen(fname, "rb"); + if (!fprof) { + error("Cannot open profile data file '%s'\n", + fname); + return 1; + } else { + err = read_profile(fprof, ¬_found); + fclose(fprof); + if (err) + return err; + + if (not_found) { + warn("%d profile functions could not be found in the map file - are you sure that your profile data and map file correspond?\n", + not_found); + return 1; + } + } + return 0; +} + +static int regex_report_error(regex_t *regex, int err, const char *op, + const char *name) +{ + char buf[200]; + + regerror(err, regex, buf, sizeof(buf)); + error("Regex error '%s' in %s '%s'\n", buf, op, name); + return -1; +} + +static void check_trace_config_line(struct trace_configline_info *item) +{ + struct func_info *func, *end; + int err; + + debug("Checking trace config line '%s'\n", item->name); + for (func = func_list, end = func + func_count; func < end; func++) { + err = regexec(&item->regex, func->name, 0, NULL, 0); + debug(" - regex '%s', string '%s': %d\n", item->name, + func->name, err); + if (err == REG_NOMATCH) + continue; + + if (err != REG_NOERROR) { + regex_report_error(&item->regex, err, "match", + item->name); + break; + } + + /* It matches, so perform the action */ + switch (item->type) { + case TRACE_LINE_INCLUDE: + info(" include %s at %lx\n", func->name, + text_offset + func->offset); + func->flags |= FUNCF_TRACE; + break; + + case TRACE_LINE_EXCLUDE: + info(" exclude %s at %lx\n", func->name, + text_offset + func->offset); + func->flags &= ~FUNCF_TRACE; + break; + } + } +} + +static void check_trace_config(void) +{ + struct trace_configline_info *line; + + for (line = trace_config_head; line; line = line->next) + check_trace_config_line(line); +} + +/** + * Check the functions to see if they each have an objsection. If not, then + * the linker must have eliminated them. + */ +static void check_functions(void) +{ + struct func_info *func, *end; + unsigned long removed_code_size = 0; + int not_found = 0; + + /* Look for missing functions */ + for (func = func_list, end = func + func_count; func < end; func++) { + if (!func->objsection) { + removed_code_size += func->code_size; + not_found++; + } + } + + /* Figure out what functions we want to trace */ + check_trace_config(); + + warn("%d functions removed by linker, %ld code size\n", + not_found, removed_code_size); +} + +static int read_trace_config(FILE *fin) +{ + char buff[200]; + int linenum = 0; + struct trace_configline_info **tailp = &trace_config_head; + + while (fgets(buff, sizeof(buff), fin)) { + int len = strlen(buff); + struct trace_configline_info *line; + char *saveptr; + char *s, *tok; + int err; + + linenum++; + if (len && buff[len - 1] == '\n') + buff[len - 1] = '\0'; + + /* skip blank lines and comments */ + for (s = buff; *s == ' ' || *s == '\t'; s++) + ; + if (!*s || *s == '#') + continue; + + line = (struct trace_configline_info *)calloc(1, + sizeof(*line)); + if (!line) { + error("Cannot allocate config line\n"); + return -1; + } + + tok = strtok_r(s, " \t", &saveptr); + if (!tok) { + error("Invalid trace config data on line %d\n", + linenum); + return -1; + } + if (0 == strcmp(tok, "include-func")) { + line->type = TRACE_LINE_INCLUDE; + } else if (0 == strcmp(tok, "exclude-func")) { + line->type = TRACE_LINE_EXCLUDE; + } else { + error("Unknown command in trace config data line %d\n", + linenum); + return -1; + } + + tok = strtok_r(NULL, " \t", &saveptr); + if (!tok) { + error("Missing pattern in trace config data line %d\n", + linenum); + return -1; + } + + err = regcomp(&line->regex, tok, REG_NOSUB); + if (err) { + free(line); + return regex_report_error(&line->regex, err, "compile", + tok); + } + + /* link this new one to the end of the list */ + line->name = strdup(tok); + line->next = NULL; + *tailp = line; + tailp = &line->next; + } + + if (!feof(fin)) { + error("Cannot read from trace config file at position %ld\n", + ftell(fin)); + return -1; + } + return 0; +} + +static int read_trace_config_file(const char *fname) +{ + FILE *fin; + int err; + + fin = fopen(fname, "r"); + if (!fin) { + error("Cannot open trace_config file '%s'\n", fname); + return -1; + } + err = read_trace_config(fin); + fclose(fin); + return err; +} + +static void out_func(ulong func_offset, int is_caller, const char *suffix) +{ + struct func_info *func; + + func = (is_caller ? find_caller_by_offset : find_func_by_offset) + (func_offset); + + if (func) + printf("%s%s", func->name, suffix); + else + printf("%lx%s", func_offset, suffix); +} + +/* + * # tracer: function + * # + * # TASK-PID CPU# TIMESTAMP FUNCTION + * # | | | | | + * # bash-4251 [01] 10152.583854: path_put <-path_walk + * # bash-4251 [01] 10152.583855: dput <-path_put + * # bash-4251 [01] 10152.583855: _atomic_dec_and_lock <-dput + */ +static int make_ftrace(void) +{ + struct trace_call *call; + int missing_count = 0, skip_count = 0; + int i; + + printf("# tracer: ftrace\n" + "#\n" + "# TASK-PID CPU# TIMESTAMP FUNCTION\n" + "# | | | | |\n"); + for (i = 0, call = call_list; i < call_count; i++, call++) { + struct func_info *func = find_func_by_offset(call->func); + ulong time = call->flags & FUNCF_TIMESTAMP_MASK; + + if (TRACE_CALL_TYPE(call) != FUNCF_ENTRY && + TRACE_CALL_TYPE(call) != FUNCF_EXIT) + continue; + if (!func) { + warn("Cannot find function at %lx\n", + text_offset + call->func); + missing_count++; + continue; + } + + if (!(func->flags & FUNCF_TRACE)) { + debug("Funcion '%s' is excluded from trace\n", + func->name); + skip_count++; + continue; + } + + printf("%16s-%-5d [01] %lu.%06lu: ", "uboot", 1, + time / 1000000, time % 1000000); + + out_func(call->func, 0, " <- "); + out_func(call->caller, 1, "\n"); + } + info("ftrace: %d functions not found, %d excluded\n", missing_count, + skip_count); + + return 0; +} + +static int prof_tool(int argc, char * const argv[], + const char *prof_fname, const char *map_fname, + const char *trace_config_fname) +{ + int err = 0; + + if (read_map_file(map_fname)) + return -1; + if (prof_fname && read_profile_file(prof_fname)) + return -1; + if (trace_config_fname && read_trace_config_file(trace_config_fname)) + return -1; + + check_functions(); + + for (; argc; argc--, argv++) { + const char *cmd = *argv; + + if (0 == strcmp(cmd, "dump-ftrace")) + err = make_ftrace(); + else + warn("Unknown command '%s'\n", cmd); + } + + return err; +} + +int main(int argc, char *argv[]) +{ + const char *map_fname = "System.map"; + const char *prof_fname = NULL; + const char *trace_config_fname = NULL; + int opt; + + verbose = 2; + while ((opt = getopt(argc, argv, "m:p:t:v:")) != -1) { + switch (opt) { + case 'm': + map_fname = optarg; + break; + + case 'p': + prof_fname = optarg; + break; + + case 't': + trace_config_fname = optarg; + break; + + case 'v': + verbose = atoi(optarg); + break; + + default: + usage(); + } + } + argc -= optind; argv += optind; + if (argc < 1) + usage(); + + debug("Debug enabled\n"); + return prof_tool(argc, argv, prof_fname, map_fname, + trace_config_fname); +}

Support tracing on sandbox by adding suitable CONFIG options. To enable it, compile U-Boot with FTRACE=1.
The timer functions are marked to skip tracing, since these are called from the tracing code itself, and we want to avoid an infinite loop.
Signed-off-by: Simon Glass sjg@chromium.org --- arch/sandbox/cpu/cpu.c | 2 +- arch/sandbox/cpu/os.c | 2 +- include/configs/sandbox.h | 13 +++++++++++++ 3 files changed, 15 insertions(+), 2 deletions(-)
diff --git a/arch/sandbox/cpu/cpu.c b/arch/sandbox/cpu/cpu.c index dd8d495..e9385de 100644 --- a/arch/sandbox/cpu/cpu.c +++ b/arch/sandbox/cpu/cpu.c @@ -37,7 +37,7 @@ void __udelay(unsigned long usec) os_usleep(usec); }
-unsigned long timer_get_us(void) +unsigned long __attribute__((no_instrument_function)) timer_get_us(void) { return os_get_nsec() / 1000; } diff --git a/arch/sandbox/cpu/os.c b/arch/sandbox/cpu/os.c index d075407..541e450 100644 --- a/arch/sandbox/cpu/os.c +++ b/arch/sandbox/cpu/os.c @@ -152,7 +152,7 @@ void os_usleep(unsigned long usec) usleep(usec); }
-u64 os_get_nsec(void) +u64 __attribute__((no_instrument_function)) os_get_nsec(void) { #if defined(CLOCK_MONOTONIC) && defined(_POSIX_MONOTONIC_CLOCK) struct timespec tp; diff --git a/include/configs/sandbox.h b/include/configs/sandbox.h index 788207d..d704329 100644 --- a/include/configs/sandbox.h +++ b/include/configs/sandbox.h @@ -22,6 +22,19 @@ #ifndef __CONFIG_H #define __CONFIG_H
+#ifdef FTRACE +#define CONFIG_TRACE +#define CONFIG_CMD_TRACE +#define CONFIG_TRACE_BUFFER_SIZE (16 << 20) +#define CONFIG_TRACE_EARLY_SIZE (8 << 20) +#define CONFIG_TRACE_EARLY +#define CONFIG_TRACE_EARLY_ADDR 0x00100000 + +#endif + +#define CONFIG_BOOTSTAGE +#define CONFIG_BOOTSTAGE_REPORT + /* Number of bits in a C 'long' on this architecture */ #define CONFIG_SANDBOX_BITS_PER_LONG 64

It is difficult to automatically test tracing on most architectures, but with sandbox it is easy enough to do a simple sanity check.
Signed-off-by: Simon Glass sjg@chromium.org --- test/trace/test-trace.sh | 88 ++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 88 insertions(+) create mode 100755 test/trace/test-trace.sh
diff --git a/test/trace/test-trace.sh b/test/trace/test-trace.sh new file mode 100755 index 0000000..b797667 --- /dev/null +++ b/test/trace/test-trace.sh @@ -0,0 +1,88 @@ +# Copyright (c) 2013 The Chromium OS Authors. +# +# 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 +# + +# Test script for tracing with sandbox + +OUTPUT_DIR=sandbox +TRACE_OPT="FTRACE=1" + +fail() { + echo "Test failed: $1" + if [ -n ${tmp} ]; then + rm ${tmp} + fi + exit 1 +} + +build_uboot() { + echo "Build sandbox" + OPTS="O=${OUTPUT_DIR} ${TRACE_OPT}" + NUM_CPUS=$(grep -c processor /proc/cpuinfo) + make ${OPTS} sandbox_config + make ${OPTS} -s -j${NUM_CPUS} +} + +run_trace() { + echo "Run trace" + ./${OUTPUT_DIR}/u-boot <<END + trace stats + hash sha256 0 10000 + trace pause + trace stats + hash sha256 0 10000 + trace stats + trace resume + hash sha256 0 10000 + trace pause + trace stats + reset +END +} + +check_results() { + echo "Check results" + + # Expect sha256 to run 3 times, so we see the string 6 times + if [ $(grep -c sha256 ${tmp}) -ne 6 ]; then + fail "sha256 error" + fi + + # 4 sets of results (output of 'trace stats') + if [ $(grep -c "traced function calls" ${tmp}) -ne 4 ]; then + fail "trace output error" + fi + + # Check trace counts. We expect to see an increase in the number of + # traced function calls between each 'trace stats' command, except + # between calls 2 and 3, where tracing is paused. + # This code gets the sign of the difference between each number and + # its predecessor. + counts="$(tr -d , <${tmp} | awk '/traced function calls/ { diff = $1 - upto; upto = $1; printf "%d ", diff < 0 ? -1 : (diff > 0 ? 1 : 0)}')" + + if [ "${counts}" != "1 1 0 1 " ]; then + fail "trace collection error: ${counts}" + fi +} + +echo "Simple trace test / sanity check using sandbox" +echo +tmp="$(tempfile)" +build_uboot +run_trace >${tmp} +check_results ${tmp} +rm ${tmp}

At present the arguments to bootm are processed in a somewhat confusing way. Sub-functions must know how many arguments their calling functions have processed, and the OS boot function must also have this information. Also it isn't obvious that 'bootm' and 'bootm start' provide arguments in the same way.
Adjust the code so that arguments are removed from the list before calling a sub-function. This means that all functions can know that argv[0] is the first argument of which they need to take notice.
Signed-off-by: Simon Glass sjg@chromium.org --- arch/microblaze/lib/bootm.c | 4 ++-- arch/nios2/lib/bootm.c | 4 ++-- arch/openrisc/lib/bootm.c | 4 ++-- common/cmd_bootm.c | 44 ++++++++++++++++++++++++++------------------ common/image-fdt.c | 13 ++++++++----- common/image.c | 22 ++++++++++++++-------- 6 files changed, 54 insertions(+), 37 deletions(-)
diff --git a/arch/microblaze/lib/bootm.c b/arch/microblaze/lib/bootm.c index 66d21f4..f0ec7ae 100644 --- a/arch/microblaze/lib/bootm.c +++ b/arch/microblaze/lib/bootm.c @@ -61,8 +61,8 @@ int do_bootm_linux(int flag, int argc, char * const argv[], bootm_headers_t *ima
bootstage_mark(BOOTSTAGE_ID_RUN_OS);
- if (!of_flat_tree && argc > 3) - of_flat_tree = (char *)simple_strtoul(argv[3], NULL, 16); + if (!of_flat_tree && argc > 1) + of_flat_tree = (char *)simple_strtoul(argv[1], NULL, 16); #ifdef DEBUG printf ("## Transferring control to Linux (at address 0x%08lx) " \ "ramdisk 0x%08lx, FDT 0x%08lx...\n", diff --git a/arch/nios2/lib/bootm.c b/arch/nios2/lib/bootm.c index f32be52..114e146 100644 --- a/arch/nios2/lib/bootm.c +++ b/arch/nios2/lib/bootm.c @@ -40,8 +40,8 @@ int do_bootm_linux(int flag, int argc, char * const argv[], bootm_headers_t *ima if (images->ft_len) of_flat_tree = images->ft_addr; #endif - if (!of_flat_tree && argc > 3) - of_flat_tree = (char *)simple_strtoul(argv[3], NULL, 16); + if (!of_flat_tree && argc > 1) + of_flat_tree = (char *)simple_strtoul(argv[1], NULL, 16); if (of_flat_tree) initrd_end = (ulong)of_flat_tree;
diff --git a/arch/openrisc/lib/bootm.c b/arch/openrisc/lib/bootm.c index 2c5d9ae..7f716b8 100644 --- a/arch/openrisc/lib/bootm.c +++ b/arch/openrisc/lib/bootm.c @@ -63,8 +63,8 @@ int do_bootm_linux(int flag, int argc, char * const argv[],
show_boot_progress(15);
- if (!of_flat_tree && argc > 3) - of_flat_tree = (char *)simple_strtoul(argv[3], NULL, 16); + if (!of_flat_tree && argc > 1) + of_flat_tree = (char *)simple_strtoul(argv[1], NULL, 16); #ifdef DEBUG printf("## Transferring control to Linux (at address 0x%08lx) " \ "ramdisk 0x%08lx, FDT 0x%08lx...\n", diff --git a/common/cmd_bootm.c b/common/cmd_bootm.c index d97c9c7..5236fb4 100644 --- a/common/cmd_bootm.c +++ b/common/cmd_bootm.c @@ -104,9 +104,18 @@ static const void *boot_get_kernel(cmd_tbl_t *cmdtp, int flag, int argc, * - verified image architecture (PPC) and type (KERNEL or MULTI), * - loaded (first part of) image to header load address, * - disabled interrupts. + * + * @flag: Command flags (CMD_FLAG_...) + * @argc: Number of arguments. Note that the arguments are shifted down + * so that 0 is the first argument not processed by U-Boot, and + * argc is adjusted accordingly. This avoids confusion as to how + * many arguments are available for the OS. + * @images: Pointers to os/initrd/fdt + * @return 1 on error. On success the OS boots so this function does + * not return. */ typedef int boot_os_fn(int flag, int argc, char * const argv[], - bootm_headers_t *images); /* pointers to os/initrd/fdt */ + bootm_headers_t *images);
#ifdef CONFIG_BOOTM_LINUX extern boot_os_fn do_bootm_linux; @@ -457,7 +466,7 @@ static int bootm_start_standalone(ulong iflag, int argc, char * const argv[]) return 0; } appl = (int (*)(int, char * const []))(ulong)ntohl(images.ep); - (*appl)(argc-1, &argv[1]); + (*appl)(argc, argv); return 0; }
@@ -486,17 +495,15 @@ static int do_bootm_subcommand(cmd_tbl_t *cmdtp, int flag, int argc, cmd_tbl_t *c; boot_os_fn *boot_fn;
- c = find_cmd_tbl(argv[1], &cmd_bootm_sub[0], ARRAY_SIZE(cmd_bootm_sub)); + c = find_cmd_tbl(argv[0], &cmd_bootm_sub[0], ARRAY_SIZE(cmd_bootm_sub)); + argc--; argv++;
if (c) { state = (long)c->cmd;
/* treat start special since it resets the state machine */ - if (state == BOOTM_STATE_START) { - argc--; - argv++; + if (state == BOOTM_STATE_START) return bootm_start(cmdtp, flag, argc, argv); - } } else { /* Unrecognized command */ return CMD_RET_USAGE; @@ -611,11 +618,12 @@ int do_bootm(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) #endif
/* determine if we have a sub command */ - if (argc > 1) { + argc--; argv++; + if (argc > 0) { char *endp;
- simple_strtoul(argv[1], &endp, 16); - /* endp pointing to NULL means that argv[1] was just a + simple_strtoul(argv[0], &endp, 16); + /* endp pointing to NULL means that argv[0] was just a * valid number, pass it along to the normal bootm processing * * If endp is ':' or '#' assume a FIT identifier so pass @@ -816,22 +824,22 @@ static const void *boot_get_kernel(cmd_tbl_t *cmdtp, int flag, int argc, #endif
/* find out kernel image address */ - if (argc < 2) { + if (argc < 1) { img_addr = load_addr; debug("* kernel: default image load address = 0x%08lx\n", load_addr); #if defined(CONFIG_FIT) - } else if (fit_parse_conf(argv[1], load_addr, &img_addr, + } else if (fit_parse_conf(argv[0], load_addr, &img_addr, &fit_uname_config)) { debug("* kernel: config '%s' from image at 0x%08lx\n", fit_uname_config, img_addr); - } else if (fit_parse_subimage(argv[1], load_addr, &img_addr, + } else if (fit_parse_subimage(argv[0], load_addr, &img_addr, &fit_uname_kernel)) { debug("* kernel: subimage '%s' from image at 0x%08lx\n", fit_uname_kernel, img_addr); #endif } else { - img_addr = simple_strtoul(argv[1], NULL, 16); + img_addr = simple_strtoul(argv[0], NULL, 16); debug("* kernel: cmdline image address = 0x%08lx\n", img_addr); }
@@ -1384,16 +1392,16 @@ static int do_bootm_netbsd(int flag, int argc, char * const argv[], consdev = "scc3"; #endif
- if (argc > 2) { + if (argc > 0) { ulong len; int i;
- for (i = 2, len = 0; i < argc; i += 1) + for (i = 0, len = 0; i < argc; i += 1) len += strlen(argv[i]) + 1; cmdline = malloc(len);
- for (i = 2, len = 0; i < argc; i += 1) { - if (i > 2) + for (i = 0, len = 0; i < argc; i += 1) { + if (i > 0) cmdline[len++] = ' '; strcpy(&cmdline[len], argv[i]); len += strlen(argv[i]); diff --git a/common/image-fdt.c b/common/image-fdt.c index 0d421d9..d99f444 100644 --- a/common/image-fdt.c +++ b/common/image-fdt.c @@ -248,13 +248,16 @@ int boot_get_fdt(int flag, int argc, char * const argv[], uint8_t arch, ulong default_addr; int fdt_noffset; #endif + const char *select = NULL;
*of_flat_tree = NULL; *of_size = 0;
- if (argc > 3 || genimg_has_config(images)) { + if (argc > 2) + select = argv[2]; + if (select || genimg_has_config(images)) { #if defined(CONFIG_FIT) - if (argc > 3) { + if (select) { /* * If the FDT blob comes from the FIT image and the * FIT image address is omitted in the command line @@ -268,18 +271,18 @@ int boot_get_fdt(int flag, int argc, char * const argv[], uint8_t arch, else default_addr = load_addr;
- if (fit_parse_conf(argv[3], default_addr, + if (fit_parse_conf(select, default_addr, &fdt_addr, &fit_uname_config)) { debug("* fdt: config '%s' from image at 0x%08lx\n", fit_uname_config, fdt_addr); - } else if (fit_parse_subimage(argv[3], default_addr, + } else if (fit_parse_subimage(select, default_addr, &fdt_addr, &fit_uname_fdt)) { debug("* fdt: subimage '%s' from image at 0x%08lx\n", fit_uname_fdt, fdt_addr); } else #endif { - fdt_addr = simple_strtoul(argv[3], NULL, 16); + fdt_addr = simple_strtoul(select, NULL, 16); debug("* fdt: cmdline image address = 0x%08lx\n", fdt_addr); } diff --git a/common/image.c b/common/image.c index f863502..d117a76 100644 --- a/common/image.c +++ b/common/image.c @@ -816,20 +816,23 @@ int boot_get_ramdisk(int argc, char * const argv[], bootm_headers_t *images, ulong default_addr; int rd_noffset; #endif + const char *select = NULL;
*rd_start = 0; *rd_end = 0;
+ if (argc >= 2) + select = argv[1]; /* * Look for a '-' which indicates to ignore the * ramdisk argument */ - if ((argc >= 3) && (strcmp(argv[2], "-") == 0)) { + if (select && strcmp(select, "-") == 0) { debug("## Skipping init Ramdisk\n"); rd_len = rd_data = 0; - } else if (argc >= 3 || genimg_has_config(images)) { + } else if (select || genimg_has_config(images)) { #if defined(CONFIG_FIT) - if (argc >= 3) { + if (select) { /* * If the init ramdisk comes from the FIT image and * the FIT image address is omitted in the command @@ -841,12 +844,12 @@ int boot_get_ramdisk(int argc, char * const argv[], bootm_headers_t *images, else default_addr = load_addr;
- if (fit_parse_conf(argv[2], default_addr, - &rd_addr, &fit_uname_config)) { + if (fit_parse_conf(select, default_addr, + &rd_addr, &fit_uname_config)) { debug("* ramdisk: config '%s' from image at " "0x%08lx\n", fit_uname_config, rd_addr); - } else if (fit_parse_subimage(argv[2], default_addr, + } else if (fit_parse_subimage(select, default_addr, &rd_addr, &fit_uname_ramdisk)) { debug("* ramdisk: subimage '%s' from image at " "0x%08lx\n", @@ -854,7 +857,7 @@ int boot_get_ramdisk(int argc, char * const argv[], bootm_headers_t *images, } else #endif { - rd_addr = simple_strtoul(argv[2], NULL, 16); + rd_addr = simple_strtoul(select, NULL, 16); debug("* ramdisk: cmdline image address = " "0x%08lx\n", rd_addr); @@ -918,7 +921,10 @@ int boot_get_ramdisk(int argc, char * const argv[], bootm_headers_t *images, #endif default: #ifdef CONFIG_SUPPORT_RAW_INITRD - if (argc >= 3 && (end = strchr(argv[2], ':'))) { + end = NULL; + if (select) + end = strchr(select, ':'); + if (end)) { rd_len = simple_strtoul(++end, NULL, 16); rd_data = rd_addr; } else

At present the bootm code is mostly duplicated for the plain 'bootm' command and its sub-command variant. This makes the code harder to maintain and means that changes must be made to several places.
Introduce do_bootm_states() which performs selected portions of the bootm work, so that both plain 'bootm' and 'bootm <sub_command>' can use the same code.
Additional duplication exists in bootz, so tidy that up as well. This is not intended to change behaviour, apart from minor fixes where the previously-duplicated code missed some chunks of code.
Signed-off-by: Simon Glass sjg@chromium.org --- common/cmd_bootm.c | 457 +++++++++++++++++++++++++---------------------------- include/image.h | 16 +- 2 files changed, 226 insertions(+), 247 deletions(-)
diff --git a/common/cmd_bootm.c b/common/cmd_bootm.c index 5236fb4..f441064 100644 --- a/common/cmd_bootm.c +++ b/common/cmd_bootm.c @@ -208,15 +208,21 @@ static inline void boot_start_lmb(bootm_headers_t *images) { }
static int bootm_start(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) { - const void *os_hdr; - int ret; - memset((void *)&images, 0, sizeof(images)); images.verify = getenv_yesno("verify");
boot_start_lmb(&images);
bootstage_mark_name(BOOTSTAGE_ID_BOOTM_START, "bootm_start"); + images.state = BOOTM_STATE_START; + + return 0; +} + +static int bootm_find_os(cmd_tbl_t *cmdtp, int flag, int argc, + char * const argv[]) +{ + const void *os_hdr;
/* get kernel image header, start address and length */ os_hdr = boot_get_kernel(cmdtp, flag, argc, argv, @@ -279,6 +285,8 @@ static int bootm_start(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[] images.ep = image_get_ep(&images.legacy_hdr_os_copy); #if defined(CONFIG_FIT) } else if (images.fit_uname_os) { + int ret; + ret = fit_image_get_entry(images.fit_hdr_os, images.fit_noffset_os, &images.ep); if (ret) { @@ -296,6 +304,16 @@ static int bootm_start(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[] images.ep += images.os.load; }
+ images.os.start = (ulong)os_hdr; + + return 0; +} + +static int bootm_find_other(cmd_tbl_t *cmdtp, int flag, int argc, + char * const argv[]) +{ + int ret; + if (((images.os.type == IH_TYPE_KERNEL) || (images.os.type == IH_TYPE_KERNEL_NOLOAD) || (images.os.type == IH_TYPE_MULTI)) && @@ -321,9 +339,6 @@ static int bootm_start(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[] #endif }
- images.os.start = (ulong)os_hdr; - images.state = BOOTM_STATE_START; - return 0; }
@@ -455,7 +470,7 @@ static int bootm_load_os(image_info_t os, ulong *load_end, int boot_progress) return 0; }
-static int bootm_start_standalone(ulong iflag, int argc, char * const argv[]) +static int bootm_start_standalone(int argc, char * const argv[]) { char *s; int (*appl)(int, char * const []); @@ -487,103 +502,210 @@ static cmd_tbl_t cmd_bootm_sub[] = { U_BOOT_CMD_MKENT(go, 0, 1, (void *)BOOTM_STATE_OS_GO, "", ""), };
+static int boot_selected_os(int argc, char * const argv[], int state, + bootm_headers_t *images, boot_os_fn *boot_fn, ulong *iflag) +{ + if (images->os.type == IH_TYPE_STANDALONE) { + /* This may return when 'autostart' is 'no' */ + bootm_start_standalone(argc, argv); + return 0; + } + /* + * We have reached the point of no return: we are going to + * overwrite all exception vector code, so we cannot easily + * recover from any failures any more... + */ + *iflag = disable_interrupts(); +#ifdef CONFIG_NETCONSOLE + /* Stop the ethernet stack if NetConsole could have left it up */ + eth_halt(); +#endif + +#if defined(CONFIG_CMD_USB) + /* + * turn off USB to prevent the host controller from writing to the + * SDRAM while Linux is booting. This could happen (at least for OHCI + * controller), because the HCCA (Host Controller Communication Area) + * lies within the SDRAM and the host controller writes continously to + * this area (as busmaster!). The HccaFrameNumber is for example + * updated every 1 ms within the HCCA structure in SDRAM! For more + * details see the OpenHCI specification. + */ + usb_stop(); +#endif +#ifdef CONFIG_SILENT_CONSOLE + if (images->os.os == IH_OS_LINUX) + fixup_silent_linux(); +#endif + arch_preboot_os(); + boot_fn(state, argc, argv, images); + bootstage_error(BOOTSTAGE_ID_BOOT_OS_RETURNED); +#ifdef DEBUG + puts("\n## Control returned to monitor - resetting...\n"); +#endif + return BOOTM_ERR_RESET; +} + +/** + * Execute selected states of the bootm command. + * + * Note the arguments to this state must be the first argument, Any 'bootm' + * or sub-command arguments must have already been taken. + * + * Note that if states contains more than one flag it MUST contain + * BOOTM_STATE_START, since this handles and consumes the command line args. + * + * @param cmdtp Pointer to bootm command table entry + * @param flag Command flags (CMD_FLAG_...) + * @param argc Number of subcommand arguments (0 = no arguments) + * @param argv Arguments + * @param states Mask containing states to run (BOOTM_STATE_...) + * @param images Image header information + * @param boot_progress 1 to show boot progress, 0 to not do this + * @return 0 if ok, something else on error. Some errors will cause this + * function to perform a reboot! If states contains BOOTM_STATE_OS_GO + * then the intent is to boot an OS, so this function will not return + * unless the image type is standalone. + */ +static int do_bootm_states(cmd_tbl_t *cmdtp, int flag, int argc, + char * const argv[], int states, bootm_headers_t *images, + int boot_progress) +{ + boot_os_fn *boot_fn; + ulong iflag = 0; + int ret = 0; + + printf("argc=%d\n", argc); + images->state |= states; + + /* + * Work through the states and see how far we get. We stop on + * any error. + */ + if (states & BOOTM_STATE_START) + ret = bootm_start(cmdtp, flag, argc, argv); + + if (!ret && (states & BOOTM_STATE_FINDOS)) + ret = bootm_find_os(cmdtp, flag, argc, argv); + + if (!ret && (states & BOOTM_STATE_FINDOTHER)) { + ret = bootm_find_other(cmdtp, flag, argc, argv); + argc = 0; /* consume the args */ + } + + /* Load the OS */ + if (!ret && (states & BOOTM_STATE_LOADOS)) { + ulong load_end; + + ret = bootm_load_os(images->os, &load_end, 0); + if (!ret) { + lmb_reserve(&images->lmb, images->os.load, + (load_end - images->os.load)); + } + } + + /* Relocate the ramdisk */ +#ifdef CONFIG_SYS_BOOT_RAMDISK_HIGH + if (!ret && (states & BOOTM_STATE_RAMDISK)) { + ulong rd_len = images->rd_end - images->rd_start; + + ret = boot_ramdisk_high(&images->lmb, images->rd_start, + rd_len, &images->initrd_start, &images->initrd_end); + if (!ret) { + setenv_hex("initrd_start", images->initrd_start); + setenv_hex("initrd_end", images->initrd_end); + } + } +#endif +#if defined(CONFIG_OF_LIBFDT) && defined(CONFIG_LMB) + if (!ret && (states & BOOTM_STATE_FDT)) { + boot_fdt_add_mem_rsv_regions(&images->lmb, images->ft_addr); + ret = boot_relocate_fdt(&images->lmb, &images->ft_addr, + &images->ft_len); + } +#endif + + /* From now on, we need the OS boot function */ + if (ret) + return ret; + boot_fn = boot_os[images->os.os]; + if (boot_fn == NULL) { + if (iflag) + enable_interrupts(); + printf("ERROR: booting os '%s' (%d) is not supported\n", + genimg_get_os_name(images->os.os), images->os.os); + bootstage_error(BOOTSTAGE_ID_CHECK_BOOT_OS); + return 1; + } + + /* Call various other states that are not generally used */ + if (!ret && (states & BOOTM_STATE_OS_CMDLINE)) + ret = boot_fn(BOOTM_STATE_OS_CMDLINE, argc, argv, images); + if (!ret && (states & BOOTM_STATE_OS_BD_T)) + ret = boot_fn(BOOTM_STATE_OS_BD_T, argc, argv, images); + if (!ret && (states & BOOTM_STATE_OS_PREP)) + ret = boot_fn(BOOTM_STATE_OS_PREP, argc, argv, images); + + /* Now run the OS! We hope this doesn't return */ + if (!ret && (states & BOOTM_STATE_OS_GO)) + ret = boot_selected_os(argc, argv, BOOTM_STATE_OS_GO, + images, boot_fn, &iflag); + + /* Deal with any fallout */ + if (ret < 0) { + if (ret == BOOTM_ERR_UNIMPLEMENTED) { + if (iflag) + enable_interrupts(); + bootstage_error(BOOTSTAGE_ID_DECOMP_UNIMPL); + return 1; + } else if (ret == BOOTM_ERR_OVERLAP) { + if (images->legacy_hdr_valid) { + if (image_get_type(&images->legacy_hdr_os_copy) + == IH_TYPE_MULTI) + puts("WARNING: legacy format multi component image overwritten\n"); + } else { + puts("ERROR: new format image overwritten - must RESET the board to recover\n"); + bootstage_error(BOOTSTAGE_ID_OVERWRITTEN); + ret = BOOTM_ERR_RESET; + } + } + if (ret == BOOTM_ERR_RESET) + do_reset(cmdtp, flag, argc, argv); + } + if (iflag) + enable_interrupts(); + if (ret) + puts("subcommand not supported\n"); + + return ret; +} + static int do_bootm_subcommand(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) { int ret = 0; long state; cmd_tbl_t *c; - boot_os_fn *boot_fn;
c = find_cmd_tbl(argv[0], &cmd_bootm_sub[0], ARRAY_SIZE(cmd_bootm_sub)); argc--; argv++;
if (c) { state = (long)c->cmd; - - /* treat start special since it resets the state machine */ if (state == BOOTM_STATE_START) - return bootm_start(cmdtp, flag, argc, argv); + state |= BOOTM_STATE_FINDOS | BOOTM_STATE_FINDOTHER; } else { /* Unrecognized command */ return CMD_RET_USAGE; } + printf("subcmd=%lx, argc=%d\n", state, argc);
- if (images.state < BOOTM_STATE_START || - images.state >= state) { + if (state != BOOTM_STATE_START && images.state >= state) { printf("Trying to execute a command out of order\n"); return CMD_RET_USAGE; }
- images.state |= state; - boot_fn = boot_os[images.os.os]; - - switch (state) { - ulong load_end; - case BOOTM_STATE_START: - /* should never occur */ - break; - case BOOTM_STATE_LOADOS: - ret = bootm_load_os(images.os, &load_end, 0); - if (ret) - return ret; - - lmb_reserve(&images.lmb, images.os.load, - (load_end - images.os.load)); - break; -#ifdef CONFIG_SYS_BOOT_RAMDISK_HIGH - case BOOTM_STATE_RAMDISK: - { - ulong rd_len = images.rd_end - images.rd_start; - - ret = boot_ramdisk_high(&images.lmb, images.rd_start, - rd_len, &images.initrd_start, &images.initrd_end); - if (ret) - return ret; - - setenv_hex("initrd_start", images.initrd_start); - setenv_hex("initrd_end", images.initrd_end); - } - break; -#endif -#if defined(CONFIG_OF_LIBFDT) && defined(CONFIG_LMB) - case BOOTM_STATE_FDT: - { - boot_fdt_add_mem_rsv_regions(&images.lmb, - images.ft_addr); - ret = boot_relocate_fdt(&images.lmb, - &images.ft_addr, &images.ft_len); - break; - } -#endif - case BOOTM_STATE_OS_CMDLINE: - ret = boot_fn(BOOTM_STATE_OS_CMDLINE, argc, argv, &images); - if (ret) - printf("cmdline subcommand not supported\n"); - break; - case BOOTM_STATE_OS_BD_T: - ret = boot_fn(BOOTM_STATE_OS_BD_T, argc, argv, &images); - if (ret) - printf("bdt subcommand not supported\n"); - break; - case BOOTM_STATE_OS_PREP: - ret = boot_fn(BOOTM_STATE_OS_PREP, argc, argv, &images); - if (ret) - printf("prep subcommand not supported\n"); - break; - case BOOTM_STATE_OS_GO: - disable_interrupts(); -#ifdef CONFIG_NETCONSOLE - /* - * Stop the ethernet stack if NetConsole could have - * left it up - */ - eth_halt(); -#endif - arch_preboot_os(); - boot_fn(BOOTM_STATE_OS_GO, argc, argv, &images); - break; - } + ret = do_bootm_states(cmdtp, flag, argc, argv, state, &images, 0);
return ret; } @@ -594,10 +716,6 @@ static int do_bootm_subcommand(cmd_tbl_t *cmdtp, int flag, int argc,
int do_bootm(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) { - ulong iflag; - ulong load_end = 0; - int ret; - boot_os_fn *boot_fn; #ifdef CONFIG_NEEDS_MANUAL_RELOC static int relocated = 0;
@@ -635,101 +753,9 @@ int do_bootm(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) return do_bootm_subcommand(cmdtp, flag, argc, argv); }
- if (bootm_start(cmdtp, flag, argc, argv)) - return 1; - - /* - * We have reached the point of no return: we are going to - * overwrite all exception vector code, so we cannot easily - * recover from any failures any more... - */ - iflag = disable_interrupts(); - -#ifdef CONFIG_NETCONSOLE - /* Stop the ethernet stack if NetConsole could have left it up */ - eth_halt(); -#endif - -#if defined(CONFIG_CMD_USB) - /* - * turn off USB to prevent the host controller from writing to the - * SDRAM while Linux is booting. This could happen (at least for OHCI - * controller), because the HCCA (Host Controller Communication Area) - * lies within the SDRAM and the host controller writes continously to - * this area (as busmaster!). The HccaFrameNumber is for example - * updated every 1 ms within the HCCA structure in SDRAM! For more - * details see the OpenHCI specification. - */ - usb_stop(); -#endif - - ret = bootm_load_os(images.os, &load_end, 1); - - if (ret < 0) { - if (ret == BOOTM_ERR_RESET) - do_reset(cmdtp, flag, argc, argv); - if (ret == BOOTM_ERR_OVERLAP) { - if (images.legacy_hdr_valid) { - image_header_t *hdr; - hdr = &images.legacy_hdr_os_copy; - if (image_get_type(hdr) == IH_TYPE_MULTI) - puts("WARNING: legacy format multi " - "component image " - "overwritten\n"); - } else { - puts("ERROR: new format image overwritten - " - "must RESET the board to recover\n"); - bootstage_error(BOOTSTAGE_ID_OVERWRITTEN); - do_reset(cmdtp, flag, argc, argv); - } - } - if (ret == BOOTM_ERR_UNIMPLEMENTED) { - if (iflag) - enable_interrupts(); - bootstage_error(BOOTSTAGE_ID_DECOMP_UNIMPL); - return 1; - } - } - - lmb_reserve(&images.lmb, images.os.load, (load_end - images.os.load)); - - if (images.os.type == IH_TYPE_STANDALONE) { - if (iflag) - enable_interrupts(); - /* This may return when 'autostart' is 'no' */ - bootm_start_standalone(iflag, argc, argv); - return 0; - } - - bootstage_mark(BOOTSTAGE_ID_CHECK_BOOT_OS); - -#if defined(CONFIG_SILENT_CONSOLE) && !defined(CONFIG_SILENT_U_BOOT_ONLY) - if (images.os.os == IH_OS_LINUX) - fixup_silent_linux(); -#endif - - boot_fn = boot_os[images.os.os]; - - if (boot_fn == NULL) { - if (iflag) - enable_interrupts(); - printf("ERROR: booting os '%s' (%d) is not supported\n", - genimg_get_os_name(images.os.os), images.os.os); - bootstage_error(BOOTSTAGE_ID_CHECK_BOOT_OS); - return 1; - } - - arch_preboot_os(); - - boot_fn(0, argc, argv, &images); - - bootstage_error(BOOTSTAGE_ID_BOOT_OS_RETURNED); -#ifdef DEBUG - puts("\n## Control returned to monitor - resetting...\n"); -#endif - do_reset(cmdtp, flag, argc, argv); - - return 1; + return do_bootm_states(cmdtp, flag, argc, argv, BOOTM_STATE_START | + BOOTM_STATE_FINDOS | BOOTM_STATE_FINDOTHER | + BOOTM_STATE_LOADOS | BOOTM_STATE_OS_GO, &images, 1); }
int bootm_maybe_autostart(cmd_tbl_t *cmdtp, const char *cmd) @@ -823,6 +849,7 @@ static const void *boot_get_kernel(cmd_tbl_t *cmdtp, int flag, int argc, int os_noffset; #endif
+ printf("%s: argc=%d\n", __func__, argc); /* find out kernel image address */ if (argc < 1) { img_addr = load_addr; @@ -1654,9 +1681,8 @@ static int bootz_start(cmd_tbl_t *cmdtp, int flag, int argc, int ret; void *zi_start, *zi_end;
- memset(images, 0, sizeof(bootm_headers_t)); - - boot_start_lmb(images); + ret = do_bootm_states(cmdtp, flag, argc, argv, BOOTM_STATE_START, + images, 1);
/* Setup Linux kernel zImage entry point */ if (argc < 2) { @@ -1675,73 +1701,24 @@ static int bootz_start(cmd_tbl_t *cmdtp, int flag, int argc,
lmb_reserve(&images->lmb, images->ep, zi_end - zi_start);
- /* Find ramdisk */ - ret = boot_get_ramdisk(argc, argv, images, IH_INITRD_ARCH, - &images->rd_start, &images->rd_end); - if (ret) { - puts("Ramdisk image is corrupt or invalid\n"); - return 1; - } - -#if defined(CONFIG_OF_LIBFDT) - /* find flattened device tree */ - ret = boot_get_fdt(flag, argc, argv, IH_ARCH_DEFAULT, images, - &images->ft_addr, &images->ft_len); - if (ret) { - puts("Could not find a valid device tree\n"); - return 1; - } - - set_working_fdt_addr(images->ft_addr); -#endif + ret = do_bootm_states(cmdtp, flag, argc, argv, BOOTM_STATE_FINDOTHER, + images, 1);
- return 0; + return ret; }
static int do_bootz(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) { bootm_headers_t images; + int ret;
if (bootz_start(cmdtp, flag, argc, argv, &images)) return 1;
- /* - * We have reached the point of no return: we are going to - * overwrite all exception vector code, so we cannot easily - * recover from any failures any more... - */ - disable_interrupts(); - -#ifdef CONFIG_NETCONSOLE - /* Stop the ethernet stack if NetConsole could have left it up */ - eth_halt(); -#endif + ret = do_bootm_states(cmdtp, flag, argc, argv, + BOOTM_STATE_OS_GO, &images, 1);
-#if defined(CONFIG_CMD_USB) - /* - * turn off USB to prevent the host controller from writing to the - * SDRAM while Linux is booting. This could happen (at least for OHCI - * controller), because the HCCA (Host Controller Communication Area) - * lies within the SDRAM and the host controller writes continously to - * this area (as busmaster!). The HccaFrameNumber is for example - * updated every 1 ms within the HCCA structure in SDRAM! For more - * details see the OpenHCI specification. - */ - usb_stop(); -#endif - -#if defined(CONFIG_SILENT_CONSOLE) && !defined(CONFIG_SILENT_U_BOOT_ONLY) - fixup_silent_linux(); -#endif - arch_preboot_os(); - - do_bootm_linux(0, argc, argv, &images); -#ifdef DEBUG - puts("\n## Control returned to monitor - resetting...\n"); -#endif - do_reset(cmdtp, flag, argc, argv); - - return 1; + return ret; }
#ifdef CONFIG_SYS_LONGHELP diff --git a/include/image.h b/include/image.h index 8ccc00b..8675a82 100644 --- a/include/image.h +++ b/include/image.h @@ -320,13 +320,15 @@ typedef struct bootm_headers { int verify; /* getenv("verify")[0] != 'n' */
#define BOOTM_STATE_START (0x00000001) -#define BOOTM_STATE_LOADOS (0x00000002) -#define BOOTM_STATE_RAMDISK (0x00000004) -#define BOOTM_STATE_FDT (0x00000008) -#define BOOTM_STATE_OS_CMDLINE (0x00000010) -#define BOOTM_STATE_OS_BD_T (0x00000020) -#define BOOTM_STATE_OS_PREP (0x00000040) -#define BOOTM_STATE_OS_GO (0x00000080) +#define BOOTM_STATE_FINDOS (0x00000002) +#define BOOTM_STATE_FINDOTHER (0x00000004) +#define BOOTM_STATE_LOADOS (0x00000008) +#define BOOTM_STATE_RAMDISK (0x00000010) +#define BOOTM_STATE_FDT (0x00000020) +#define BOOTM_STATE_OS_CMDLINE (0x00000040) +#define BOOTM_STATE_OS_BD_T (0x00000080) +#define BOOTM_STATE_OS_PREP (0x00000100) +#define BOOTM_STATE_OS_GO (0x00000200) int state;
#ifdef CONFIG_LMB

For tracing it is useful to run as much of U-Boot as possible so as to get a complete picture. Quite a bit of work happens in bootm, and we don't want to have to stop tracing before bootm starts.
Add a way of doing a 'fake' boot of the OS - which does everything up to the point where U-Boot is about to jump to the OS image. This allows tracing to record right until the end.
This requires arch support to work.
Signed-off-by: Simon Glass sjg@chromium.org --- common/cmd_bootm.c | 20 ++++++++++++++++++-- include/image.h | 3 ++- 2 files changed, 20 insertions(+), 3 deletions(-)
diff --git a/common/cmd_bootm.c b/common/cmd_bootm.c index f441064..2a08b19 100644 --- a/common/cmd_bootm.c +++ b/common/cmd_bootm.c @@ -499,6 +499,7 @@ static cmd_tbl_t cmd_bootm_sub[] = { U_BOOT_CMD_MKENT(cmdline, 0, 1, (void *)BOOTM_STATE_OS_CMDLINE, "", ""), U_BOOT_CMD_MKENT(bdt, 0, 1, (void *)BOOTM_STATE_OS_BD_T, "", ""), U_BOOT_CMD_MKENT(prep, 0, 1, (void *)BOOTM_STATE_OS_PREP, "", ""), + U_BOOT_CMD_MKENT(fake, 0, 1, (void *)BOOTM_STATE_OS_FAKE_GO, "", ""), U_BOOT_CMD_MKENT(go, 0, 1, (void *)BOOTM_STATE_OS_GO, "", ""), };
@@ -539,6 +540,8 @@ static int boot_selected_os(int argc, char * const argv[], int state, #endif arch_preboot_os(); boot_fn(state, argc, argv, images); + if (state == BOOTM_STATE_OS_FAKE_GO) /* We expect to return */ + return 0; bootstage_error(BOOTSTAGE_ID_BOOT_OS_RETURNED); #ifdef DEBUG puts("\n## Control returned to monitor - resetting...\n"); @@ -646,6 +649,17 @@ static int do_bootm_states(cmd_tbl_t *cmdtp, int flag, int argc, if (!ret && (states & BOOTM_STATE_OS_PREP)) ret = boot_fn(BOOTM_STATE_OS_PREP, argc, argv, images);
+#ifdef CONFIG_TRACE + /* Pretend to run the OS, then run a user command */ + if (!ret && (states & BOOTM_STATE_OS_FAKE_GO)) { + char *cmd_list = getenv("fakegocmd"); + + ret = boot_selected_os(argc, argv, BOOTM_STATE_OS_FAKE_GO, + images, boot_fn, &iflag); + if (!ret && cmd_list) + ret = run_command_list(cmd_list, -1, flag); + } +#endif /* Now run the OS! We hope this doesn't return */ if (!ret && (states & BOOTM_STATE_OS_GO)) ret = boot_selected_os(argc, argv, BOOTM_STATE_OS_GO, @@ -755,7 +769,8 @@ int do_bootm(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[])
return do_bootm_states(cmdtp, flag, argc, argv, BOOTM_STATE_START | BOOTM_STATE_FINDOS | BOOTM_STATE_FINDOTHER | - BOOTM_STATE_LOADOS | BOOTM_STATE_OS_GO, &images, 1); + BOOTM_STATE_LOADOS | BOOTM_STATE_OS_FAKE_GO | + BOOTM_STATE_OS_GO, &images, 1); }
int bootm_maybe_autostart(cmd_tbl_t *cmdtp, const char *cmd) @@ -1716,7 +1731,8 @@ static int do_bootz(cmd_tbl_t *cmdtp, int flag, int argc, char * const argv[]) return 1;
ret = do_bootm_states(cmdtp, flag, argc, argv, - BOOTM_STATE_OS_GO, &images, 1); + BOOTM_STATE_OS_FAKE_GO | BOOTM_STATE_OS_GO, + &images, 1);
return ret; } diff --git a/include/image.h b/include/image.h index 8675a82..4415bcf 100644 --- a/include/image.h +++ b/include/image.h @@ -328,7 +328,8 @@ typedef struct bootm_headers { #define BOOTM_STATE_OS_CMDLINE (0x00000040) #define BOOTM_STATE_OS_BD_T (0x00000080) #define BOOTM_STATE_OS_PREP (0x00000100) -#define BOOTM_STATE_OS_GO (0x00000200) +#define BOOTM_STATE_OS_FAKE_GO (0x00000200) /* 'Almost' run the OS */ +#define BOOTM_STATE_OS_GO (0x00000400) int state;
#ifdef CONFIG_LMB

Implement this feature on ARM for tracing.
It would be nice to have generic bootm support so that it is easily implemented on any arch.
Signed-off-by: Simon Glass sjg@chromium.org --- arch/arm/lib/bootm.c | 33 +++++++++++++++++++++------------ 1 file changed, 21 insertions(+), 12 deletions(-)
diff --git a/arch/arm/lib/bootm.c b/arch/arm/lib/bootm.c index 1b6e0ac..28fba19 100644 --- a/arch/arm/lib/bootm.c +++ b/arch/arm/lib/bootm.c @@ -68,12 +68,19 @@ void arch_lmb_reserve(struct lmb *lmb) gd->bd->bi_dram[0].start + gd->bd->bi_dram[0].size - sp); }
-static void announce_and_cleanup(void) +/** + * announce_and_cleanup() - Print message and prepare for kernel boot + * + * @fake: non-zero to do everything except actually boot + */ +static void announce_and_cleanup(int fake) { - printf("\nStarting kernel ...\n\n"); + printf("\nStarting kernel ...%s\n\n", fake ? + "(fake run for tracing)" : ""); bootstage_mark_name(BOOTSTAGE_ID_BOOTM_HANDOFF, "start_kernel"); #ifdef CONFIG_BOOTSTAGE_FDT - bootstage_fdt_add_report(); + if (flag == BOOTM_STATE_OS_FAKE_GO) + bootstage_fdt_add_report(); #endif #ifdef CONFIG_BOOTSTAGE_REPORT bootstage_report(); @@ -225,14 +232,15 @@ static void boot_prep_linux(bootm_headers_t *images) }
/* Subcommand: GO */ -static void boot_jump_linux(bootm_headers_t *images) +static void boot_jump_linux(bootm_headers_t *image, int flag) { unsigned long machid = gd->bd->bi_arch_number; char *s; void (*kernel_entry)(int zero, int arch, uint params); unsigned long r2; + int fake = (flag & BOOTM_STATE_OS_FAKE_GO);
- kernel_entry = (void (*)(int, int, uint))images->ep; + kernel_entry = (void (*)(int, int, uint))image->ep;
s = getenv("machid"); if (s) { @@ -243,14 +251,15 @@ static void boot_jump_linux(bootm_headers_t *images) debug("## Transferring control to Linux (at address %08lx)" \ "...\n", (ulong) kernel_entry); bootstage_mark(BOOTSTAGE_ID_RUN_OS); - announce_and_cleanup(); + announce_and_cleanup(fake);
- if (IMAGE_ENABLE_OF_LIBFDT && images->ft_len) - r2 = (unsigned long)images->ft_addr; + if (IMAGE_ENABLE_OF_LIBFDT && image->ft_len) + r2 = (unsigned long)image->ft_addr; else r2 = gd->bd->bi_boot_params;
- kernel_entry(0, machid, r2); + if (!fake) + kernel_entry(0, machid, r2); }
/* Main Entry point for arm bootm implementation @@ -270,13 +279,13 @@ int do_bootm_linux(int flag, int argc, char *argv[], bootm_headers_t *images) return 0; }
- if (flag & BOOTM_STATE_OS_GO) { - boot_jump_linux(images); + if (flag & (BOOTM_STATE_OS_GO | BOOTM_STATE_OS_FAKE_GO)) { + boot_jump_linux(images, flag); return 0; }
boot_prep_linux(images); - boot_jump_linux(images); + boot_jump_linux(images, flag); return 0; }

When this test fails it is useful to see the output from U-Boot. Add printing of this information on failure.
Signed-off-by: Simon Glass sjg@chromium.org --- test/image/test-fit.py | 19 ++++++++++--------- 1 file changed, 10 insertions(+), 9 deletions(-)
diff --git a/test/image/test-fit.py b/test/image/test-fit.py index c4e8211..aad9f59 100755 --- a/test/image/test-fit.py +++ b/test/image/test-fit.py @@ -272,12 +272,13 @@ def set_test(name): test_name = name print name
-def fail(msg): +def fail(msg, stdout): """Raise an error with a helpful failure message
Args: msg: Message to display """ + print stdout raise ValueError("Test '%s' failed: %s" % (test_name, msg))
def run_fit_test(mkimage, u_boot): @@ -341,11 +342,11 @@ def run_fit_test(mkimage, u_boot): set_test('Kernel load') stdout = command.Output(u_boot, '-d', control_dtb, '-c', cmd) if read_file(kernel) != read_file(kernel_out): - fail('Kernel not loaded') + fail('Kernel not loaded', stdout) if read_file(control_dtb) == read_file(fdt_out): - fail('FDT loaded but should be ignored') + fail('FDT loaded but should be ignored', stdout) if read_file(ramdisk) == read_file(ramdisk_out): - fail('Ramdisk loaded but should not be') + fail('Ramdisk loaded but should not be', stdout)
# Find out the offset in the FIT where U-Boot has found the FDT line = find_matching(stdout, 'Booting using the fdt blob at ') @@ -357,7 +358,7 @@ def run_fit_test(mkimage, u_boot): real_fit_offset = data.find(fdt_magic, 4) if fit_offset != real_fit_offset: fail('U-Boot loaded FDT from offset %#x, FDT is actually at %#x' % - (fit_offset, real_fit_offset)) + (fit_offset, real_fit_offset), stdout)
# Now a kernel and an FDT set_test('Kernel + FDT load') @@ -365,11 +366,11 @@ def run_fit_test(mkimage, u_boot): fit = make_fit(mkimage, params) stdout = command.Output(u_boot, '-d', control_dtb, '-c', cmd) if read_file(kernel) != read_file(kernel_out): - fail('Kernel not loaded') + fail('Kernel not loaded', stdout) if read_file(control_dtb) != read_file(fdt_out): - fail('FDT not loaded') + fail('FDT not loaded', stdout) if read_file(ramdisk) == read_file(ramdisk_out): - fail('Ramdisk loaded but should not be') + fail('Ramdisk loaded but should not be', stdout)
# Try a ramdisk set_test('Kernel + FDT + Ramdisk load') @@ -378,7 +379,7 @@ def run_fit_test(mkimage, u_boot): fit = make_fit(mkimage, params) stdout = command.Output(u_boot, '-d', control_dtb, '-c', cmd) if read_file(ramdisk) != read_file(ramdisk_out): - fail('Ramdisk not loaded') + fail('Ramdisk not loaded', stdout)
def run_tests(): """Parse options, run the FIT tests and print the result"""

For tracing to work it has to be able to access the microsecond timer without causing a recursive call to the function entry/exit handlers. Add attributes to the relevant functions to support this.
Signed-off-by: Simon Glass sjg@chromium.org --- arch/arm/cpu/armv7/s5p-common/timer.c | 2 +- arch/arm/include/asm/arch-exynos/cpu.h | 10 ++++++---- 2 files changed, 7 insertions(+), 5 deletions(-)
diff --git a/arch/arm/cpu/armv7/s5p-common/timer.c b/arch/arm/cpu/armv7/s5p-common/timer.c index 4adfaae..637593c 100644 --- a/arch/arm/cpu/armv7/s5p-common/timer.c +++ b/arch/arm/cpu/armv7/s5p-common/timer.c @@ -95,7 +95,7 @@ unsigned long get_timer(unsigned long base) return time_ms - base; }
-unsigned long timer_get_us(void) +unsigned long __attribute__((no_instrument_function)) timer_get_us(void) { static unsigned long base_time_us;
diff --git a/arch/arm/include/asm/arch-exynos/cpu.h b/arch/arm/include/asm/arch-exynos/cpu.h index f76e489..6b1b54f 100644 --- a/arch/arm/include/asm/arch-exynos/cpu.h +++ b/arch/arm/include/asm/arch-exynos/cpu.h @@ -175,7 +175,7 @@ static inline char *s5p_get_cpu_name(void) }
#define IS_SAMSUNG_TYPE(type, id) \ -static inline int cpu_is_##type(void) \ +static inline int __attribute__((no_instrument_function)) cpu_is_##type(void) \ { \ return (s5p_cpu_id >> 12) == id; \ } @@ -184,7 +184,8 @@ IS_SAMSUNG_TYPE(exynos4, 0x4) IS_SAMSUNG_TYPE(exynos5, 0x5)
#define IS_EXYNOS_TYPE(type, id) \ -static inline int proid_is_##type(void) \ +static inline int __attribute__((no_instrument_function)) \ + proid_is_##type(void) \ { \ return s5p_cpu_id == id; \ } @@ -194,9 +195,10 @@ IS_EXYNOS_TYPE(exynos4412, 0x4412) IS_EXYNOS_TYPE(exynos5250, 0x5250)
#define SAMSUNG_BASE(device, base) \ -static inline unsigned int samsung_get_base_##device(void) \ +static inline unsigned int __attribute__((no_instrument_function)) \ + samsung_get_base_##device(void) \ { \ - if (cpu_is_exynos4()) { \ + if (cpu_is_exynos4()) { \ if (proid_is_exynos4412()) \ return EXYNOS4X12_##base; \ return EXYNOS4_##base; \

On Sat, Apr 27, 2013 at 07:17:37PM -0700, Simon Glass wrote:
This series adds a tracing feature to U-Boot which is useful for profiling boot time and other purposes.
The core trace library relies on standard gcc function instrumentation and a microsecond timer which should work correctly on almost any architecture. Generic board is used to avoid the need to add the same code in multiple places (CONFIG_SYS_GENERIC_BOARD).
Tracing must be built into the U-Boot image at build time, but can be paused and resumed while running. A trace buffer is used to collect trace information. This buffer can then be transmitted to a host for processing. A host-based processing tool is provided which converts the data to the same format used by Linux, and that can be read by the pytimechart GUI tool.
A U-Boot 'trace' command provides access to the trace information, including support for writing it to memory in a few forms.
Support is provided for stopping tracing at the last possible moment in the bootm process (just before U-Boot jumps to the OS). This is done with a new 'fake go' command, which allows bootm to go through the motions of an OS boot without actually committing to it. Once the 'fake go' is complete, U-Boot can stop tracing and continue execution to transmit the trace information to the host, before jumping to the OS for real.
The system is tested on sandbox and has previously worked on ARM Tegra and Exynos machines. A simple test script is provided for sandbox, along with documentation on how to use the feature.
This feature has been successfully used alongside bootstage to locate bottlenecks and reduce overall boot time.
Because of the bootm changes this series sits on top of the image improvements that were done for verified boot. This series is available at:
http://git.denx.de/u-boot-x86.git
in branch 'trace'.
I like the concept, implementations seems reasonable. How far back does gcc support -finstrument-functions? Any chance of getting tegra support at least resurrected (since it uses the generic board framework)? Thanks!

Hi Tom,
On Mon, May 13, 2013 at 2:36 PM, Tom Rini trini@ti.com wrote:
On Sat, Apr 27, 2013 at 07:17:37PM -0700, Simon Glass wrote:
This series adds a tracing feature to U-Boot which is useful for profiling boot time and other purposes.
The core trace library relies on standard gcc function instrumentation and a microsecond timer which should work correctly on almost any architecture. Generic board is used to avoid the need to add the same code in multiple places (CONFIG_SYS_GENERIC_BOARD).
Tracing must be built into the U-Boot image at build time, but can be paused and resumed while running. A trace buffer is used to collect trace information. This buffer can then be transmitted to a host for processing. A host-based processing tool is provided which converts the data to the same format used by Linux, and that can be read by the pytimechart GUI tool.
A U-Boot 'trace' command provides access to the trace information, including support for writing it to memory in a few forms.
Support is provided for stopping tracing at the last possible moment in the bootm process (just before U-Boot jumps to the OS). This is done with a new 'fake go' command, which allows bootm to go through the motions of an OS boot without actually committing to it. Once the 'fake go' is complete, U-Boot can stop tracing and continue execution to transmit the trace information to the host, before jumping to the OS for real.
The system is tested on sandbox and has previously worked on ARM Tegra and Exynos machines. A simple test script is provided for sandbox, along with documentation on how to use the feature.
This feature has been successfully used alongside bootstage to locate bottlenecks and reduce overall boot time.
Because of the bootm changes this series sits on top of the image improvements that were done for verified boot. This series is available at:
http://git.denx.de/u-boot-x86.git
in branch 'trace'.
I like the concept, implementations seems reasonable. How far back does gcc support -finstrument-functions? Any chance of getting tegra support at least resurrected (since it uses the generic board framework)?
OK thanks, I will take a look at these points in the next week or two, and make sure it works on Tegra, Exynos and x86 (as well as the current sandbox). There might be a few problems but it should not be too far away.
Thanks!
-- Tom
Regards, Simon
participants (2)
-
Simon Glass
-
Tom Rini