From 5f6aa6d82e45d27f00f39844749ae812c7fd6ab3 Mon Sep 17 00:00:00 2001 From: Daniel Latypov Date: Thu, 30 Sep 2021 15:20:47 -0700 Subject: kunit: tool: actually track how long it took to run tests This is a long standing bug in kunit tool. Since these files were added, run_kernel() has always yielded lines. That means, the call to run_kernel() returns before the kernel finishes executing tests, potentially before a single line of output is even produced. So code like this time_start = time.time() result = linux.run_kernel(...) time_end = time.time() would only measure the time taken for python to give back the generator object. From a caller's perspective, the only way to know the kernel has exited is for us to consume all the output from the `result` generator object. Alternatively, we could change run_kernel() to try and do its own book keeping and return the total time, but that doesn't seem worth it. This change makes us record `time_end` after we're done parsing all the output (which should mean we've consumed all of it, or errored out). That means we're including in the parsing time as well, but that should be quite small, and it's better than claiming it took 0s to run tests. Let's use this as an example: $ ./tools/testing/kunit/kunit.py run --kunitconfig=lib/kunit example Before: Elapsed time: 7.684s total, 0.001s configuring, 4.692s building, 0.000s running After: Elapsed time: 6.283s total, 0.001s configuring, 3.202s building, 3.079s running Signed-off-by: Daniel Latypov Reviewed-by: David Gow Reviewed-by: Brendan Higgins Signed-off-by: Shuah Khan --- tools/testing/kunit/kunit.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) (limited to 'tools/testing/kunit') diff --git a/tools/testing/kunit/kunit.py b/tools/testing/kunit/kunit.py index 116ce7a8a18f..1c495d8ce189 100755 --- a/tools/testing/kunit/kunit.py +++ b/tools/testing/kunit/kunit.py @@ -100,12 +100,14 @@ def exec_tests(linux: kunit_kernel.LinuxSourceTree, request: KunitExecRequest, filter_glob=request.filter_glob, build_dir=request.build_dir) + result = parse_tests(parse_request, run_result) + + # run_kernel() doesn't block on the kernel exiting. + # That only happens after we get the last line of output from `run_result`. + # So exec_time here actually contains parsing + execution time, which is fine. test_end = time.time() exec_time = test_end - test_start - # Named tuples are immutable, so we rebuild them here manually - result = parse_tests(parse_request, run_result) - return KunitResult(status=result.status, result=result.result, elapsed_time=exec_time) def parse_tests(request: KunitParseRequest, input_data: Iterable[str]) -> KunitResult: -- cgit v1.2.3