From 723a8fcf364e57decdde906cf1af62b08b76e5d5 Mon Sep 17 00:00:00 2001 From: Benjamin Gwin Date: Thu, 11 Aug 2022 15:42:15 -0700 Subject: [PATCH] twister: Add logging of stderr for BinaryHandlers In the case where a test causes the test executor to crash, the stderr is currently lost, making it hard to debug failures. This changes it so that the process' stderr gets captured to 'handler_stderr.log' for inspection. Signed-off-by: Benjamin Gwin --- scripts/pylib/twister/twisterlib/handlers.py | 8 ++++++-- scripts/pylib/twister/twisterlib/runner.py | 4 ++++ 2 files changed, 10 insertions(+), 2 deletions(-) diff --git a/scripts/pylib/twister/twisterlib/handlers.py b/scripts/pylib/twister/twisterlib/handlers.py index 16cec58be2f8..970e6b2717ef 100755 --- a/scripts/pylib/twister/twisterlib/handlers.py +++ b/scripts/pylib/twister/twisterlib/handlers.py @@ -307,8 +307,9 @@ def handle(self, harness): harness.run_robot_test(command, self) return - with subprocess.Popen(command, stdout=subprocess.PIPE, - stderr=subprocess.PIPE, cwd=self.build_dir, env=env) as proc: + stderr_log = "{}/handler_stderr.log".format(self.instance.build_dir) + with open(stderr_log, "w+") as stderr_log_fp, subprocess.Popen(command, stdout=subprocess.PIPE, + stderr=stderr_log_fp, cwd=self.build_dir, env=env) as proc: logger.debug("Spawning BinaryHandler Thread for %s" % self.name) t = threading.Thread(target=self._output_handler, args=(proc, harness,), daemon=True) t.start() @@ -318,6 +319,9 @@ def handle(self, harness): t.join() proc.wait() self.returncode = proc.returncode + if proc.returncode != 0: + self.instance.status = "error" + self.instance.reason = "BinaryHandler returned {}".format(proc.returncode) self.try_kill_process_by_pid() handler_time = time.time() - start_time diff --git a/scripts/pylib/twister/twisterlib/runner.py b/scripts/pylib/twister/twisterlib/runner.py index 25037eb26324..7251f3f733ce 100644 --- a/scripts/pylib/twister/twisterlib/runner.py +++ b/scripts/pylib/twister/twisterlib/runner.py @@ -573,6 +573,7 @@ def log_info(self, filename, inline_logs, log_testcases=False): def log_info_file(self, inline_logs): build_dir = self.instance.build_dir h_log = "{}/handler.log".format(build_dir) + he_log = "{}/handler_stderr.log".format(build_dir) b_log = "{}/build.log".format(build_dir) v_log = "{}/valgrind.log".format(build_dir) d_log = "{}/device.log".format(build_dir) @@ -584,6 +585,8 @@ def log_info_file(self, inline_logs): self.log_info("{}".format(pytest_log), inline_logs, log_testcases=True) elif os.path.exists(h_log) and os.path.getsize(h_log) > 0: self.log_info("{}".format(h_log), inline_logs) + elif os.path.exists(he_log) and os.path.getsize(he_log) > 0: + self.log_info("{}".format(he_log), inline_logs) elif os.path.exists(d_log) and os.path.getsize(d_log) > 0: self.log_info("{}".format(d_log), inline_logs) else: @@ -757,6 +760,7 @@ def cleanup_artifacts(self, additional_keep: List[str] = []): allow = [ os.path.join('zephyr', '.config'), 'handler.log', + 'handler_stderr.log', 'build.log', 'device.log', 'recording.csv',