From b2107a4b77458424d60dda05e778319eadcde0ed Mon Sep 17 00:00:00 2001 From: Heinrich Schuchardt Date: Thu, 15 Oct 2020 07:40:57 +0200 Subject: doc: global data pointer on x86, x86_64 On x86 the global data pointer is stored in register fs. On x86_64 no register is used for the global data pointer. Signed-off-by: Heinrich Schuchardt Reviewed-by: Simon Glass --- doc/develop/global_data.rst | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) (limited to 'doc/develop') diff --git a/doc/develop/global_data.rst b/doc/develop/global_data.rst index 9e7c8a24da0..230ebcd8604 100644 --- a/doc/develop/global_data.rst +++ b/doc/develop/global_data.rst @@ -33,8 +33,10 @@ On most architectures the global data pointer is stored in a register. +------------+----------+ | SuperH | r13 | +------------+----------+ +| x86 32bit | fs | ++------------+----------+ -The sandbox, x86, and Xtensa are notable exceptions. +The sandbox, x86_64, and Xtensa are notable exceptions. Clang for ARM does not support assigning a global register. When using Clang gd is defined as an inline function using assembly code. This adds a few bytes -- cgit v1.3.1 From 380c6b94dae83463d8f0d737ec548ba90dabfc8a Mon Sep 17 00:00:00 2001 From: Heinrich Schuchardt Date: Sat, 12 Dec 2020 08:33:28 +0100 Subject: doc: move README.commands to HTML doc Reformat README.commands as reStructured text and add it to the HTML documentation as develop/commands.rst. Signed-off-by: Heinrich Schuchardt Reviewed-by: Simon Glass --- doc/README.commands | 186 -------------------------------------- doc/develop/commands.rst | 226 +++++++++++++++++++++++++++++++++++++++++++++++ doc/develop/index.rst | 1 + 3 files changed, 227 insertions(+), 186 deletions(-) delete mode 100644 doc/README.commands create mode 100644 doc/develop/commands.rst (limited to 'doc/develop') diff --git a/doc/README.commands b/doc/README.commands deleted file mode 100644 index 22ab063fdc0..00000000000 --- a/doc/README.commands +++ /dev/null @@ -1,186 +0,0 @@ -Command definition ------------------- - -Commands are added to U-Boot by creating a new command structure. -This is done by first including command.h, then using the U_BOOT_CMD() or the -U_BOOT_CMD_COMPLETE macro to fill in a struct cmd_tbl struct. - -U_BOOT_CMD(name, maxargs, repeatable, command, "usage", "help") -U_BOOT_CMD_COMPLETE(name, maxargs, repeatable, command, "usage, "help", comp) - -name: The name of the command. THIS IS NOT a string. - -maxargs: The maximum number of arguments this function takes including - the command itself. - -repeatable: Either 0 or 1 to indicate if autorepeat is allowed. - -command: Pointer to the command function. This is the function that is - called when the command is issued. - -usage: Short description. This is a string. - -help: Long description. This is a string. The long description is - only available if CONFIG_SYS_LONGHELP is defined. - -comp: Pointer to the completion function. May be NULL. - This function is called if the user hits the TAB key while - entering the command arguments to complete the entry. Command - completion is only available if CONFIG_AUTO_COMPLETE is defined. - -Sub-command definition ----------------------- - -Likewise an array of struct cmd_tbl holding sub-commands can be created using either -of the following macros: - -* U_BOOT_CMD_MKENT(name, maxargs, repeatable, command, "usage", "help") -* U_BOOT_CMD_MKENTCOMPLETE(name, maxargs, repeatable, command, "usage, "help", - comp) - -This table has to be evaluated in the command function of the main command, e.g. - - static struct cmd_tbl cmd_sub[] = { - U_BOOT_CMD_MKENT(foo, CONFIG_SYS_MAXARGS, 1, do_foo, "", ""), - U_BOOT_CMD_MKENT(bar, CONFIG_SYS_MAXARGS, 1, do_bar, "", ""), - }; - - static int do_cmd(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) - { - struct cmd_tbl *cp; - - if (argc < 2) - return CMD_RET_USAGE; - - /* drop sub-command argument */ - argc--; - argv++; - - cp = find_cmd_tbl(argv[0], cmd_ut_sub, ARRAY_SIZE(cmd_sub)); - - if (cp) - return cp->cmd(cmdtp, flag, argc, argv); - - return CMD_RET_USAGE; - } - -Command function ----------------- - -The command function pointer has to be of type -int (*cmd)(struct cmd_tbl *cmdtp, int flag, int argc, const char *argv[]); - -cmdtp: Table entry describing the command (see above). - -flag: A bitmap which may contain the following bit: - CMD_FLAG_REPEAT - The last command is repeated. - CMD_FLAG_BOOTD - The command is called by the bootd command. - CMD_FLAG_ENV - The command is called by the run command. - -argc: Number of arguments including the command. - -argv: Arguments. - -Allowable return value are: - -CMD_RET_SUCCESS The command was successfully executed. - -CMD_RET_FAILURE The command failed. - -CMD_RET_USAGE The command was called with invalid parameters. This value - leads to the display of the usage string. - -Completion function -------------------- - -The completion function pointer has to be of type -int (*complete)(int argc, char *const argv[], char last_char, - int maxv, char *cmdv[]); - -argc: Number of arguments including the command. - -argv: Arguments. - -last_char: The last character in the command line buffer. - -maxv: Maximum number of possible completions that may be returned by - the function. - -cmdv: Used to return possible values for the last argument. The last - possible completion must be followed by NULL. - -The function returns the number of possible completions (without the terminating -NULL value). - -Behind the scene ----------------- - -The structure created is named with a special prefix and placed by -the linker in a special section using the linker lists mechanism -(see include/linker_lists.h) - -This makes it possible for the final link to extract all commands -compiled into any object code and construct a static array so the -command array can be iterated over using the linker lists macros. - -The linker lists feature ensures that the linker does not discard -these symbols when linking full U-Boot even though they are not -referenced in the source code as such. - -If a new board is defined do not forget to define the command section -by writing in u-boot.lds ($(srctree)/board/boardname/u-boot.lds) these -3 lines: - - .u_boot_list : { - KEEP(*(SORT(.u_boot_list*))); - } - -Writing tests -------------- - -All new commands should have tests. Tests for existing commands are very -welcome. - -It is fairly easy to write a test for a command. Enable it in sandbox, and -then add code that runs the command and checks the output. - -Here is an example: - -/* Test 'acpi items' command */ -static int dm_test_acpi_cmd_items(struct unit_test_state *uts) -{ - struct acpi_ctx ctx; - void *buf; - - buf = malloc(BUF_SIZE); - ut_assertnonnull(buf); - - ctx.current = buf; - ut_assertok(acpi_fill_ssdt(&ctx)); - console_record_reset(); - run_command("acpi items", 0); - ut_assert_nextline("dev 'acpi-test', type 1, size 2"); - ut_assert_nextline("dev 'acpi-test2', type 1, size 2"); - ut_assert_console_end(); - - ctx.current = buf; - ut_assertok(acpi_inject_dsdt(&ctx)); - console_record_reset(); - run_command("acpi items", 0); - ut_assert_nextline("dev 'acpi-test', type 2, size 2"); - ut_assert_nextline("dev 'acpi-test2', type 2, size 2"); - ut_assert_console_end(); - - console_record_reset(); - run_command("acpi items -d", 0); - ut_assert_nextline("dev 'acpi-test', type 2, size 2"); - ut_assert_nextlines_are_dump(2); - ut_assert_nextline("%s", ""); - ut_assert_nextline("dev 'acpi-test2', type 2, size 2"); - ut_assert_nextlines_are_dump(2); - ut_assert_nextline("%s", ""); - ut_assert_console_end(); - - return 0; -} -DM_TEST(dm_test_acpi_cmd_items, UT_TESTF_SCAN_PDATA | UT_TESTF_SCAN_FDT); diff --git a/doc/develop/commands.rst b/doc/develop/commands.rst new file mode 100644 index 00000000000..c72d1b0aaad --- /dev/null +++ b/doc/develop/commands.rst @@ -0,0 +1,226 @@ +.. SPDX-License-Identifier: GPL-2.0+ + +Implementing shell commands +=========================== + +Command definition +------------------ + +Commands are added to U-Boot by creating a new command structure. +This is done by first including command.h, then using the U_BOOT_CMD() or the +U_BOOT_CMD_COMPLETE macro to fill in a struct cmd_tbl structure. + +.. code-block:: c + + U_BOOT_CMD(name, maxargs, repeatable, command, "usage", "help") + U_BOOT_CMD_COMPLETE(name, maxargs, repeatable, command, "usage, "help", comp) + +name + The name of the command. This is **not** a string. + +maxargs + The maximum number of arguments this function takes including + the command itself. + +repeatable + Either 0 or 1 to indicate if autorepeat is allowed. + +command + Pointer to the command function. This is the function that is + called when the command is issued. + +usage + Short description. This is a string. + +help + Long description. This is a string. The long description is + only available if CONFIG_SYS_LONGHELP is defined. + +comp + Pointer to the completion function. May be NULL. + This function is called if the user hits the TAB key while + entering the command arguments to complete the entry. Command + completion is only available if CONFIG_AUTO_COMPLETE is defined. + +Sub-command definition +---------------------- + +Likewise an array of struct cmd_tbl holding sub-commands can be created using +either of the following macros: + +.. code-block:: c + + U_BOOT_CMD_MKENT(name, maxargs, repeatable, command, "usage", "help") + U_BOOT_CMD_MKENTCOMPLETE(name, maxargs, repeatable, command, "usage, "help", comp) + +This table has to be evaluated in the command function of the main command, e.g. + +.. code-block:: c + + static struct cmd_tbl cmd_sub[] = { + U_BOOT_CMD_MKENT(foo, CONFIG_SYS_MAXARGS, 1, do_foo, "", ""), + U_BOOT_CMD_MKENT(bar, CONFIG_SYS_MAXARGS, 1, do_bar, "", ""), + }; + + static int do_cmd(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) + { + struct cmd_tbl *cp; + + if (argc < 2) + return CMD_RET_USAGE; + + /* drop sub-command argument */ + argc--; + argv++; + + cp = find_cmd_tbl(argv[0], cmd_ut_sub, ARRAY_SIZE(cmd_sub)); + + if (cp) + return cp->cmd(cmdtp, flag, argc, argv); + + return CMD_RET_USAGE; + } + +Command function +---------------- + +The command function pointer has to be of type + +.. code-block:: c + + int (*cmd)(struct cmd_tbl *cmdtp, int flag, int argc, const char *argv[]); + +cmdtp + Table entry describing the command (see above). + +flag + A bitmap which may contain the following bits + + * CMD_FLAG_REPEAT - The last command is repeated. + * CMD_FLAG_BOOTD - The command is called by the bootd command. + * CMD_FLAG_ENV - The command is called by the run command. + +argc + Number of arguments including the command. + +argv + Arguments. + +Allowable return value are: + +CMD_RET_SUCCESS + The command was successfully executed. + +CMD_RET_FAILURE + The command failed. + +CMD_RET_USAGE + The command was called with invalid parameters. This value + leads to the display of the usage string. + +Completion function +------------------- + +The completion function pointer has to be of type + +.. code-block:: c + + int (*complete)(int argc, char *const argv[], char last_char, + int maxv, char *cmdv[]); + +argc + Number of arguments including the command. + +argv + Arguments. + +last_char + The last character in the command line buffer. + +maxv + Maximum number of possible completions that may be returned by + the function. + +cmdv + Used to return possible values for the last argument. The last + possible completion must be followed by NULL. + +The function returns the number of possible completions (without the terminating +NULL value). + +Behind the scene +---------------- + +The structure created is named with a special prefix and placed by +the linker in a special section using the linker lists mechanism +(see include/linker_lists.h) + +This makes it possible for the final link to extract all commands +compiled into any object code and construct a static array so the +command array can be iterated over using the linker lists macros. + +The linker lists feature ensures that the linker does not discard +these symbols when linking full U-Boot even though they are not +referenced in the source code as such. + +If a new board is defined do not forget to define the command section +by writing in u-boot.lds ($(srctree)/board/boardname/u-boot.lds) these +3 lines: + +.. code-block:: c + + .u_boot_list : { + KEEP(*(SORT(.u_boot_list*))); + } + +Writing tests +------------- + +All new commands should have tests. Tests for existing commands are very +welcome. + +It is fairly easy to write a test for a command. Enable it in sandbox, and +then add code that runs the command and checks the output. + +Here is an example: + +.. code-block:: c + + /* Test 'acpi items' command */ + static int dm_test_acpi_cmd_items(struct unit_test_state *uts) + { + struct acpi_ctx ctx; + void *buf; + + buf = malloc(BUF_SIZE); + ut_assertnonnull(buf); + + ctx.current = buf; + ut_assertok(acpi_fill_ssdt(&ctx)); + console_record_reset(); + run_command("acpi items", 0); + ut_assert_nextline("dev 'acpi-test', type 1, size 2"); + ut_assert_nextline("dev 'acpi-test2', type 1, size 2"); + ut_assert_console_end(); + + ctx.current = buf; + ut_assertok(acpi_inject_dsdt(&ctx)); + console_record_reset(); + run_command("acpi items", 0); + ut_assert_nextline("dev 'acpi-test', type 2, size 2"); + ut_assert_nextline("dev 'acpi-test2', type 2, size 2"); + ut_assert_console_end(); + + console_record_reset(); + run_command("acpi items -d", 0); + ut_assert_nextline("dev 'acpi-test', type 2, size 2"); + ut_assert_nextlines_are_dump(2); + ut_assert_nextline("%s", ""); + ut_assert_nextline("dev 'acpi-test2', type 2, size 2"); + ut_assert_nextlines_are_dump(2); + ut_assert_nextline("%s", ""); + ut_assert_console_end(); + + return 0; + } + DM_TEST(dm_test_acpi_cmd_items, UT_TESTF_SCAN_PDATA | UT_TESTF_SCAN_FDT); diff --git a/doc/develop/index.rst b/doc/develop/index.rst index 89e80eab945..c95a8d6b123 100644 --- a/doc/develop/index.rst +++ b/doc/develop/index.rst @@ -8,6 +8,7 @@ Develop U-Boot :maxdepth: 2 coccinelle + commands crash_dumps global_data logging -- cgit v1.3.1 From dce26c7d56ed26ba07e1da245c84690ec1edcf65 Mon Sep 17 00:00:00 2001 From: Heinrich Schuchardt Date: Sat, 12 Dec 2020 10:14:22 +0100 Subject: doc: move README.trace to HTML documentation Convert README.trace to reStructured text and move it to develop/trace.rst. Signed-off-by: Heinrich Schuchardt Reviewed-by: Simon Glass --- doc/README.trace | 346 ------------------------------------------------ doc/develop/index.rst | 1 + doc/develop/trace.rst | 355 ++++++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 356 insertions(+), 346 deletions(-) delete mode 100644 doc/README.trace create mode 100644 doc/develop/trace.rst (limited to 'doc/develop') diff --git a/doc/README.trace b/doc/README.trace deleted file mode 100644 index 2e7ca3319a9..00000000000 --- a/doc/README.trace +++ /dev/null @@ -1,346 +0,0 @@ -# SPDX-License-Identifier: GPL-2.0+ -# -# Copyright (c) 2013 The Chromium OS Authors. - -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 -=>host 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 [ ] - Dump a list of functions into the buffer - -- calls [ ] - 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 - Specify U-Boot map file - - -p - 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 -April 2013 diff --git a/doc/develop/index.rst b/doc/develop/index.rst index c95a8d6b123..0a7e204b343 100644 --- a/doc/develop/index.rst +++ b/doc/develop/index.rst @@ -12,3 +12,4 @@ Develop U-Boot crash_dumps global_data logging + trace diff --git a/doc/develop/trace.rst b/doc/develop/trace.rst new file mode 100644 index 00000000000..7776c484286 --- /dev/null +++ b/doc/develop/trace.rst @@ -0,0 +1,355 @@ +.. SPDX-License-Identifier: GPL-2.0+ +.. Copyright (c) 2013 The Chromium OS Authors. + +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) + +.. code-block:: c + + #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: + +.. code-block:: console + + $ 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: + +.. code-block:: console + + $ ./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 + =>host 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 + +.. code-block:: console + + $ ./sandbox/tools/proftool -m sandbox/System.map -p trace dump-ftrace >trace.txt + +Finally run pytimechart to display it + +.. code-block:: console + + $ 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 [ ] + Dump a list of functions into the buffer + +calls [ ] + 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 + Specify U-Boot map file + +-p + 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 +April 2013 -- cgit v1.3.1