diff --git a/CHANGELOG.D/622.feature b/CHANGELOG.D/622.feature new file mode 100644 index 00000000..3f30ed94 --- /dev/null +++ b/CHANGELOG.D/622.feature @@ -0,0 +1,2 @@ +Enabled detailed automatic logging to file. For locally executed commands, logs will +go to `~/.neuro/logs` directory. Remote executor detailed logs will go to `storage:.flow/logs//`. diff --git a/neuro_flow/batch_runner.py b/neuro_flow/batch_runner.py index aad1c751..67e16435 100644 --- a/neuro_flow/batch_runner.py +++ b/neuro_flow/batch_runner.py @@ -471,6 +471,7 @@ async def _run_bake( run_args = [ "run", "--pass-config", + f"--volume=storage:.flow/logs/{bake.id}/:/root/.neuro/logs" f"--life-span={life_span}", f"--tag=project:{self.project_id}", f"--tag=flow:{bake.batch}", diff --git a/neuro_flow/cli/file_logging.py b/neuro_flow/cli/file_logging.py new file mode 100644 index 00000000..4f8241b9 --- /dev/null +++ b/neuro_flow/cli/file_logging.py @@ -0,0 +1,51 @@ +import logging +from datetime import datetime, timedelta, timezone +from pathlib import Path +from random import random +from typing import Optional + + +DATETIME_FORMAT = "%Y-%m-%d_%H-%M-%S" +LOGS_DIR = Path("~/.neuro/logs").expanduser() +FILE_FORMAT_PREFIX = "neuro-flow-run-" +LOGS_ROTATION_DELAY = timedelta(days=3) + + +def get_handler() -> logging.FileHandler: + if random() < 0.1: # Only do cleanup for 10% of runs + _do_rotation(LOGS_ROTATION_DELAY) + return _get_handler() + + +_file_path_cached: Optional[Path] = None + + +def get_log_file_path() -> Path: + global _file_path_cached + if _file_path_cached is None: + now = datetime.now(timezone.utc) + time_str = now.strftime(DATETIME_FORMAT) + _file_path_cached = LOGS_DIR / f"{FILE_FORMAT_PREFIX}{time_str}.txt" + return _file_path_cached + + +def _get_handler() -> logging.FileHandler: + LOGS_DIR.mkdir(parents=True, exist_ok=True) + return logging.FileHandler(get_log_file_path()) + + +def _do_rotation(delay: timedelta) -> None: + now = datetime.now(timezone.utc) + if not LOGS_DIR.exists(): + return + for log_file in LOGS_DIR.iterdir(): + if not log_file.is_file(): + continue + time_str = log_file.stem[len(FILE_FORMAT_PREFIX) :] + try: + log_time = datetime.strptime(time_str, DATETIME_FORMAT) + except ValueError: + continue + log_time = log_time.replace(tzinfo=timezone.utc) + if log_time + delay < now: + log_file.unlink() diff --git a/neuro_flow/cli/main.py b/neuro_flow/cli/main.py index dc2cc131..ea32577c 100644 --- a/neuro_flow/cli/main.py +++ b/neuro_flow/cli/main.py @@ -8,7 +8,7 @@ from typing import Any, List, Optional import neuro_flow -from neuro_flow.cli import batch, completion, images, live, storage +from neuro_flow.cli import batch, completion, file_logging, images, live, storage from neuro_flow.parser import ConfigDir, find_workspace from neuro_flow.types import LocalPath, TaskStatus @@ -24,14 +24,15 @@ def setup_logging(color: bool, verbosity: int, show_traceback: bool) -> None: root_logger = logging.getLogger() - handler = ConsoleHandler(color=color, show_traceback=show_traceback) - root_logger.addHandler(handler) + console_handler = ConsoleHandler(color=color, show_traceback=show_traceback) + file_handler = file_logging.get_handler() + root_logger.addHandler(console_handler) + root_logger.addHandler(file_handler) root_logger.setLevel(logging.DEBUG) - if verbosity <= 1: - formatter = logging.Formatter() - else: + if verbosity > 1: formatter = logging.Formatter("%(name)s.%(funcName)s: %(message)s") + console_handler.setFormatter(formatter) if verbosity < -1: loglevel = logging.CRITICAL @@ -44,8 +45,7 @@ def setup_logging(color: bool, verbosity: int, show_traceback: bool) -> None: else: loglevel = logging.DEBUG - handler.setFormatter(formatter) - handler.setLevel(loglevel) + console_handler.setLevel(loglevel) class MainGroup(click.Group): diff --git a/neuro_flow/cli/utils.py b/neuro_flow/cli/utils.py index ece5cfba..0420f3ca 100644 --- a/neuro_flow/cli/utils.py +++ b/neuro_flow/cli/utils.py @@ -29,7 +29,7 @@ def _runner() -> Iterator[Runner]: def wrap_async( - pass_obj: bool = True, + pass_obj: bool = True, init_client: bool = True ) -> Callable[[Callable[..., Awaitable[_T]]], Callable[..., _T]]: def _decorator(callback: Callable[..., Awaitable[_T]]) -> Callable[..., _T]: assert iscoroutinefunction(callback)