Observed issue
==============
The test suite for lttng-tools is relatively large and can take
upwards of an hour or more to run in CI, especially with root
tests enabled.
Neither automake driver (`tests/utils/tap-driver.sh`) nor the
standalone tap script (`tests/utils/tap/tap.sh`) provide timing
information for the test runs or the steps within a test run.
Solution
========
The TAP driver invoked by `make check` has been modified to include a
`:time-taken:` metadata field (in seconds) in the produced trs file.
Known drawbacks
===============
`date` on FreeBSD does not support the `%N` formatter for nanoseconds,
which results in the precision dropping to 1s.
Metadata which isn't recognized by the automake test harness is
currently ignored, but it is a behaviour that remains open to change.
C.f. https://www.gnu.org/software/automake/manual/html_node/Log-files-generation-and-test-results-recording.html
Further work is required on the CI side to make use of the information.
Signed-off-by: Kienan Stewart <kstewart@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I94c7ddd7eb9388c595794e76dbbedc9bfe64d206
+function gettime_ns( r, cmd)
+{
+ cmd = "date +%s.%N"
+ r = ""
+ if (cmd | getline r) {
+ r = r
+ }
+ close(cmd)
+ return sprintf("%f", r)
+}
+
function get_global_test_result()
{
if ("ERROR" in test_results_seen)
function get_global_test_result()
{
if ("ERROR" in test_results_seen)
print ":global-test-result: " get_global_test_result() > trs_file
print ":recheck: " yn(must_recheck()) > trs_file
print ":copy-in-global-log: " yn(copy_in_global_log()) > trs_file
print ":global-test-result: " get_global_test_result() > trs_file
print ":recheck: " yn(must_recheck()) > trs_file
print ":copy-in-global-log: " yn(copy_in_global_log()) > trs_file
+ print ":time-taken: " sprintf("%f", gettime_ns() - TIME_START) > trs_file
for (i = 0; i < test_results_index; i += 1)
print ":test-result: " test_results_list[i] > trs_file
close(trs_file);
for (i = 0; i < test_results_index; i += 1)
print ":test-result: " test_results_list[i] > trs_file
close(trs_file);
# it is ("early" is seen before any test result, "late" otherwise).
plan_seen = NO_PLAN
# it is ("early" is seen before any test result, "late" otherwise).
plan_seen = NO_PLAN
+TIME_START = gettime_ns();
## --------- ##
## PARSING ##
## --------- ##
## --------- ##
## PARSING ##
## --------- ##