From 9a13b5bf1dd3eeb20e9e41dbc8efa1cf33d17485 Mon Sep 17 00:00:00 2001 From: Zingo Andersen Date: Mon, 30 Jun 2025 16:26:38 +0200 Subject: [PATCH] Arm backend: Measure and show time per model during testing This will add time logs during testing so it will be easier to track what part of the flow take time and for what models. Signed-off-by: Zingo Andersen Change-Id: I5e124bf5e15a7c252df77089e83044d96b9ade4e --- backends/arm/test/test_model.py | 30 ++++++++++++++++++++++++++---- 1 file changed, 26 insertions(+), 4 deletions(-) diff --git a/backends/arm/test/test_model.py b/backends/arm/test/test_model.py index 3e3ecf30fa0..5e53da4a0ef 100755 --- a/backends/arm/test/test_model.py +++ b/backends/arm/test/test_model.py @@ -7,6 +7,7 @@ import os import subprocess import sys +import time def get_args(): @@ -199,12 +200,17 @@ def run_elf_with_fvp(script_path: str, elf_file: str, target: str, timeout: int) if __name__ == "__main__": - + total_start_time = time.perf_counter() args = get_args() script_path = os.path.join("backends", "arm", "scripts") if args.build_libs: + start_time = time.perf_counter() build_libs(args.test_output, script_path) + end_time = time.perf_counter() + print( + f"[Test model: {end_time - start_time:.2f} s] Build needed executorch libs" + ) if args.model: model_name = args.model.split(" ")[0].split(";")[0] @@ -217,6 +223,7 @@ def run_elf_with_fvp(script_path: str, elf_file: str, target: str, timeout: int) args.test_output, f"{model_name}_arm_delegate_{args.target}" ) + start_time = time.perf_counter() pte_file = build_pte( args.test_output, model_name, @@ -226,13 +233,17 @@ def run_elf_with_fvp(script_path: str, elf_file: str, target: str, timeout: int) output, args.no_intermediate, ) - print(f"PTE file created: {pte_file} ") + end_time = time.perf_counter() + print( + f"[Test model: {end_time - start_time:.2f} s] PTE file created: {pte_file}" + ) if "ethos-u" in args.target: elf_build_path = os.path.join( output, f"{model_name}_arm_delegate_{args.target}" ) + start_time = time.perf_counter() elf_file = build_ethosu_runtime( args.test_output, script_path, @@ -243,7 +254,18 @@ def run_elf_with_fvp(script_path: str, elf_file: str, target: str, timeout: int) args.extra_flags, elf_build_path, ) - print(f"ELF file created: {elf_file} ") + end_time = time.perf_counter() + print( + f"[Test model: {end_time - start_time:.2f} s] ELF file created: {elf_file}" + ) + start_time = time.perf_counter() run_elf_with_fvp(script_path, elf_file, args.target, args.timeout) - print(f"Model: {model_name} on {args.target} -> PASS") + end_time = time.perf_counter() + print( + f"[Test model: {end_time - start_time:.2f} s] Tested elf on FVP {elf_file}" + ) + total_end_time = time.perf_counter() + print( + f"[Test model: {total_end_time - total_start_time:.2f} s total] Model: {model_name} on {args.target} -> PASS" + )