diff --git a/docs/docs/guides/troubleshooting.md b/docs/docs/guides/troubleshooting.md index 9ef8ea3849..6a46ec0730 100644 --- a/docs/docs/guides/troubleshooting.md +++ b/docs/docs/guides/troubleshooting.md @@ -14,8 +14,14 @@ If you have a question or need help, feel free to ask it in our [Discord server] Make sure to provide clear, detailed steps to reproduce the issue. Include server logs, CLI outputs, and configuration samples. Avoid using screenshots for logs or errors—use text instead. -To get more detailed logs, make sure to set the `DSTACK_CLI_LOG_LEVEL` and `DSTACK_SERVER_LOG_LEVEL` -environment variables to `debug` when running the CLI and the server, respectively. +#### Server logs + +To get more detailed server logs, set the `DSTACK_SERVER_LOG_LEVEL` +environment variable to `DEBUG`. By default, it is set to `INFO`. + +#### CLI logs + +CLI logs are located in `~/.dstack/logs/cli`, and the default log level is `DEBUG`. > See these examples for well-reported issues: [this :material-arrow-top-right-thin:{ .external }](https://github.com/dstackai/dstack/issues/1640){:target="_blank"} and [this :material-arrow-top-right-thin:{ .external }](https://github.com/dstackai/dstack/issues/1551){:target="_blank"}. diff --git a/docs/docs/reference/environment-variables.md b/docs/docs/reference/environment-variables.md index 3c28ba3339..2a690b85c5 100644 --- a/docs/docs/reference/environment-variables.md +++ b/docs/docs/reference/environment-variables.md @@ -145,7 +145,7 @@ For more details on the options below, refer to the [server deployment](../guide The following environment variables are supported by the CLI. -- `DSTACK_CLI_LOG_LEVEL`{ #DSTACK_CLI_LOG_LEVEL } – Configures CLI logging level. Defaults to `INFO`. +- `DSTACK_CLI_LOG_LEVEL`{ #DSTACK_CLI_LOG_LEVEL } – Sets the logging level for CLI output to stdout. Defaults to `INFO`. Example: @@ -157,4 +157,17 @@ $ DSTACK_CLI_LOG_LEVEL=debug dstack apply -f .dstack.yml +- `DSTACK_CLI_FILE_LOG_LEVEL`{ #DSTACK_CLI_FILE_LOG_LEVEL } – Sets the logging level for CLI log files. Defaults to `DEBUG`. + +
+ +```shell +$ find ~/.dstack/logs/cli/ + + ~/.dstack/logs/cli/latest.log + ~/.dstack/logs/cli/2025-07-31.log +``` + +
+ - `DSTACK_PROJECT`{ #DSTACK_PROJECT } – Has the same effect as `--project`. Defaults to `None`. diff --git a/src/dstack/_internal/cli/utils/common.py b/src/dstack/_internal/cli/utils/common.py index 1b5c7e3ac9..72911584a4 100644 --- a/src/dstack/_internal/cli/utils/common.py +++ b/src/dstack/_internal/cli/utils/common.py @@ -1,5 +1,7 @@ import logging import os +from datetime import datetime, timezone +from pathlib import Path from typing import Any, Dict, Union from rich.console import Console @@ -9,6 +11,7 @@ from dstack._internal.cli.utils.rich import DstackRichHandler from dstack._internal.core.errors import CLIError, DstackError +from dstack._internal.utils.common import get_dstack_dir _colors = { "secondary": "grey58", @@ -35,12 +38,59 @@ def cli_error(e: DstackError) -> CLIError: return CLIError(*e.args) +def _get_cli_log_file() -> Path: + """Get the CLI log file path, rotating the previous log if needed.""" + log_dir = get_dstack_dir() / "logs" / "cli" + log_file = log_dir / "latest.log" + + if log_file.exists(): + file_mtime = datetime.fromtimestamp(log_file.stat().st_mtime, tz=timezone.utc) + current_date = datetime.now(timezone.utc).date() + + if file_mtime.date() < current_date: + date_str = file_mtime.strftime("%Y-%m-%d") + rotated_file = log_dir / f"{date_str}.log" + + counter = 1 + while rotated_file.exists(): + rotated_file = log_dir / f"{date_str}-{counter}.log" + counter += 1 + + log_file.rename(rotated_file) + + log_dir.mkdir(parents=True, exist_ok=True) + return log_file + + def configure_logging(): dstack_logger = logging.getLogger("dstack") - dstack_logger.setLevel(os.getenv("DSTACK_CLI_LOG_LEVEL", "INFO").upper()) - handler = DstackRichHandler(console=console) - handler.setFormatter(logging.Formatter(fmt="%(message)s", datefmt="[%X]")) - dstack_logger.addHandler(handler) + dstack_logger.handlers.clear() + + log_file = _get_cli_log_file() + + level_names = logging.getLevelNamesMapping() + stdout_level_name = os.getenv("DSTACK_CLI_LOG_LEVEL", "INFO").upper() + stdout_level = level_names[stdout_level_name] + dstack_logger.setLevel(stdout_level) + + stdout_handler = DstackRichHandler(console=console) + stdout_handler.setFormatter(logging.Formatter(fmt="%(message)s", datefmt="[%X]")) + stdout_handler.setLevel(stdout_level) + dstack_logger.addHandler(stdout_handler) + + file_level_name = os.getenv("DSTACK_CLI_FILE_LOG_LEVEL", "DEBUG").upper() + file_level = level_names[file_level_name] + + file_handler = logging.FileHandler(log_file) + file_handler.setFormatter( + logging.Formatter( + fmt="%(asctime)s - %(name)s - %(levelname)s - %(message)s", datefmt="%Y-%m-%d %H:%M:%S" + ) + ) + file_handler.setLevel(file_level) + dstack_logger.addHandler(file_handler) + + dstack_logger.setLevel(min(stdout_level, file_level)) def confirm_ask(prompt, **kwargs) -> bool: diff --git a/src/dstack/api/server/__init__.py b/src/dstack/api/server/__init__.py index 5cba94f552..5608d90bba 100644 --- a/src/dstack/api/server/__init__.py +++ b/src/dstack/api/server/__init__.py @@ -173,7 +173,7 @@ def _request( raise ClientError( f"Unexpected error: status code {resp.status_code}" f" when requesting {resp.request.url}." - " Check server logs or run with DSTACK_CLI_LOG_LEVEL=DEBUG to see more details" + " Check the server logs for backend issues, and the CLI logs at (~/.dstack/logs/cli/latest.log) local CLI output" ) return resp diff --git a/src/tests/_internal/cli/utils/test_common.py b/src/tests/_internal/cli/utils/test_common.py new file mode 100644 index 0000000000..d439b9e7fa --- /dev/null +++ b/src/tests/_internal/cli/utils/test_common.py @@ -0,0 +1,103 @@ +import os +from datetime import datetime, timedelta, timezone +from pathlib import Path +from typing import Generator +from unittest.mock import patch + +import pytest + +from dstack._internal.cli.utils.common import _get_cli_log_file + + +@pytest.fixture +def mock_dstack_dir(tmp_path: Path) -> Generator[Path, None, None]: + with patch("dstack._internal.cli.utils.common.get_dstack_dir") as mock: + mock.return_value = tmp_path + yield tmp_path + + +class TestGetCliLogFile: + def test_no_existing_dir(self, mock_dstack_dir: Path): + log_dir = mock_dstack_dir / "logs" / "cli" + expected_log_file = log_dir / "latest.log" + assert not log_dir.exists() + + result = _get_cli_log_file() + + assert log_dir.exists() + assert result == expected_log_file + + def test_no_rotation_needed_for_today_file(self, mock_dstack_dir: Path): + log_dir = mock_dstack_dir / "logs" / "cli" + log_dir.mkdir(parents=True, exist_ok=True) + latest_log = log_dir / "latest.log" + latest_log.touch() + + result = _get_cli_log_file() + + assert result == latest_log + assert latest_log.exists(), "latest.log should not have been renamed" + + @patch("dstack._internal.cli.utils.common.datetime") + def test_simple_rotation(self, mock_datetime, mock_dstack_dir: Path): + # Mock "now" to be a specific date + now = datetime(2023, 10, 27, 10, 0, 0, tzinfo=timezone.utc) + mock_datetime.now.return_value = now + # Ensure fromtimestamp still works correctly for the System Under Test + mock_datetime.fromtimestamp.side_effect = lambda ts, tz: datetime.fromtimestamp(ts, tz) + + log_dir = mock_dstack_dir / "logs" / "cli" + log_dir.mkdir(parents=True, exist_ok=True) + latest_log = log_dir / "latest.log" + latest_log.touch() + + # Set the modification time to yesterday + yesterday = now - timedelta(days=1) + mtime = yesterday.timestamp() + os.utime(latest_log, (mtime, mtime)) + + # The expected rotated file name is based on the modification time (yesterday) + date_str = yesterday.strftime("%Y-%m-%d") + expected_rotated_log = log_dir / f"{date_str}.log" + + result = _get_cli_log_file() + + assert result == log_dir / "latest.log" + assert not latest_log.exists(), "The original latest.log should have been renamed" + assert expected_rotated_log.exists(), "The log file should have been rotated" + + @patch("dstack._internal.cli.utils.common.datetime") + def test_rotation_with_conflict(self, mock_datetime, mock_dstack_dir: Path): + now = datetime(2023, 10, 27, 10, 0, 0, tzinfo=timezone.utc) + yesterday = now - timedelta(days=1) + mock_datetime.now.return_value = now + mock_datetime.fromtimestamp.side_effect = lambda ts, tz: datetime.fromtimestamp(ts, tz) + + log_dir = mock_dstack_dir / "logs" / "cli" + log_dir.mkdir(parents=True, exist_ok=True) + + # Create the old 'latest.log' and set its modification time to yesterday + latest_log = log_dir / "latest.log" + latest_log.touch() + mtime = yesterday.timestamp() + os.utime(latest_log, (mtime, mtime)) + + # Create conflicting files that already exist from a previous rotation + date_str = yesterday.strftime("%Y-%m-%d") + conflicting_log_1 = log_dir / f"{date_str}.log" + conflicting_log_1.touch() + conflicting_log_2 = log_dir / f"{date_str}-1.log" + conflicting_log_2.touch() + + # We expect the file to be rotated to the next available counter + expected_rotated_log = log_dir / f"{date_str}-2.log" + + result = _get_cli_log_file() + + assert result == log_dir / "latest.log" + assert not latest_log.exists(), "The original latest.log should have been renamed" + assert conflicting_log_1.exists(), "Existing rotated log should be untouched" + assert conflicting_log_2.exists(), "Existing rotated log with counter should be untouched" + assert expected_rotated_log.exists(), ( + "The log should have rotated to the next available counter" + )