|
| 1 | +#!/usr/bin/env python3 |
| 2 | + |
| 3 | +"""Module to stress test firmware boot""" |
| 4 | + |
| 5 | +import argparse |
| 6 | +import logging |
| 7 | +import sys |
| 8 | +import time |
| 9 | +from datetime import datetime |
| 10 | +from systemd import journal |
| 11 | + |
| 12 | +logging.basicConfig(level=logging.INFO, format="%(message)s") |
| 13 | + |
| 14 | +# set path to the depbugfs entries |
| 15 | +debugfs_path = "/sys/kernel/debug/sof/fw_debug_ops" |
| 16 | + |
| 17 | +def read_jctl_logs(start_time): |
| 18 | + """Reads journalctl logs from a given start time and extracts the timestamp and log""" |
| 19 | + journal_reader = journal.Reader() |
| 20 | + journal_reader.this_boot() |
| 21 | + journal_reader.seek_realtime(datetime.strptime(start_time, '%Y-%m-%d %H:%M:%S')) |
| 22 | + |
| 23 | + entries = [] |
| 24 | + for entry in journal_reader: |
| 25 | + timestamp = entry['__REALTIME_TIMESTAMP'] |
| 26 | + message = entry.get('MESSAGE', '') |
| 27 | + if isinstance(message, bytes): |
| 28 | + message = message.decode('utf-8', errors='replace') |
| 29 | + entries.append((timestamp, message)) |
| 30 | + |
| 31 | + return entries |
| 32 | + |
| 33 | +# define command line arguments |
| 34 | +def parse_cmdline(): |
| 35 | + """Function to parse the command line arguments""" |
| 36 | + parser = argparse.ArgumentParser( |
| 37 | + add_help=True, |
| 38 | + formatter_class=argparse.RawTextHelpFormatter, |
| 39 | + description="A script for stress testing firmware boot", |
| 40 | + ) |
| 41 | + parser.add_argument( |
| 42 | + "-i", "--iter", type=int, default=100, help="number of firmware boot iterations" |
| 43 | + ) |
| 44 | + parser.add_argument( |
| 45 | + "-f", "--firmware", type=str, |
| 46 | + help="firmware filename. If this is not set, the kernel will boot the default firmware" |
| 47 | + ) |
| 48 | + parser.add_argument( |
| 49 | + "-p", |
| 50 | + "--fw_path", |
| 51 | + type=str, |
| 52 | + help="""path to the firmware file. If the path is not relative to /lib/firmware, |
| 53 | + use echo -n /path/to/fw_file > /sys/module/firmware_class/parameters/path""", |
| 54 | + ) |
| 55 | + return parser.parse_args() |
| 56 | + |
| 57 | +def dsp_set(node, state): |
| 58 | + open(f"{debugfs_path}/{node}", "w").write(f"{state}\n") |
| 59 | + |
| 60 | +def dsp_get(node): |
| 61 | + return open(f"{debugfs_path}/{node}").read().rstrip() |
| 62 | + |
| 63 | +def boot_fw(): |
| 64 | + """Power down the DSP and boot firmware using previously set firmware path and filename""" |
| 65 | + # put the DSP in D3 |
| 66 | + debugfs_entry = debugfs_path + "/dsp_power_state" |
| 67 | + dsp_set("dsp_power_state", "D3") |
| 68 | + |
| 69 | + # check if the DSP is in D3 |
| 70 | + power_state = dsp_get("dsp_power_state") |
| 71 | + if power_state != "D3": |
| 72 | + sys.exit("Failed booting firmware. DSP is not in D3") |
| 73 | + |
| 74 | + # unload current firmware |
| 75 | + dsp_set("unload_fw", "1") |
| 76 | + |
| 77 | + # get current fw_state and continue to boot only if the current state is 'PREPARE' |
| 78 | + fw_state = dsp_get("fw_state") |
| 79 | + if "PREPARE" not in fw_state: |
| 80 | + sys.exit(f"Cannot boot firmware from current state {fw_state}") |
| 81 | + |
| 82 | + # load and boot firmware |
| 83 | + dsp_set("boot_fw", "1") |
| 84 | + |
| 85 | + # get current fw_state |
| 86 | + fw_state = dsp_get("fw_state") |
| 87 | + |
| 88 | + return fw_state |
| 89 | + |
| 90 | +def main(): |
| 91 | + """Main function for stress testing""" |
| 92 | + cmd_args = parse_cmdline() |
| 93 | + |
| 94 | + # clear firmware filename/path |
| 95 | + dsp_set("fw_filename", "") |
| 96 | + dsp_set("fw_path", "") |
| 97 | + |
| 98 | + # Get firmware file path if set |
| 99 | + if cmd_args.fw_path: |
| 100 | + fw_path = cmd_args.fw_path |
| 101 | + dsp_set("fw_path", fw_path) |
| 102 | + else: |
| 103 | + fw_path = "default" |
| 104 | + |
| 105 | + # Get firmware file name if set |
| 106 | + if cmd_args.firmware: |
| 107 | + fw_filename = cmd_args.firmware |
| 108 | + dsp_set("fw_filename", fw_filename) |
| 109 | + else: |
| 110 | + fw_filename = "default" |
| 111 | + |
| 112 | + num_iter = cmd_args.iter |
| 113 | + output = f"""============================================================================== |
| 114 | + Starting boot stress test with: |
| 115 | + Firmware filename: {fw_filename} |
| 116 | + Path to firmware file: {fw_path} |
| 117 | + Number of Iterations: {num_iter} |
| 118 | +==============================================================================""" |
| 119 | + logging.info(output) |
| 120 | + |
| 121 | + total_boot_time_ms = 0 |
| 122 | + min_boot_time_ms = sys.maxsize |
| 123 | + max_boot_time_ms = 0 |
| 124 | + |
| 125 | + for i in range(num_iter): |
| 126 | + start_time = datetime.now().strftime('%Y-%m-%d %H:%M:%S') |
| 127 | + fw_state = boot_fw() |
| 128 | + # check if fw_state is COMPLETE |
| 129 | + if "COMPLETE" not in fw_state: |
| 130 | + sys.exit(f"Firmware boot failed at iteration {i}") |
| 131 | + |
| 132 | + journalctl_output = read_jctl_logs(start_time) |
| 133 | + |
| 134 | + boot_start_time = 0 |
| 135 | + boot_end_time = 0 |
| 136 | + for timestamp, message in journalctl_output: |
| 137 | + if 'booting DSP firmware' in message: |
| 138 | + boot_start_time = timestamp |
| 139 | + if 'firmware boot complete' in message: |
| 140 | + boot_end_time = timestamp |
| 141 | + if boot_start_time == 0 or boot_end_time == 0: |
| 142 | + sys.exit(f"Failed to calculate boot time at iteration {i}") |
| 143 | + |
| 144 | + time_diff = (boot_end_time - boot_start_time) |
| 145 | + boot_time_ms = round(time_diff.total_seconds() * 1000, 2) |
| 146 | + total_boot_time_ms += boot_time_ms |
| 147 | + min_boot_time_ms = min(min_boot_time_ms, boot_time_ms) |
| 148 | + max_boot_time_ms = max(max_boot_time_ms, boot_time_ms) |
| 149 | + |
| 150 | + logging.info(f"Firmware boot iteration {i} completed in {boot_time_ms} ms") |
| 151 | + |
| 152 | + # print firmware boot stats |
| 153 | + avg_boot_time_ms = total_boot_time_ms / num_iter |
| 154 | + output = f"""============================================================================== |
| 155 | + Average firmware boot time {avg_boot_time_ms} ms |
| 156 | + Maximum firmware boot time {max_boot_time_ms} ms |
| 157 | + Minimum firmware boot time {min_boot_time_ms} ms |
| 158 | +==============================================================================""" |
| 159 | + logging.info(output) |
| 160 | + |
| 161 | +if __name__ == "__main__": |
| 162 | + main() |
0 commit comments