[CLI] Write logs, errors and warnings to stderr

mkdocs/docs/reference/env.md

@@ -202,7 +202,7 @@ The following environment variables are supported by the CLI.
   dstack ps
   ```
 
-- `DSTACK_CLI_LOG_LEVEL`{ #DSTACK_CLI_LOG_LEVEL } – Sets the logging level for CLI output to stdout. Defaults to `INFO`.
+- `DSTACK_CLI_LOG_LEVEL`{ #DSTACK_CLI_LOG_LEVEL } – Sets the logging level for CLI output to stderr. Defaults to `INFO`.
 
 Example:
 

src/dstack/_internal/cli/commands/fleet.py

@@ -11,6 +11,7 @@
     LIVE_TABLE_REFRESH_RATE_PER_SEC,
     confirm_ask,
     console,
+    error_console,
 )
 from dstack._internal.cli.utils.fleet import get_fleets_table, print_fleets_table
 from dstack._internal.core.errors import CLIError, ResourceNotExistsError
@@ -172,7 +173,7 @@ def _get(self, args: argparse.Namespace):
                     name=args.name.name,
                 )
         except ResourceNotExistsError:
-            console.print(f"Fleet [code]{args.name or args.id}[/] not found")
+            error_console.print(f"Fleet [code]{args.name or args.id}[/] not found")
             exit(1)
 
         print(fleet.model_dump_json(indent=2))

src/dstack/_internal/cli/commands/preset.py

@@ -267,7 +267,7 @@ def _list(self, args: argparse.Namespace) -> None:
             )
             return
         # The store warns about unreadable presets on stderr once per read;
-        # inside Live that would tear the render on every refresh. The first
+        # inside Live that would repeat them on every refresh. The first
         # read happens before Live starts so warnings print once, above the
         # table; refreshes read with stderr suppressed.
         presets, sessions = self._list_presets_and_sessions(base=base, repo=repo)
@@ -303,10 +303,7 @@ def _list_presets_and_sessions(
         return presets, sessions
 
     def _create(self, args: argparse.Namespace) -> None:
-        warn(
-            "`dstack preset create` is deprecated; use `dstack apply -f <configuration>`",
-            stderr=True,
-        )
+        warn("`dstack preset create` is deprecated; use `dstack apply -f <configuration>`")
         _check_stdin_configuration_confirmable(args)
         _, configuration = _read_configuration_arg(args.configuration_file)
         # A thin adapter over the configurator, the same path `dstack apply` takes.
@@ -399,7 +396,7 @@ def _delete(self, args: argparse.Namespace) -> None:
                 preset = store.find_by_id_or_name(args.preset)
             except CLIError as e:
                 # A corrupt preset file must still be removable by ID.
-                warn(str(e), stderr=True)
+                warn(str(e))
                 preset_ids = [args.preset]
                 description = f"preset [code]{args.preset}[/]"
             else:

src/dstack/_internal/cli/commands/run.py

@@ -3,7 +3,7 @@
 
 from dstack._internal.cli.commands import APIBaseCommand
 from dstack._internal.cli.services.completion import RunNameCompleter
-from dstack._internal.cli.utils.common import console
+from dstack._internal.cli.utils.common import error_console
 from dstack._internal.core.errors import CLIError, ResourceNotExistsError
 
 
@@ -62,7 +62,7 @@ def _get(self, args: argparse.Namespace):
             else:
                 run = self.api.client.runs.get(project_name=self.api.project, run_name=args.name)
         except ResourceNotExistsError:
-            console.print(f"Run [code]{args.name or args.id}[/] not found")
+            error_console.print(f"Run [code]{args.name or args.id}[/] not found")
             exit(1)
 
         print(run.model_dump_json(indent=2))

src/dstack/_internal/cli/commands/volume.py

@@ -10,6 +10,7 @@
     LIVE_TABLE_REFRESH_RATE_PER_SEC,
     confirm_ask,
     console,
+    error_console,
 )
 from dstack._internal.cli.utils.volume import get_volumes_table, print_volumes_table
 from dstack._internal.core.errors import ResourceNotExistsError
@@ -110,7 +111,7 @@ def _get(self, args: argparse.Namespace):
         try:
             volume = self.api.client.volumes.get(project_name=self.api.project, name=args.name)
         except ResourceNotExistsError:
-            console.print("Volume not found")
+            error_console.print("Volume not found")
             exit(1)
 
         print(volume.model_dump_json(indent=2))

src/dstack/_internal/cli/main.py

@@ -26,7 +26,7 @@
 from dstack._internal.cli.commands.server import ServerCommand
 from dstack._internal.cli.commands.stop import StopCommand
 from dstack._internal.cli.commands.volume import VolumeCommand
-from dstack._internal.cli.utils.common import _colors, console
+from dstack._internal.cli.utils.common import _colors, error_console
 from dstack._internal.cli.utils.updates import check_for_updates
 from dstack._internal.core.errors import ClientError, CLIError, ConfigurationError, SSHError
 from dstack._internal.core.services.ssh.client import get_ssh_client_info
@@ -98,7 +98,7 @@ def main():
         get_ssh_client_info()
         args.func(args)
     except (ClientError, CLIError, ConfigurationError, SSHError) as e:
-        console.print(f"[error]{escape(str(e))}[/]")
+        error_console.print(f"[error]{escape(str(e))}[/]")
         logger.debug(e, exc_info=True)
         exit(1)
 

src/dstack/_internal/cli/services/presets/session.py

@@ -26,7 +26,7 @@
     PresetSessionStatus,
     PresetSessionWorkspace,
 )
-from dstack._internal.cli.utils.common import console
+from dstack._internal.cli.utils.common import console, error_console
 from dstack._internal.compat import IS_WINDOWS
 from dstack._internal.core.errors import CLIError
 from dstack._internal.core.models.common import validate_extra_ignore, validate_json_extra_ignore
@@ -142,7 +142,7 @@ def append_log(self, line: str) -> None:
         except OSError as e:
             self._log_enabled = False
             if self.echo:
-                console.print(f"[warning]Could not write agent log {self.log_path}: {e}[/]")
+                error_console.print(f"[warning]Could not write agent log {self.log_path}: {e}[/]")
 
     def read_state(self) -> Optional[PresetSessionState]:
         """None marks a session with no readable state: never created, or corrupt."""

src/dstack/_internal/cli/services/presets/store.py

@@ -48,21 +48,19 @@ def list(self) -> list[AnyStoredPreset]:
                 earlier_version_ids.append(path.parent.name)
             except CLIError as e:
                 # One corrupt file must not take down every read; the preset
-                # stays deletable by ID. stderr keeps `--json` output parseable.
-                warn(str(e), stderr=True)
+                # stays deletable by ID.
+                warn(str(e))
         if len(earlier_version_ids) == 1:
             warn(
                 f"Preset {earlier_version_ids[0]} was created before dstack 0.21 and cannot"
                 f" be read. Delete it with"
-                f" [code]dstack preset delete {earlier_version_ids[0]}[/], or recreate.",
-                stderr=True,
+                f" [code]dstack preset delete {earlier_version_ids[0]}[/], or recreate."
             )
         elif earlier_version_ids:
             warn(
                 f"{len(earlier_version_ids)} presets created before dstack 0.21 cannot be"
                 f" read: {', '.join(sorted(earlier_version_ids))}."
-                f" Delete them with [code]dstack preset delete <id>[/], or recreate.",
-                stderr=True,
+                f" Delete them with [code]dstack preset delete <id>[/], or recreate."
             )
         return sorted(presets, key=lambda preset: (preset.base.lower(), preset.id))
 

src/dstack/_internal/cli/services/presets/tail.py

@@ -14,7 +14,7 @@
     _write_private_text,
     print_preset_progress,
 )
-from dstack._internal.cli.utils.common import console
+from dstack._internal.cli.utils.common import error_console
 
 
 class FileLineReader:
@@ -193,7 +193,7 @@ def flush(self) -> None:
         except OSError as e:
             self._enabled = False
             if self._echo:
-                console.print(f"[warning]Could not mirror {self._target.name}: {e}[/]")
+                error_console.print(f"[warning]Could not mirror {self._target.name}: {e}[/]")
 
 
 class DirectoryMirror:
@@ -237,7 +237,7 @@ def flush(self) -> None:
             if stat.st_size > self._MAX_FILE_BYTES:
                 if self._echo and relative not in self._warned:
                     self._warned.add(relative)
-                    console.print(
+                    error_console.print(
                         f"[warning]Not mirroring {relative}: "
                         f"larger than {self._MAX_FILE_BYTES // (1024 * 1024)} MiB[/]"
                     )
@@ -253,7 +253,7 @@ def flush(self) -> None:
             except OSError as e:
                 if self._echo and relative not in self._warned:
                     self._warned.add(relative)
-                    console.print(f"[warning]Could not mirror {relative}: {e}[/]")
+                    error_console.print(f"[warning]Could not mirror {relative}: {e}[/]")
                 continue
             self._copied[relative] = signature
 

src/dstack/_internal/cli/utils/common.py

@@ -1,10 +1,13 @@
+import io
 import logging
+import sys
 from datetime import datetime, timezone
 from pathlib import Path
 from typing import Any, Optional
 
 import requests
 from rich.console import Console
+from rich.file_proxy import FileProxy
 from rich.prompt import Confirm
 from rich.table import Table
 from rich.theme import Theme
@@ -26,7 +29,38 @@
 
 console = Console(theme=Theme(_colors))
 
-error_console = Console(theme=Theme(_colors), stderr=True)
+
+class _LiveAwareStderr:
+    """
+    Resolves `sys.stderr` on each call. `Console(stderr=True)` unwraps the proxy that
+    `rich.live.Live` installs on `sys.stderr`, so its output would bypass an active
+    `console.status()` or live table and break the render.
+    """
+
+    @property
+    def encoding(self) -> str:
+        return getattr(sys.stderr, "encoding", None) or "utf-8"
+
+    def write(self, text: str) -> int:
+        return sys.stderr.write(text)
+
+    def flush(self) -> None:
+        sys.stderr.flush()
+
+    def isatty(self) -> bool:
+        return sys.stderr.isatty()
+
+    def fileno(self) -> int:
+        if isinstance(sys.stderr, FileProxy):
+            # Without a std stream fileno, rich on legacy Windows consoles renders ANSI
+            # in one write instead of a write and flush per styled segment, each of
+            # which `FileProxy` would print on a separate line.
+            raise io.UnsupportedOperation("fileno")
+        return sys.stderr.fileno()
+
+
+error_console = Console(theme=Theme(_colors), file=_LiveAwareStderr())  # type: ignore[arg-type]
+"""Logs, errors, and warnings. Keeps stdout for command output, e.g., `--json`."""
 
 
 LIVE_TABLE_REFRESH_RATE_PER_SEC = 1
@@ -77,10 +111,10 @@ def configure_logging():
     dstack_logger = logging.getLogger("dstack")
     dstack_logger.handlers.clear()
 
-    stdout_handler = DstackRichHandler(console=console)
-    stdout_handler.setFormatter(logging.Formatter(fmt="%(message)s", datefmt="[%X]"))
-    stdout_handler.setLevel(settings.CLI_LOG_LEVEL)
-    dstack_logger.addHandler(stdout_handler)
+    stderr_handler = DstackRichHandler(console=error_console)
+    stderr_handler.setFormatter(logging.Formatter(fmt="%(message)s", datefmt="[%X]"))
+    stderr_handler.setLevel(settings.CLI_LOG_LEVEL)
+    dstack_logger.addHandler(stderr_handler)
 
     log_file = get_dstack_dir() / "logs" / "cli" / "latest.log"
     try:
@@ -95,7 +129,9 @@ def configure_logging():
         file_handler.setLevel(settings.CLI_FILE_LOG_LEVEL)
         dstack_logger.addHandler(file_handler)
     except PermissionError:
-        console.print(f"[warning]Couldn't write to {log_file} due to a permissions problem.[/]")
+        error_console.print(
+            f"[warning]Couldn't write to {log_file} due to a permissions problem.[/]"
+        )
 
     # the logger allows all messages, filtering is done by the handlers
     dstack_logger.setLevel(logging.DEBUG)
@@ -118,12 +154,11 @@ def add_row_from_dict(table: Table, data: dict[str, Any], **kwargs):
     table.add_row(*row, **kwargs)
 
 
-def warn(message: str, stderr: bool = False):
-    """`stderr=True` keeps the warning off stdout, so `--json` output stays parseable."""
+def warn(message: str):
     if not message.endswith("\n"):
         # Additional blank line for better visibility if there are more than one warning
         message = f"{message}\n"
-    (error_console if stderr else console).print(f"[warning][bold]{message}[/]")
+    error_console.print(f"[warning][bold]{message}[/]")
 
 
 def get_start_time(since: Optional[str]) -> Optional[datetime]:

src/dstack/_internal/cli/utils/updates.py

@@ -7,7 +7,7 @@
 from packaging import version as pkg_version
 
 from dstack import version
-from dstack._internal.cli.utils.common import console
+from dstack._internal.cli.utils.common import error_console
 from dstack._internal.utils.logging import get_logger
 
 logger = get_logger(__name__)
@@ -73,7 +73,9 @@ def _check_version():
     latest_version = get_latest_version()
     if latest_version is not None:
         if is_update_available(version.__version__, latest_version):
-            console.print(f"A new version of dstack is available: [code]{latest_version}[/]\n")
+            error_console.print(
+                f"A new version of dstack is available: [code]{latest_version}[/]\n"
+            )
 
 
 def _update_last_check_time():

src/tests/_internal/cli/commands/test_dstack.py

@@ -1,3 +1,5 @@
+from pathlib import Path
+
 from pytest import CaptureFixture
 
 from tests._internal.cli.common import run_dstack_cli
@@ -8,3 +10,10 @@ def test_prints_help_and_exists_with_0_exit_code(self, capsys: CaptureFixture):
         exit_code = run_dstack_cli([])
         assert exit_code == 0
         assert capsys.readouterr().out.startswith("Usage: dstack [-h] [-v] COMMAND ...")
+
+    def test_prints_errors_to_stderr(self, tmp_path: Path, capsys: CaptureFixture):
+        exit_code = run_dstack_cli(["ps", "--nonsense"], home_dir=tmp_path)
+        assert exit_code == 1
+        captured = capsys.readouterr()
+        assert captured.out == ""
+        assert "Unrecognized arguments: --nonsense" in captured.err

src/tests/_internal/cli/commands/test_preset.py

@@ -129,7 +129,7 @@ def test_resume_refuses_a_session_with_a_saved_preset(self, tmp_path, capsys):
 
         assert exit_code == 1
         create.assert_not_called()
-        assert "already created; nothing to resume" in capsys.readouterr().out
+        assert "already created; nothing to resume" in capsys.readouterr().err
 
     def test_get_returns_the_requested_configuration_for_an_unfinished_preset(
         self, tmp_path, capsys
@@ -272,7 +272,7 @@ def test_refuses_to_delete_a_running_creation(self, tmp_path, capsys):
             exit_code = run_dstack_cli(["preset", "delete", "ab12cd34", "-y"], home_dir=tmp_path)
 
         assert exit_code != 0
-        assert "Preset creation is in use" in capsys.readouterr().out
+        assert "Preset creation is in use" in capsys.readouterr().err
         assert session_dir.exists()
 
     def test_refuses_to_delete_an_orphaned_creation_that_recorded_runs(self, tmp_path, capsys):
@@ -284,7 +284,7 @@ def test_refuses_to_delete_an_orphaned_creation_that_recorded_runs(self, tmp_pat
         exit_code = run_dstack_cli(["preset", "delete", "ab12cd34", "-y"], home_dir=tmp_path)
 
         assert exit_code != 0
-        assert "Preset creation was interrupted" in capsys.readouterr().out
+        assert "Preset creation was interrupted" in capsys.readouterr().err
         assert session_dir.exists()
 
     def test_deletes_an_orphaned_creation_without_runs(self, tmp_path):
@@ -609,7 +609,7 @@ def test_delete_of_an_unknown_qualified_ref_reports_it_does_not_exist(self, tmp_
         # A qualified ref never names a creation session, so the session
         # fallback must not turn this into a confusing error.
         assert exit_code != 0
-        assert "does not exist" in capsys.readouterr().out
+        assert "does not exist" in capsys.readouterr().err
         assert store.list() != []
 
     def test_create_always_asks_even_without_a_name_conflict(self, tmp_path):
@@ -674,7 +674,7 @@ def test_rejects_an_unqualified_ref(self, tmp_path, capsys, args):
         exit_code = run_dstack_cli(args, home_dir=tmp_path)
 
         assert exit_code != 0
-        assert "Invalid registry reference" in capsys.readouterr().out
+        assert "Invalid registry reference" in capsys.readouterr().err
 
 
 class TestApplyPresetConfiguration:

src/tests/_internal/cli/services/presets/test_agent.py

@@ -646,7 +646,7 @@ def test_log_write_failure_warns_once(self, tmp_path, capsys):
         session.append_log("first")
         session.append_log("second")
 
-        assert capsys.readouterr().out.count("Could not write agent log") == 1
+        assert capsys.readouterr().err.count("Could not write agent log") == 1
 
 
 class TestRedaction: