From a0a43d4135c830bf076bb76b0a9dd2eaa4ffaaef Mon Sep 17 00:00:00 2001 From: Ranjani Sridharan Date: Wed, 24 Apr 2024 09:16:18 -0700 Subject: [PATCH] tools: Add a new script for firmware boot stress testing This requires the kernel changes that expose the debugfs entries for executing the different DSP ops and reading the current DSP firmware and power states. The script takes the firmware name and the path as inputs along with the number of iterations of firmware boot. It takes care of putting the DSP in the D3 state and unloading any existing firmware before starting firmware boot. Signed-off-by: Ranjani Sridharan --- tools/sof-fw-boot-test.py | 162 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 162 insertions(+) create mode 100755 tools/sof-fw-boot-test.py diff --git a/tools/sof-fw-boot-test.py b/tools/sof-fw-boot-test.py new file mode 100755 index 00000000..b6ae35ae --- /dev/null +++ b/tools/sof-fw-boot-test.py @@ -0,0 +1,162 @@ +#!/usr/bin/env python3 + +"""Module to stress test firmware boot""" + +import argparse +import logging +import sys +import time +from datetime import datetime +from systemd import journal + +logging.basicConfig(level=logging.INFO, format="%(message)s") + +# set path to the depbugfs entries +debugfs_path = "/sys/kernel/debug/sof/fw_debug_ops" + +def read_jctl_logs(start_time): + """Reads journalctl logs from a given start time and extracts the timestamp and log""" + journal_reader = journal.Reader() + journal_reader.this_boot() + journal_reader.seek_realtime(datetime.strptime(start_time, '%Y-%m-%d %H:%M:%S')) + + entries = [] + for entry in journal_reader: + timestamp = entry['__REALTIME_TIMESTAMP'] + message = entry.get('MESSAGE', '') + if isinstance(message, bytes): + message = message.decode('utf-8', errors='replace') + entries.append((timestamp, message)) + + return entries + +# define command line arguments +def parse_cmdline(): + """Function to parse the command line arguments""" + parser = argparse.ArgumentParser( + add_help=True, + formatter_class=argparse.RawTextHelpFormatter, + description="A script for stress testing firmware boot", + ) + parser.add_argument( + "-i", "--iter", type=int, default=100, help="number of firmware boot iterations" + ) + parser.add_argument( + "-f", "--firmware", type=str, + help="firmware filename. If this is not set, the kernel will boot the default firmware" + ) + parser.add_argument( + "-p", + "--fw_path", + type=str, + help="""path to the firmware file. If the path is not relative to /lib/firmware, + use echo -n /path/to/fw_file > /sys/module/firmware_class/parameters/path""", + ) + return parser.parse_args() + +def dsp_set(node, state): + open(f"{debugfs_path}/{node}", "w").write(f"{state}\n") + +def dsp_get(node): + return open(f"{debugfs_path}/{node}").read().rstrip() + +def boot_fw(): + """Power down the DSP and boot firmware using previously set firmware path and filename""" + # put the DSP in D3 + debugfs_entry = debugfs_path + "/dsp_power_state" + dsp_set("dsp_power_state", "D3") + + # check if the DSP is in D3 + power_state = dsp_get("dsp_power_state") + if power_state != "D3": + sys.exit("Failed booting firmware. DSP is not in D3") + + # unload current firmware + dsp_set("unload_fw", "1") + + # get current fw_state and continue to boot only if the current state is 'PREPARE' + fw_state = dsp_get("fw_state") + if "PREPARE" not in fw_state: + sys.exit(f"Cannot boot firmware from current state {fw_state}") + + # load and boot firmware + dsp_set("boot_fw", "1") + + # get current fw_state + fw_state = dsp_get("fw_state") + + return fw_state + +def main(): + """Main function for stress testing""" + cmd_args = parse_cmdline() + + # clear firmware filename/path + dsp_set("fw_filename", "") + dsp_set("fw_path", "") + + # Get firmware file path if set + if cmd_args.fw_path: + fw_path = cmd_args.fw_path + dsp_set("fw_path", fw_path) + else: + fw_path = "default" + + # Get firmware file name if set + if cmd_args.firmware: + fw_filename = cmd_args.firmware + dsp_set("fw_filename", fw_filename) + else: + fw_filename = "default" + + num_iter = cmd_args.iter + output = f"""============================================================================== + Starting boot stress test with: + Firmware filename: {fw_filename} + Path to firmware file: {fw_path} + Number of Iterations: {num_iter} +==============================================================================""" + logging.info(output) + + total_boot_time_ms = 0 + min_boot_time_ms = sys.maxsize + max_boot_time_ms = 0 + + for i in range(num_iter): + start_time = datetime.now().strftime('%Y-%m-%d %H:%M:%S') + fw_state = boot_fw() + # check if fw_state is COMPLETE + if "COMPLETE" not in fw_state: + sys.exit(f"Firmware boot failed at iteration {i}") + + journalctl_output = read_jctl_logs(start_time) + + boot_start_time = 0 + boot_end_time = 0 + for timestamp, message in journalctl_output: + if 'booting DSP firmware' in message: + boot_start_time = timestamp + if 'firmware boot complete' in message: + boot_end_time = timestamp + if boot_start_time == 0 or boot_end_time == 0: + sys.exit(f"Failed to calculate boot time at iteration {i}") + + time_diff = (boot_end_time - boot_start_time) + boot_time_ms = round(time_diff.total_seconds() * 1000, 2) + total_boot_time_ms += boot_time_ms + min_boot_time_ms = min(min_boot_time_ms, boot_time_ms) + max_boot_time_ms = max(max_boot_time_ms, boot_time_ms) + + logging.info("Firmware boot iteration %d completed in %s ms" % (i, boot_time_ms)) + + # print firmware boot stats + avg_boot_time_ms = total_boot_time_ms / num_iter + output = f"""============================================================================== + Average firmware boot time {avg_boot_time_ms} ms + Maximum firmware boot time {max_boot_time_ms} ms + Minimum firmware boot time {min_boot_time_ms} ms +==============================================================================""" + logging.info(output) + +if __name__ == "__main__": + main()