From 38a4ec7342c27e675cc049d923e0075655fd91fd Mon Sep 17 00:00:00 2001 From: Paul Vinciguerra Date: Wed, 28 Nov 2018 11:34:21 -0800 Subject: make test: Add exception handling around subprocess. This cleans up exception catching to identify oserrors. By raising the specific exception closer to the offending call, we get additional stack history and can add clearer error logging to assist in troubleshooting. Change-Id: I592e4d46844b822a816485bf54910f8daed92088 Signed-off-by: Paul Vinciguerra --- test/framework.py | 11 ++++++++++- test/hook.py | 21 ++++++++++++++++----- test/run_tests.py | 16 +++++++++++++--- test/test_vcl.py | 21 ++++++++++++++++++++- 4 files changed, 59 insertions(+), 10 deletions(-) (limited to 'test') diff --git a/test/framework.py b/test/framework.py index 13f94d66354..38a49859e14 100644 --- a/test/framework.py +++ b/test/framework.py @@ -367,7 +367,16 @@ class VppTestCase(unittest.TestCase): stderr=subprocess.PIPE, bufsize=1) except subprocess.CalledProcessError as e: - cls.logger.critical("Couldn't start vpp: %s" % e) + cls.logger.critical("Subprocess returned with non-0 return code: (" + "%s)", e.returncode) + raise + except OSError as e: + cls.logger.critical("Subprocess returned with OS error: " + "(%s) %s", e.errno, e.strerror) + raise + except Exception as e: + cls.logger.exception("Subprocess returned unexpected from " + "%s:", cmdline) raise cls.wait_for_enter() diff --git a/test/hook.py b/test/hook.py index cddb603e46e..d23604ba13f 100644 --- a/test/hook.py +++ b/test/hook.py @@ -84,17 +84,28 @@ class PollHook(Hook): super(PollHook, self).__init__(test) def on_crash(self, core_path): - self.logger.error("Core file present, debug with: gdb %s %s" % - (self.test.vpp_bin, core_path)) + self.logger.error("Core file present, debug with: gdb %s %s", + self.testcase.vpp_bin, core_path) check_core_path(self.logger, core_path) - self.logger.error("Running `file %s':" % core_path) + self.logger.error("Running `file %s':", core_path) try: info = check_output(["file", core_path]) self.logger.error(info) except CalledProcessError as e: self.logger.error( - "Could not run `file' utility on core-file, " - "rc=%s" % e.returncode) + "Subprocess returned with error running `file' utility on " + "core-file, " + "rc=%s", e.returncode) + except OSError as e: + self.logger.error( + "Subprocess returned OS error running `file' utility on " + "core-file, " + "oserror=(%s) %s", e.errno, e.strerror) + except Exception as e: + self.logger.error( + "Subprocess returned unanticipated error running `file' " + "utility on core-file, " + "%s", e) def poll_vpp(self): """ diff --git a/test/run_tests.py b/test/run_tests.py index 726ccc9c0f4..f5d0d3546a2 100644 --- a/test/run_tests.py +++ b/test/run_tests.py @@ -253,13 +253,23 @@ def handle_failed_suite(logger, last_test_temp_dir, vpp_pid): "Core-file exists in test temporary directory: %s!" % core_path) check_core_path(logger, core_path) - logger.debug("Running `file %s':" % core_path) + logger.debug("Running 'file %s':" % core_path) try: info = check_output(["file", core_path]) logger.debug(info) except CalledProcessError as e: - logger.error("Could not run `file' utility on core-file, " - "rc=%s" % e.returncode) + logger.error("Subprocess returned with return code " + "while running `file' utility on core-file " + "returned: " + "rc=%s", e.returncode) + except OSError as e: + logger.error("Subprocess returned with OS error while " + "running 'file' utility " + "on core-file: " + "(%s) %s", e.errno, e.strerror) + except Exception as e: + logger.exception("Unexpected error running `file' utility " + "on core-file") if vpp_pid: # Copy api post mortem diff --git a/test/test_vcl.py b/test/test_vcl.py index 09017127eba..0a971a59a78 100644 --- a/test/test_vcl.py +++ b/test/test_vcl.py @@ -276,9 +276,20 @@ class LDPCutThruTestCase(VCLTestCase): try: subprocess.check_output(['iperf3', '-v']) except subprocess.CalledProcessError: - self.logger.error("WARNING: 'iperf3' is not installed,") + self.logger.error( + "WARNING: Subprocess returned non-0 running 'iperf3 -v") + self.logger.error(" 'test_ldp_cut_thru_iperf3' not run!") + return + except OSError as e: + self.logger.error( + "WARNING: Subprocess returned with OS error (%s) %s\n" + " 'iperf3' is likely not installed,", + e.errno, e.strerror) self.logger.error(" 'test_ldp_cut_thru_iperf3' not run!") return + except Exception: + self.logger.exception( + "Subprocess returned non-0 running 'iperf3 -v") self.timeout = self.client_iperf3_timeout self.cut_thru_test("iperf3", self.server_iperf3_args, @@ -652,6 +663,14 @@ class LDPThruHostStackIperf(VCLTestCase): self.logger.error( " 'test_ldp_thru_host_stack_iperf3' not run!") return + except OSError as e: + self.logger.error("WARNING: 'iperf3' is not installed,") + self.logger.error(" 'test' not run!") + return + except Exception as e: + self.logger.error("WARNING: 'iperf3' unexpected error,") + self.logger.error(" 'test' not run!") + return self.timeout = self.client_iperf3_timeout self.thru_host_stack_test("iperf3", self.server_iperf3_args, -- cgit 1.2.3-korg