diff options
Diffstat (limited to 'test')
| -rw-r--r-- | test/boot/bootdev.c | 29 | ||||
| -rw-r--r-- | test/boot/bootstd_common.h | 2 | ||||
| -rw-r--r-- | test/cmd/Makefile | 1 | ||||
| -rw-r--r-- | test/cmd/seama.c | 71 | ||||
| -rw-r--r-- | test/cmd_ut.c | 6 | ||||
| -rw-r--r-- | test/dm/button.c | 13 | ||||
| -rw-r--r-- | test/dm/ofnode.c | 2 | ||||
| -rw-r--r-- | test/dm/test-fdt.c | 36 | ||||
| -rw-r--r-- | test/lib/lmb.c | 44 | ||||
| -rw-r--r-- | test/py/tests/test_trace.py | 304 |
10 files changed, 477 insertions, 31 deletions
diff --git a/test/boot/bootdev.c b/test/boot/bootdev.c index ef5215bbcec..e1eb8ccd9a7 100644 --- a/test/boot/bootdev.c +++ b/test/boot/bootdev.c @@ -18,7 +18,11 @@ #include "bootstd_common.h" /* Allow reseting the USB-started flag */ +#if defined(CONFIG_USB_HOST) || defined(CONFIG_USB_GADGET) extern char usb_started; +#else +char usb_started; +#endif /* Check 'bootdev list' command */ static int bootdev_test_cmd_list(struct unit_test_state *uts) @@ -316,11 +320,12 @@ static int bootdev_test_hunter(struct unit_test_state *uts) ut_assert_nextline(" 5 ide ide_bootdev"); ut_assert_nextline(" 2 mmc mmc_bootdev"); ut_assert_nextline(" 4 nvme nvme_bootdev"); + ut_assert_nextline(" 4 qfw qfw_bootdev"); ut_assert_nextline(" 4 scsi scsi_bootdev"); ut_assert_nextline(" 4 spi_flash sf_bootdev"); ut_assert_nextline(" 5 usb usb_bootdev"); ut_assert_nextline(" 4 virtio virtio_bootdev"); - ut_assert_nextline("(total hunters: 9)"); + ut_assert_nextline("(total hunters: 10)"); ut_assert_console_end(); ut_assertok(bootdev_hunt("usb1", false)); @@ -328,8 +333,8 @@ static int bootdev_test_hunter(struct unit_test_state *uts) "Bus usb@1: scanning bus usb@1 for devices... 5 USB Device(s) found"); ut_assert_console_end(); - /* USB is sixth in the list, so bit 7 */ - ut_asserteq(BIT(7), std->hunters_used); + /* USB is 7th in the list, so bit 8 */ + ut_asserteq(BIT(8), std->hunters_used); return 0; } @@ -350,7 +355,7 @@ static int bootdev_test_cmd_hunt(struct unit_test_state *uts) ut_assert_nextline("Prio Used Uclass Hunter"); ut_assert_nextlinen("----"); ut_assert_nextline(" 6 ethernet eth_bootdev"); - ut_assert_skip_to_line("(total hunters: 9)"); + ut_assert_skip_to_line("(total hunters: 10)"); ut_assert_console_end(); /* Use the MMC hunter and see that it updates */ @@ -358,7 +363,7 @@ static int bootdev_test_cmd_hunt(struct unit_test_state *uts) ut_assertok(run_command("bootdev hunt -l", 0)); ut_assert_skip_to_line(" 5 ide ide_bootdev"); ut_assert_nextline(" 2 * mmc mmc_bootdev"); - ut_assert_skip_to_line("(total hunters: 9)"); + ut_assert_skip_to_line("(total hunters: 10)"); ut_assert_console_end(); /* Scan all hunters */ @@ -376,6 +381,7 @@ static int bootdev_test_cmd_hunt(struct unit_test_state *uts) /* mmc hunter has already been used so should not run again */ ut_assert_nextline("Hunting with: nvme"); + ut_assert_nextline("Hunting with: qfw"); ut_assert_nextline("Hunting with: scsi"); ut_assert_nextline("scanning bus for devices..."); ut_assert_skip_to_line("Hunting with: spi_flash"); @@ -394,11 +400,12 @@ static int bootdev_test_cmd_hunt(struct unit_test_state *uts) ut_assert_nextline(" 5 * ide ide_bootdev"); ut_assert_nextline(" 2 * mmc mmc_bootdev"); ut_assert_nextline(" 4 * nvme nvme_bootdev"); + ut_assert_nextline(" 4 * qfw qfw_bootdev"); ut_assert_nextline(" 4 * scsi scsi_bootdev"); ut_assert_nextline(" 4 * spi_flash sf_bootdev"); ut_assert_nextline(" 5 * usb usb_bootdev"); ut_assert_nextline(" 4 * virtio virtio_bootdev"); - ut_assert_nextline("(total hunters: 9)"); + ut_assert_nextline("(total hunters: 10)"); ut_assert_console_end(); ut_asserteq(GENMASK(MAX_HUNTER, 0), std->hunters_used); @@ -585,8 +592,8 @@ static int bootdev_test_next_label(struct unit_test_state *uts) ut_asserteq_str("scsi.id0lun0.bootdev", dev->name); ut_asserteq(BOOTFLOW_METHF_SINGLE_UCLASS, mflags); - /* SCSI is sixth in the list, so bit 5 */ - ut_asserteq(BIT(MMC_HUNTER) | BIT(5), std->hunters_used); + /* SCSI is 7th in the list, so bit 6 */ + ut_asserteq(BIT(MMC_HUNTER) | BIT(6), std->hunters_used); ut_assertok(bootdev_next_label(&iter, &dev, &mflags)); ut_assert_console_end(); @@ -596,7 +603,7 @@ static int bootdev_test_next_label(struct unit_test_state *uts) mflags); /* dhcp: Ethernet is first so bit 0 */ - ut_asserteq(BIT(MMC_HUNTER) | BIT(5) | BIT(0), std->hunters_used); + ut_asserteq(BIT(MMC_HUNTER) | BIT(6) | BIT(0), std->hunters_used); ut_assertok(bootdev_next_label(&iter, &dev, &mflags)); ut_assert_console_end(); @@ -606,7 +613,7 @@ static int bootdev_test_next_label(struct unit_test_state *uts) mflags); /* pxe: Ethernet is first so bit 0 */ - ut_asserteq(BIT(MMC_HUNTER) | BIT(5) | BIT(0), std->hunters_used); + ut_asserteq(BIT(MMC_HUNTER) | BIT(6) | BIT(0), std->hunters_used); mflags = 123; ut_asserteq(-ENODEV, bootdev_next_label(&iter, &dev, &mflags)); @@ -614,7 +621,7 @@ static int bootdev_test_next_label(struct unit_test_state *uts) ut_assert_console_end(); /* no change */ - ut_asserteq(BIT(MMC_HUNTER) | BIT(5) | BIT(0), std->hunters_used); + ut_asserteq(BIT(MMC_HUNTER) | BIT(6) | BIT(0), std->hunters_used); return 0; } diff --git a/test/boot/bootstd_common.h b/test/boot/bootstd_common.h index 136a79b5178..4a126e43ff4 100644 --- a/test/boot/bootstd_common.h +++ b/test/boot/bootstd_common.h @@ -21,7 +21,7 @@ #define TEST_VERNUM 0x00010002 enum { - MAX_HUNTER = 8, + MAX_HUNTER = 9, MMC_HUNTER = 3, /* ID of MMC hunter */ }; diff --git a/test/cmd/Makefile b/test/cmd/Makefile index 09e410ec30e..2ffde8703ab 100644 --- a/test/cmd/Makefile +++ b/test/cmd/Makefile @@ -16,6 +16,7 @@ obj-$(CONFIG_CMD_LOADM) += loadm.o obj-$(CONFIG_CMD_MEM_SEARCH) += mem_search.o obj-$(CONFIG_CMD_PINMUX) += pinmux.o obj-$(CONFIG_CMD_PWM) += pwm.o +obj-$(CONFIG_CMD_SEAMA) += seama.o ifdef CONFIG_SANDBOX obj-$(CONFIG_CMD_SETEXPR) += setexpr.o endif diff --git a/test/cmd/seama.c b/test/cmd/seama.c new file mode 100644 index 00000000000..b1b56930c64 --- /dev/null +++ b/test/cmd/seama.c @@ -0,0 +1,71 @@ +// SPDX-License-Identifier: GPL-2.0+ +/* + * Executes tests for SEAMA (SEAttle iMAge) command + * + * Copyright (C) 2021 Linus Walleij <linus.walleij@linaro.org> + */ + +#include <common.h> +#include <command.h> +#include <dm.h> +#include <test/suites.h> +#include <test/test.h> +#include <test/ut.h> + +#define SEAMA_TEST(_name, _flags) UNIT_TEST(_name, _flags, seama_test) + +static int seama_test_noargs(struct unit_test_state *uts) +{ + /* Test that 'seama' with no arguments fails gracefully */ + console_record_reset(); + run_command("seama", 0); + ut_assert_nextlinen("seama - Load the SEAMA image and sets envs"); + ut_assert_skipline(); + ut_assert_skipline(); + ut_assert_skipline(); + ut_assert_skipline(); + ut_assert_console_end(); + return 0; +} +SEAMA_TEST(seama_test_noargs, UT_TESTF_CONSOLE_REC); + +static int seama_test_addr(struct unit_test_state *uts) +{ + /* Test that loads SEAMA image 0 to address 0x01000000 */ + console_record_reset(); + run_command("seama 0x01000000", 0); + ut_assert_nextlinen("Loading SEAMA image 0 from nand0"); + ut_assert_nextlinen("SEMA IMAGE:"); + ut_assert_nextlinen(" metadata size "); + ut_assert_nextlinen(" image size "); + ut_assert_nextlinen(" checksum "); + ut_assert_nextlinen("Decoding SEAMA image 0x01000040.."); + ut_assert_console_end(); + return 0; +} +SEAMA_TEST(seama_test_addr, UT_TESTF_CONSOLE_REC); + +static int seama_test_index(struct unit_test_state *uts) +{ + /* Test that loads SEAMA image 0 exlicitly specified */ + console_record_reset(); + run_command("seama 0x01000000 0", 0); + ut_assert_nextlinen("Loading SEAMA image 0 from nand0"); + ut_assert_nextlinen("SEMA IMAGE:"); + ut_assert_nextlinen(" metadata size "); + ut_assert_nextlinen(" image size "); + ut_assert_nextlinen(" checksum "); + ut_assert_nextlinen("Decoding SEAMA image 0x01000040.."); + ut_assert_console_end(); + return 0; +} +SEAMA_TEST(seama_test_index, UT_TESTF_CONSOLE_REC); + +int do_ut_seama(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) +{ + struct unit_test *tests = UNIT_TEST_SUITE_START(seama_test); + const int n_ents = UNIT_TEST_SUITE_COUNT(seama_test); + + return cmd_ut_category("seama", "seama_test_", tests, n_ents, argc, + argv); +} diff --git a/test/cmd_ut.c b/test/cmd_ut.c index 1713d0d1c85..409c22bfd24 100644 --- a/test/cmd_ut.c +++ b/test/cmd_ut.c @@ -110,6 +110,9 @@ static struct cmd_tbl cmd_ut_sub[] = { #ifdef CONFIG_CMD_LOADM U_BOOT_CMD_MKENT(loadm, CONFIG_SYS_MAXARGS, 1, do_ut_loadm, "", ""), #endif +#ifdef CONFIG_CMD_SEAMA + U_BOOT_CMD_MKENT(seama, CONFIG_SYS_MAXARGS, 1, do_ut_seama, "", ""), +#endif }; static int do_ut_all(struct cmd_tbl *cmdtp, int flag, int argc, @@ -212,6 +215,9 @@ static char ut_help_text[] = #ifdef CONFIG_SANDBOX "\nstr - basic test of string functions" #endif +#ifdef CONFIG_CMD_SEAMA + "\nseama - seama command parameters loading and decoding" +#endif #ifdef CONFIG_UT_TIME "\ntime - very basic test of time functions" #endif diff --git a/test/dm/button.c b/test/dm/button.c index e76c1ad030a..3318668df25 100644 --- a/test/dm/button.c +++ b/test/dm/button.c @@ -13,6 +13,7 @@ #include <power/sandbox_pmic.h> #include <asm/gpio.h> #include <dm/test.h> +#include <dt-bindings/input/input.h> #include <test/ut.h> /* Base test of the button uclass */ @@ -85,6 +86,18 @@ static int dm_test_button_label(struct unit_test_state *uts) } DM_TEST(dm_test_button_label, UT_TESTF_SCAN_PDATA | UT_TESTF_SCAN_FDT); +/* Test button has linux,code */ +static int dm_test_button_linux_code(struct unit_test_state *uts) +{ + struct udevice *dev; + + ut_assertok(uclass_get_device(UCLASS_BUTTON, 1, &dev)); + ut_asserteq(BTN_1, button_get_code(dev)); + + return 0; +} +DM_TEST(dm_test_button_linux_code, UT_TESTF_SCAN_PDATA | UT_TESTF_SCAN_FDT); + /* Test adc-keys driver */ static int dm_test_button_keys_adc(struct unit_test_state *uts) { diff --git a/test/dm/ofnode.c b/test/dm/ofnode.c index 8077affabb7..473a8cef578 100644 --- a/test/dm/ofnode.c +++ b/test/dm/ofnode.c @@ -1046,7 +1046,7 @@ static int dm_test_ofnode_for_each_prop(struct unit_test_state *uts) struct ofprop prop; int count; - node = ofnode_path("/buttons"); + node = ofnode_path("/ofnode-foreach"); count = 0; /* we expect "compatible" for each node */ diff --git a/test/dm/test-fdt.c b/test/dm/test-fdt.c index 7cd2d046122..1d2af94f568 100644 --- a/test/dm/test-fdt.c +++ b/test/dm/test-fdt.c @@ -12,6 +12,7 @@ #include <asm/global_data.h> #include <asm/io.h> #include <dm/test.h> +#include <dm/read.h> #include <dm/root.h> #include <dm/device-internal.h> #include <dm/devres.h> @@ -1157,6 +1158,41 @@ static int dm_test_decode_display_timing(struct unit_test_state *uts) } DM_TEST(dm_test_decode_display_timing, UT_TESTF_SCAN_PDATA | UT_TESTF_SCAN_FDT); +/* Test dev_decode_panel_timing() */ +static int dm_test_decode_panel_timing(struct unit_test_state *uts) +{ + struct udevice *dev; + struct display_timing timing; + + ut_assertok(uclass_first_device_err(UCLASS_TEST_FDT, &dev)); + ut_asserteq_str("a-test", dev->name); + + ut_assertok(dev_decode_panel_timing(dev, &timing)); + ut_assert(timing.hactive.typ == 240); + ut_assert(timing.hback_porch.typ == 7); + ut_assert(timing.hfront_porch.typ == 6); + ut_assert(timing.hsync_len.typ == 1); + ut_assert(timing.vactive.typ == 320); + ut_assert(timing.vback_porch.typ == 5); + ut_assert(timing.vfront_porch.typ == 8); + ut_assert(timing.vsync_len.typ == 2); + ut_assert(timing.pixelclock.typ == 6500000); + ut_assert(timing.flags & DISPLAY_FLAGS_HSYNC_HIGH); + ut_assert(!(timing.flags & DISPLAY_FLAGS_HSYNC_LOW)); + ut_assert(!(timing.flags & DISPLAY_FLAGS_VSYNC_HIGH)); + ut_assert(timing.flags & DISPLAY_FLAGS_VSYNC_LOW); + ut_assert(timing.flags & DISPLAY_FLAGS_DE_HIGH); + ut_assert(!(timing.flags & DISPLAY_FLAGS_DE_LOW)); + ut_assert(timing.flags & DISPLAY_FLAGS_PIXDATA_POSEDGE); + ut_assert(!(timing.flags & DISPLAY_FLAGS_PIXDATA_NEGEDGE)); + ut_assert(timing.flags & DISPLAY_FLAGS_INTERLACED); + ut_assert(timing.flags & DISPLAY_FLAGS_DOUBLESCAN); + ut_assert(timing.flags & DISPLAY_FLAGS_DOUBLECLK); + + return 0; +} +DM_TEST(dm_test_decode_panel_timing, UT_TESTF_SCAN_PDATA | UT_TESTF_SCAN_FDT); + /* Test read_resourcee() */ static int dm_test_read_resource(struct unit_test_state *uts) { diff --git a/test/lib/lmb.c b/test/lib/lmb.c index 157c26394d6..16288750358 100644 --- a/test/lib/lmb.c +++ b/test/lib/lmb.c @@ -665,10 +665,17 @@ static int lib_test_lmb_get_free_size(struct unit_test_state *uts) DM_TEST(lib_test_lmb_get_free_size, UT_TESTF_SCAN_PDATA | UT_TESTF_SCAN_FDT); +#ifdef CONFIG_LMB_USE_MAX_REGIONS static int lib_test_lmb_max_regions(struct unit_test_state *uts) { const phys_addr_t ram = 0x00000000; - const phys_size_t ram_size = 0x8000000; + /* + * All of 32bit memory space will contain regions for this test, so + * we need to scale ram_size (which in this case is the size of the lmb + * region) to match. + */ + const phys_size_t ram_size = ((0xFFFFFFFF >> CONFIG_LMB_MAX_REGIONS) + + 1) * CONFIG_LMB_MAX_REGIONS; const phys_size_t blk_size = 0x10000; phys_addr_t offset; struct lmb lmb; @@ -677,54 +684,55 @@ static int lib_test_lmb_max_regions(struct unit_test_state *uts) lmb_init(&lmb); ut_asserteq(lmb.memory.cnt, 0); - ut_asserteq(lmb.memory.max, 8); + ut_asserteq(lmb.memory.max, CONFIG_LMB_MAX_REGIONS); ut_asserteq(lmb.reserved.cnt, 0); - ut_asserteq(lmb.reserved.max, 8); + ut_asserteq(lmb.reserved.max, CONFIG_LMB_MAX_REGIONS); - /* Add 8 memory regions */ - for (i = 0; i < 8; i++) { + /* Add CONFIG_LMB_MAX_REGIONS memory regions */ + for (i = 0; i < CONFIG_LMB_MAX_REGIONS; i++) { offset = ram + 2 * i * ram_size; ret = lmb_add(&lmb, offset, ram_size); ut_asserteq(ret, 0); } - ut_asserteq(lmb.memory.cnt, 8); + ut_asserteq(lmb.memory.cnt, CONFIG_LMB_MAX_REGIONS); ut_asserteq(lmb.reserved.cnt, 0); - /* error for the 9th memory regions */ - offset = ram + 2 * 8 * ram_size; + /* error for the (CONFIG_LMB_MAX_REGIONS + 1) memory regions */ + offset = ram + 2 * (CONFIG_LMB_MAX_REGIONS + 1) * ram_size; ret = lmb_add(&lmb, offset, ram_size); ut_asserteq(ret, -1); - ut_asserteq(lmb.memory.cnt, 8); + ut_asserteq(lmb.memory.cnt, CONFIG_LMB_MAX_REGIONS); ut_asserteq(lmb.reserved.cnt, 0); - /* reserve 8 regions */ - for (i = 0; i < 8; i++) { + /* reserve CONFIG_LMB_MAX_REGIONS regions */ + for (i = 0; i < CONFIG_LMB_MAX_REGIONS; i++) { offset = ram + 2 * i * blk_size; ret = lmb_reserve(&lmb, offset, blk_size); ut_asserteq(ret, 0); } - ut_asserteq(lmb.memory.cnt, 8); - ut_asserteq(lmb.reserved.cnt, 8); + ut_asserteq(lmb.memory.cnt, CONFIG_LMB_MAX_REGIONS); + ut_asserteq(lmb.reserved.cnt, CONFIG_LMB_MAX_REGIONS); /* error for the 9th reserved blocks */ - offset = ram + 2 * 8 * blk_size; + offset = ram + 2 * (CONFIG_LMB_MAX_REGIONS + 1) * blk_size; ret = lmb_reserve(&lmb, offset, blk_size); ut_asserteq(ret, -1); - ut_asserteq(lmb.memory.cnt, 8); - ut_asserteq(lmb.reserved.cnt, 8); + ut_asserteq(lmb.memory.cnt, CONFIG_LMB_MAX_REGIONS); + ut_asserteq(lmb.reserved.cnt, CONFIG_LMB_MAX_REGIONS); /* check each regions */ - for (i = 0; i < 8; i++) + for (i = 0; i < CONFIG_LMB_MAX_REGIONS; i++) ut_asserteq(lmb.memory.region[i].base, ram + 2 * i * ram_size); - for (i = 0; i < 8; i++) + for (i = 0; i < CONFIG_LMB_MAX_REGIONS; i++) ut_asserteq(lmb.reserved.region[i].base, ram + 2 * i * blk_size); return 0; } +#endif DM_TEST(lib_test_lmb_max_regions, UT_TESTF_SCAN_PDATA | UT_TESTF_SCAN_FDT); diff --git a/test/py/tests/test_trace.py b/test/py/tests/test_trace.py new file mode 100644 index 00000000000..14584d11a23 --- /dev/null +++ b/test/py/tests/test_trace.py @@ -0,0 +1,304 @@ +# SPDX-License-Identifier: GPL-2.0 +# Copyright 2022 Google LLC +# Written by Simon Glass <sjg@chromium.org> + +import os +import pytest +import re + +import u_boot_utils as util + +# This is needed for Azure, since the default '..' directory is not writeable +TMPDIR = '/tmp/test_trace' + +# Decode a function-graph line +RE_LINE = re.compile(r'.*\[000\]\s*([0-9.]*): func.*[|](\s*)(\S.*)?([{};])$') + + +def collect_trace(cons): + """Build U-Boot and run it to collect a trace + + Args: + cons (ConsoleBase): U-Boot console + + Returns: + tuple: + str: Filename of the output trace file + int: Microseconds taken for initf_dm according to bootstage + """ + cons.run_command('trace pause') + out = cons.run_command('trace stats') + + # The output is something like this: + # 251,003 function sites + # 1,160,283 function calls + # 0 untracked function calls + # 1,230,758 traced function calls (341538 dropped due to overflow) + # 33 maximum observed call depth + # 15 call depth limit + # 748,268 calls not traced due to depth + # 1,230,758 max function calls + + # Get a dict of values from the output + lines = [line.split(maxsplit=1) for line in out.splitlines() if line] + vals = {key: val.replace(',', '') for val, key in lines} + + assert int(vals['function sites']) > 100000 + assert int(vals['function calls']) > 200000 + assert int(vals['untracked function calls']) == 0 + assert int(vals['maximum observed call depth']) > 30 + assert (vals['call depth limit'] == + cons.config.buildconfig.get('config_trace_call_depth_limit')) + assert int(vals['calls not traced due to depth']) > 100000 + + out = cons.run_command('bootstage report') + # Accumulated time: + # 19,104 dm_r + # 23,078 of_live + # 46,280 dm_f + dm_f_time = [line.split()[0] for line in out.replace(',', '').splitlines() + if 'dm_f' in line] + + # Read out the trace data + addr = 0x02000000 + size = 0x01000000 + out = cons.run_command(f'trace calls {addr:x} {size:x}') + print(out) + fname = os.path.join(TMPDIR, 'trace') + out = cons.run_command( + 'host save hostfs - %x %s ${profoffset}' % (addr, fname)) + return fname, int(dm_f_time[0]) + + +def check_function(cons, fname, proftool, map_fname, trace_dat): + """Check that the 'function' output works + + Args: + cons (ConsoleBase): U-Boot console + fname (str): Filename of trace file + proftool (str): Filename of proftool + map_fname (str): Filename of System.map + trace_dat (str): Filename of output file + """ + out = util.run_and_log( + cons, [proftool, '-t', fname, '-o', trace_dat, '-m', map_fname, + 'dump-ftrace']) + + # Check that trace-cmd can read it + out = util.run_and_log(cons, ['trace-cmd', 'dump', trace_dat]) + + # Tracing meta data in file /tmp/test_trace/trace.dat: + # [Initial format] + # 6 [Version] + # 0 [Little endian] + # 4 [Bytes in a long] + # 4096 [Page size, bytes] + # [Header page, 205 bytes] + # [Header event, 205 bytes] + # [Ftrace format, 3 events] + # [Events format, 0 systems] + # [Kallsyms, 342244 bytes] + # [Trace printk, 0 bytes] + # [Saved command lines, 9 bytes] + # 1 [CPUs with tracing data] + # [6 options] + # [Flyrecord tracing data] + # [Tracing clock] + # [local] global counter uptime perf mono mono_raw boot x86-tsc + assert '[Flyrecord tracing data]' in out + assert '4096 [Page size, bytes]' in out + kallsyms = [line.split() for line in out.splitlines() if 'Kallsyms' in line] + # [['[Kallsyms,', '342244', 'bytes]']] + val = int(kallsyms[0][1]) + assert val > 50000 # Should be at least 50KB of symbols + + # Check that the trace has something useful + cmd = f"trace-cmd report {trace_dat} |grep -E '(initf_|initr_)'" + out = util.run_and_log(cons, ['sh', '-c', cmd]) + + # Format: + # unknown option 14 + # u-boot-1 [000] 60.805596: function: initf_malloc + # u-boot-1 [000] 60.805597: function: initf_malloc + # u-boot-1 [000] 60.805601: function: initf_bootstage + # u-boot-1 [000] 60.805607: function: initf_bootstage + lines = [line.replace(':', '').split() for line in out.splitlines()] + vals = {items[4]: float(items[2]) for items in lines if len(items) == 5} + base = None + max_delta = 0 + for timestamp in vals.values(): + if base: + max_delta = max(max_delta, timestamp - base) + else: + base = timestamp + + # Check for some expected functions + assert 'initf_malloc' in vals.keys() + assert 'initr_watchdog' in vals.keys() + assert 'initr_dm' in vals.keys() + + # All the functions should be executed within five seconds at most + assert max_delta < 5 + + +def check_funcgraph(cons, fname, proftool, map_fname, trace_dat): + """Check that the 'funcgraph' output works + + Args: + cons (ConsoleBase): U-Boot console + fname (str): Filename of trace file + proftool (str): Filename of proftool + map_fname (str): Filename of System.map + trace_dat (str): Filename of output file + + Returns: + int: Time taken by the first part of the initf_dm() function, in us + """ + + # Generate the funcgraph format + out = util.run_and_log( + cons, [proftool, '-t', fname, '-o', trace_dat, '-m', map_fname, + 'dump-ftrace', '-f', 'funcgraph']) + + # Check that the trace has what we expect + cmd = f'trace-cmd report {trace_dat} |head -n 70' + out = util.run_and_log(cons, ['sh', '-c', cmd]) + + # First look for this: + # u-boot-1 [000] 282.101360: funcgraph_entry: 0.004 us | initf_malloc(); + # ... + # u-boot-1 [000] 282.101369: funcgraph_entry: | initf_bootstage() { + # u-boot-1 [000] 282.101369: funcgraph_entry: | bootstage_init() { + # u-boot-1 [000] 282.101369: funcgraph_entry: | dlmalloc() { + # ... + # u-boot-1 [000] 282.101375: funcgraph_exit: 0.001 us | } + # Then look for this: + # u-boot-1 [000] 282.101375: funcgraph_exit: 0.006 us | } + # Then check for this: + # u-boot-1 [000] 282.101375: funcgraph_entry: 0.000 us | event_init(); + + expected_indent = None + found_start = False + found_end = False + upto = None + + # Look for initf_bootstage() entry and make sure we see the exit + # Collect the time for initf_dm() + for line in out.splitlines(): + m = RE_LINE.match(line) + if m: + timestamp, indent, func, brace = m.groups() + if found_end: + upto = func + break + elif func == 'initf_bootstage() ': + found_start = True + expected_indent = indent + ' ' + elif found_start and indent == expected_indent and brace == '}': + found_end = True + + # The next function after initf_bootstage() exits should be event_init() + assert upto == 'event_init()' + + # Now look for initf_dm() and dm_timer_init() so we can check the bootstage + # time + cmd = f"trace-cmd report {trace_dat} |grep -E '(initf_dm|dm_timer_init)'" + out = util.run_and_log(cons, ['sh', '-c', cmd]) + + start_timestamp = None + end_timestamp = None + for line in out.splitlines(): + m = RE_LINE.match(line) + if m: + timestamp, indent, func, brace = m.groups() + if func == 'initf_dm() ': + start_timestamp = timestamp + elif func == 'dm_timer_init() ': + end_timestamp = timestamp + break + assert start_timestamp and end_timestamp + + # Convert the time to microseconds + return int((float(end_timestamp) - float(start_timestamp)) * 1000000) + + +def check_flamegraph(cons, fname, proftool, map_fname, trace_fg): + """Check that the 'flamegraph' output works + + This spot checks a few call counts and estimates the time taken by the + initf_dm() function + + Args: + cons (ConsoleBase): U-Boot console + fname (str): Filename of trace file + proftool (str): Filename of proftool + map_fname (str): Filename of System.map + trace_fg (str): Filename of output file + + Returns: + int: Approximate number of microseconds used by the initf_dm() function + """ + + # Generate the flamegraph format + out = util.run_and_log( + cons, [proftool, '-t', fname, '-o', trace_fg, '-m', map_fname, + 'dump-flamegraph']) + + # We expect dm_timer_init() to be called twice: once before relocation and + # once after + look1 = 'initf_dm;dm_timer_init 1' + look2 = 'board_init_r;initr_dm_devices;dm_timer_init 1' + found = 0 + with open(trace_fg, 'r') as fd: + for line in fd: + line = line.strip() + if line == look1 or line == look2: + found += 1 + assert found == 2 + + # Generate the timing graph + out = util.run_and_log( + cons, [proftool, '-t', fname, '-o', trace_fg, '-m', map_fname, + 'dump-flamegraph', '-f', 'timing']) + + # Add up all the time spend in initf_dm() and its children + total = 0 + with open(trace_fg, 'r') as fd: + for line in fd: + line = line.strip() + if line.startswith('initf_dm'): + func, val = line.split() + count = int(val) + total += count + return total + + +@pytest.mark.slow +@pytest.mark.boardspec('sandbox') +@pytest.mark.buildconfigspec('trace') +def test_trace(u_boot_console): + """Test we can build sandbox with trace, collect and process a trace""" + cons = u_boot_console + + if not os.path.exists(TMPDIR): + os.mkdir(TMPDIR) + proftool = os.path.join(cons.config.build_dir, 'tools', 'proftool') + map_fname = os.path.join(cons.config.build_dir, 'System.map') + trace_dat = os.path.join(TMPDIR, 'trace.dat') + trace_fg = os.path.join(TMPDIR, 'trace.fg') + + fname, dm_f_time = collect_trace(cons) + + check_function(cons, fname, proftool, map_fname, trace_dat) + trace_time = check_funcgraph(cons, fname, proftool, map_fname, trace_dat) + + # Check that bootstage and funcgraph agree to within 10 microseconds + diff = abs(trace_time - dm_f_time) + print(f'trace_time {trace_time}, dm_f_time {dm_f_time}') + assert diff / dm_f_time < 0.01 + + fg_time = check_flamegraph(cons, fname, proftool, map_fname, trace_fg) + + # Check that bootstage and flamegraph agree to within 10% + diff = abs(fg_time - dm_f_time) + assert diff / dm_f_time < 0.1 |