From 88aa873fbc544b99c1e48e37d5c74662f90b3de0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Mart=C3=AD=20Bol=C3=ADvar?= Date: Mon, 22 Aug 2022 09:38:00 -0700 Subject: [PATCH] twister: improve logging of cmake commands MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit With verbose output enabled, twister logs the cmake arguments as a python array whenever it invokes cmake to generate a build system. This is clunky output for manual reproduction, because it forces the developer to manually join the arguments together for consumption by the shell. As an enhancement for this use case, use the standard library shlex.join() function to produce a string that can be copy/pasted directly into the shell on POSIX platforms. We should use this function instead of str.join, because it correctly handles things like shell quoting for options with spaces in them. This function is not available on Windows, so we fall back on behavior that is similar to the old one there. The main difference on Windows is that the output now includes the path to cmake as well, and not just its arguments. (This is the same on POSIX, and is intended to help debug if multiple cmakes are installed on the same machine.) We are running cmake from a couple of different places, so doing this cleanly requires adding a shared module with the platform abstraction. Signed-off-by: Martí Bolívar --- .../pylib/twister/twisterlib/environment.py | 8 +++--- .../pylib/twister/twisterlib/log_helper.py | 27 +++++++++++++++++++ scripts/pylib/twister/twisterlib/runner.py | 5 ++-- 3 files changed, 35 insertions(+), 5 deletions(-) create mode 100644 scripts/pylib/twister/twisterlib/log_helper.py diff --git a/scripts/pylib/twister/twisterlib/environment.py b/scripts/pylib/twister/twisterlib/environment.py index 1c6f4637cb2..62e549eb8d6 100644 --- a/scripts/pylib/twister/twisterlib/environment.py +++ b/scripts/pylib/twister/twisterlib/environment.py @@ -18,6 +18,7 @@ logger = logging.getLogger('twister') logger.setLevel(logging.DEBUG) from twisterlib.error import TwisterRuntimeError +from twisterlib.log_helper import log_command ZEPHYR_BASE = os.getenv("ZEPHYR_BASE") if not ZEPHYR_BASE: @@ -705,19 +706,20 @@ class TwisterEnv: @staticmethod def run_cmake_script(args=[]): + script = os.fspath(args[0]) - logger.debug("Running cmake script %s" % (args[0])) + logger.debug("Running cmake script %s", script) cmake_args = ["-D{}".format(a.replace('"', '')) for a in args[1:]] - cmake_args.extend(['-P', args[0]]) + cmake_args.extend(['-P', script]) - logger.debug("Calling cmake with arguments: {}".format(cmake_args)) cmake = shutil.which('cmake') if not cmake: msg = "Unable to find `cmake` in path" logger.error(msg) raise Exception(msg) cmd = [cmake] + cmake_args + log_command(logger, "Calling cmake", cmd) kwargs = dict() kwargs['stdout'] = subprocess.PIPE diff --git a/scripts/pylib/twister/twisterlib/log_helper.py b/scripts/pylib/twister/twisterlib/log_helper.py new file mode 100644 index 00000000000..3604f64ce1e --- /dev/null +++ b/scripts/pylib/twister/twisterlib/log_helper.py @@ -0,0 +1,27 @@ +# Copyright (c) 2022 Nordic Semiconductor ASA +# SPDX-License-Identifier: Apache-2.0 + +''' +Common code used when logging that is needed by multiple modules. +''' + +import platform +import shlex + +_WINDOWS = (platform.system() == 'Windows') + +def log_command(logger, msg, args): + '''Platform-independent helper for logging subprocess invocations. + Will log a command string that can be copy/pasted into a POSIX + shell on POSIX platforms. This is not available on Windows, so + the entire args array is logged instead. + + :param logger: logging.Logger to use + :param msg: message to associate with the command + :param args: argument list as passed to subprocess module + ''' + msg = f'{msg}: %s' + if _WINDOWS: + logger.debug(msg, str(args)) + else: + logger.debug(msg, shlex.join(args)) diff --git a/scripts/pylib/twister/twisterlib/runner.py b/scripts/pylib/twister/twisterlib/runner.py index 7f9cb8e1540..9c23c9a3f9f 100644 --- a/scripts/pylib/twister/twisterlib/runner.py +++ b/scripts/pylib/twister/twisterlib/runner.py @@ -19,6 +19,7 @@ from multiprocessing import Lock, Process, Value from multiprocessing.managers import BaseManager from twisterlib.cmakecache import CMakeCache from twisterlib.environment import canonical_zephyr_base +from twisterlib.log_helper import log_command logger = logging.getLogger('twister') logger.setLevel(logging.DEBUG) @@ -262,12 +263,12 @@ class CMake: cmake_opts = ['-DBOARD={}'.format(self.platform.name)] cmake_args.extend(cmake_opts) - - logger.debug("Calling cmake with arguments: {}".format(cmake_args)) cmake = shutil.which('cmake') cmd = [cmake] + cmake_args kwargs = dict() + log_command(logger, "Calling cmake", cmd) + if self.capture_output: kwargs['stdout'] = subprocess.PIPE # CMake sends the output of message() to stderr unless it's STATUS