From cf60db6ebe516d8470d9935c380f7ecc27071a25 Mon Sep 17 00:00:00 2001 From: Rob N Date: Wed, 17 Apr 2024 02:13:01 +1000 Subject: [PATCH] zts: add a debug option to get full test output The test runner accumulates output from individual tests, then writes it to the log at the end. If a test hangs or crashes the system half way through, we get no insight into how it got to where it did. This adds a -D option for "debug". When set, all test output is written to stdout. Sponsored-by: Klara, Inc. Sponsored-by: Wasabi Technology, Inc. Reviewed-by: Brian Behlendorf Reviewed-by: Akash B Signed-off-by: Rob Norris Closes #16096 --- scripts/zfs-tests.sh | 10 +++++++++- tests/test-runner/bin/test-runner.py.in | 23 ++++++++++++++++------- 2 files changed, 25 insertions(+), 8 deletions(-) diff --git a/scripts/zfs-tests.sh b/scripts/zfs-tests.sh index b5b3e4ab3..c25903ea1 100755 --- a/scripts/zfs-tests.sh +++ b/scripts/zfs-tests.sh @@ -32,6 +32,7 @@ SCRIPT_COMMON=${SCRIPT_COMMON:-${0%/*}/common.sh} PROG=zfs-tests.sh VERBOSE="no" QUIET="" +DEBUG="" CLEANUP="yes" CLEANUPALL="no" KMSG="" @@ -313,6 +314,7 @@ OPTIONS: -h Show this message -v Verbose zfs-tests.sh output -q Quiet test-runner output + -D Debug; show all test output immediately (noisy) -x Remove all testpools, dm, lo, and files (unsafe) -k Disable cleanup after test failure -K Log test names to /dev/kmsg @@ -351,7 +353,7 @@ $0 -x EOF } -while getopts 'hvqxkKfScRmn:d:s:r:?t:T:u:I:' OPTION; do +while getopts 'hvqxkKfScRmn:d:Ds:r:?t:T:u:I:' OPTION; do case $OPTION in h) usage @@ -397,6 +399,9 @@ while getopts 'hvqxkKfScRmn:d:s:r:?t:T:u:I:' OPTION; do d) FILEDIR="$OPTARG" ;; + D) + DEBUG="yes" + ;; I) ITERATIONS="$OPTARG" if [ "$ITERATIONS" -le 0 ]; then @@ -691,6 +696,7 @@ REPORT_FILE=$(mktemp_file zts-report) # msg "${TEST_RUNNER}" \ "${QUIET:+-q}" \ + "${DEBUG:+-D}" \ "${KMEMLEAK:+-m}" \ "${KMSG:+-K}" \ "-c \"${RUNFILES}\"" \ @@ -700,6 +706,7 @@ msg "${TEST_RUNNER}" \ { PATH=$STF_PATH \ ${TEST_RUNNER} \ ${QUIET:+-q} \ + ${DEBUG:+-D} \ ${KMEMLEAK:+-m} \ ${KMSG:+-K} \ -c "${RUNFILES}" \ @@ -726,6 +733,7 @@ if [ "$RESULT" -eq "2" ] && [ -n "$RERUN" ]; then { PATH=$STF_PATH \ ${TEST_RUNNER} \ ${QUIET:+-q} \ + ${DEBUG:+-D} \ ${KMEMLEAK:+-m} \ -c "${RUNFILES}" \ -T "${TAGS}" \ diff --git a/tests/test-runner/bin/test-runner.py.in b/tests/test-runner/bin/test-runner.py.in index 422ebd7bc..65247f4f0 100755 --- a/tests/test-runner/bin/test-runner.py.in +++ b/tests/test-runner/bin/test-runner.py.in @@ -113,8 +113,9 @@ class Output(object): This class is a slightly modified version of the 'Stream' class found here: http://goo.gl/aSGfv """ - def __init__(self, stream): + def __init__(self, stream, debug=False): self.stream = stream + self.debug = debug self._buf = b'' self.lines = [] @@ -140,6 +141,8 @@ class Output(object): buf = os.read(fd, 4096) if not buf: return None + if self.debug: + os.write(sys.stderr.fileno(), buf) if b'\n' not in buf: self._buf += buf return [] @@ -238,14 +241,14 @@ User: %s ret = '%s -E -u %s %s' % (SUDO, user, cmd) return ret.split(' ') - def collect_output(self, proc): + def collect_output(self, proc, debug=False): """ Read from stdout/stderr as data becomes available, until the process is no longer running. Return the lines from the stdout and stderr Output objects. """ - out = Output(proc.stdout) - err = Output(proc.stderr) + out = Output(proc.stdout, debug) + err = Output(proc.stderr, debug) res = [] while proc.returncode is None: proc.poll() @@ -308,7 +311,10 @@ User: %s try: t.start() - self.result.stdout, self.result.stderr = self.collect_output(proc) + + out, err = self.collect_output(proc, options.debug) + self.result.stdout = out + self.result.stderr = err if kmemleak: cmd = f'{SUDO} sh -c "echo scan > {KMEMLEAK_FILE}"' @@ -624,7 +630,7 @@ Tags: %s class TestRun(object): - props = ['quiet', 'outputdir'] + props = ['quiet', 'outputdir', 'debug'] def __init__(self, options): self.tests = {} @@ -644,7 +650,8 @@ class TestRun(object): ('post_user', ''), ('failsafe', ''), ('failsafe_user', ''), - ('tags', []) + ('tags', []), + ('debug', False) ] def __str__(self): @@ -1067,6 +1074,8 @@ def parse_args(): help='Specify tests to run via config files.') parser.add_option('-d', action='store_true', default=False, dest='dryrun', help='Dry run. Print tests, but take no other action.') + parser.add_option('-D', action='store_true', default=False, dest='debug', + help='Write all test output to stdout as it arrives.') parser.add_option('-l', action='callback', callback=options_cb, default=None, dest='logfile', metavar='logfile', type='string', -- 2.39.5