diff --git a/client/starwhale/consts/__init__.py b/client/starwhale/consts/__init__.py index 0292ae4c44..619b7a7b06 100644 --- a/client/starwhale/consts/__init__.py +++ b/client/starwhale/consts/__init__.py @@ -7,6 +7,7 @@ ENV_SW_CLI_CONFIG = "SW_CLI_CONFIG" ENV_LOG_LEVEL = "SW_LOG_LEVEL" +ENV_LOG_VERBOSE_COUNT = "SW_LOG_VERBOSE_COUNT" ENV_SW_IMAGE_REPO = "SW_IMAGE_REPO" # SW_LOCAL_STORAGE env used for generating default swcli config # and overriding 'storage.root' swcli config in runtime diff --git a/client/starwhale/core/runtime/process.py b/client/starwhale/core/runtime/process.py index 05acc40e64..3ec9403930 100644 --- a/client/starwhale/core/runtime/process.py +++ b/client/starwhale/core/runtime/process.py @@ -9,7 +9,7 @@ import dill from starwhale.utils import console -from starwhale.consts import PythonRunEnv +from starwhale.consts import PythonRunEnv, ENV_LOG_VERBOSE_COUNT from starwhale.base.uri import URI from starwhale.base.type import URIType, InstanceType from starwhale.utils.venv import ( @@ -57,19 +57,19 @@ def run(self) -> None: if not os.path.exists(_pkl_path): raise NotFoundError(f"dill file: {_pkl_path}") + verbose = int(os.environ.get(ENV_LOG_VERBOSE_COUNT, "0")) try: cmd = [ self._get_activate_cmd(), - f'{self._prefix_path}/bin/python3 -c \'import dill; dill.load(open("{_pkl_path}", "rb"))()\'', + f'{self._prefix_path}/bin/python3 -c \'from starwhale.utils.debug import init_logger; init_logger({verbose}); import dill; dill.load(open("{_pkl_path}", "rb"))()\'', ] console.print( f":rooster: run process in the python isolated environment(prefix: {self._prefix_path})" ) - # TODO: tune subprocess output with log-level check_call( ["bash", "-c", " && ".join(cmd)], env={self.EnvInActivatedProcess: "1"}, - log=console.print, + log=print, ) finally: os.unlink(_pkl_path) diff --git a/client/starwhale/utils/debug.py b/client/starwhale/utils/debug.py index 91996d5ddc..9c5e7ded9e 100644 --- a/client/starwhale/utils/debug.py +++ b/client/starwhale/utils/debug.py @@ -5,7 +5,7 @@ from rich import traceback from loguru import logger -from starwhale.consts import ENV_LOG_LEVEL +from starwhale.consts import ENV_LOG_LEVEL, ENV_LOG_VERBOSE_COUNT def init_logger(verbose: int) -> None: @@ -15,16 +15,11 @@ def init_logger(verbose: int) -> None: elif verbose == 1: lvl = logging.INFO else: - fmt = ( - "{time:YYYY-MM-DD HH:mm:ss.SSS} | " - "{level: <6} | " - "{message}" - ) lvl = logging.DEBUG lvl_name = logging.getLevelName(lvl) - os.environ[ENV_LOG_LEVEL] = lvl_name + os.environ[ENV_LOG_VERBOSE_COUNT] = str(verbose) # TODO: custom debug for tb install traceback.install(show_locals=True, max_frames=1, width=200) diff --git a/client/starwhale/utils/process.py b/client/starwhale/utils/process.py index 6e522d415f..72a7ac1ce9 100644 --- a/client/starwhale/utils/process.py +++ b/client/starwhale/utils/process.py @@ -1,6 +1,5 @@ import os import typing as t -from select import select from subprocess import PIPE, Popen, STDOUT, CalledProcessError from loguru import logger @@ -12,24 +11,27 @@ def log_check_call(*args: t.Any, **kwargs: t.Any) -> int: kwargs["stderr"] = STDOUT env = os.environ.copy() env.update(kwargs.get("env", {})) + env["PYTHONUNBUFFERED"] = "1" kwargs["env"] = env kwargs["universal_newlines"] = True - env["PYTHONUNBUFFERED"] = "1" output = [] p = Popen(*args, **kwargs) - log(f"cmd: {p.args!r}") + logger.debug(f"cmd: {p.args!r}") + + def _print_log() -> None: + line = p.stdout.readline() # type: ignore + if line: + log(line.rstrip()) + output.append(line) + while True: - fds, _, _ = select([p.stdout], [], [], 30) # timeout 30s - for fd in fds: - for line in fd.readlines(): - log(line.rstrip()) - output.append(line) - else: - if p.poll() is not None: - break + _print_log() + if p.poll() is not None: + break p.wait() + _print_log() try: p.stdout.close() # type: ignore diff --git a/client/tests/utils/test_process.py b/client/tests/utils/test_process.py index d3cdbba89d..62be9ed3de 100644 --- a/client/tests/utils/test_process.py +++ b/client/tests/utils/test_process.py @@ -16,9 +16,9 @@ def _log(s: t.Any) -> None: log=_log, ) - assert len(save_logs) >= 2 + assert len(save_logs) >= 1 with self.assertRaises(FileNotFoundError): log_check_call(["err"]) - assert len(save_logs) >= 2 + assert len(save_logs) >= 1