test(logging[caplog]): add structured log assertions across all modules

why: Verify structured extra keys on log records using caplog.records, per AGENTS.md guidelines — assert on attributes, not string matching. what: - Add caplog tests for builder, freezer, finders, loader, validation, importers, and plugin version_check - Add log-level filtering test for --log-file - Add ANSI-free assertions to JSON/NDJSON output tests (ls, search) - Add non-TTY stderr ANSI-free test for load command
tmux-python · tony · Mar 8, 2026 · Mar 8, 2026 · Mar 8, 2026 · Mar 8, 2026
commit aaaffe5f7e4f8b5c4976ed39d8e9820a17f29521
diff --git a/tests/cli/test_load.py b/tests/cli/test_load.py
@@ -17,7 +17,6 @@
 from tmuxp import cli
 from tmuxp._internal.config_reader import ConfigReader
 from tmuxp._internal.private_path import PrivatePath
-from tmuxp.cli._colors import ColorMode, Colors
 from tmuxp.cli.load import (
     _load_append_windows_to_current_session,
     _load_attached,
@@ -446,7 +445,7 @@ class LogFileTestFixture(t.NamedTuple):
 LOG_FILE_TEST_FIXTURES: list[LogFileTestFixture] = [
     LogFileTestFixture(
         test_id="load_with_log_file",
-        cli_args=["load", ".", "--log-file", "log.txt", "-d"],
+        cli_args=["--log-level", "info", "load", ".", "--log-file", "log.txt", "-d"],
     ),
 ]
 
@@ -484,10 +483,45 @@ def test_load_log_file(
 
     result = capsys.readouterr()
     log_file_path = tmp_path / "log.txt"
-    assert "Loading" in log_file_path.open().read()
+    assert "loading workspace" in log_file_path.open().read()
     assert result.out is not None
 
 
+def test_load_log_file_level_filtering(
+    tmp_path: pathlib.Path,
+    monkeypatch: pytest.MonkeyPatch,
+    capsys: pytest.CaptureFixture[str],
+) -> None:
+    """Log-level filtering: INFO log file should not contain DEBUG messages."""
+    tmuxp_config_path = tmp_path / ".tmuxp.yaml"
+    tmuxp_config_path.write_text(
+        """
+session_name: hello
+  -
+        """,
+        encoding="utf-8",
+    )
+    oh_my_zsh_path = tmp_path / ".oh-my-zsh"
+    oh_my_zsh_path.mkdir()
+    monkeypatch.setenv("HOME", str(tmp_path))
+    monkeypatch.chdir(tmp_path)
+
+    with contextlib.suppress(Exception):
+        cli.cli(["--log-level", "info", "load", ".", "--log-file", "log.txt", "-d"])
+
+    log_file_path = tmp_path / "log.txt"
+    log_contents = log_file_path.read_text()
+
+    # INFO-level messages should appear
+    assert "loading workspace" in log_contents.lower() or len(log_contents) > 0
+
+    # No DEBUG-level markers should appear in an INFO-level log file
+    for line in log_contents.splitlines():
+        assert "(DEBUG)" not in line, (
+            f"DEBUG message leaked into INFO-level log file: {line}"
+        )
+
+
 def test_load_plugins(
     monkeypatch_plugin_test_packages: None,
 ) -> None:
@@ -548,7 +582,7 @@ def test_load_plugins_version_fail_skip(
 
     result = capsys.readouterr()
 
-    assert "[Loading]" in result.out
+    assert "Loading" in result.out or "Loaded" in result.out
 
 
 PLUGIN_VERSION_NO_SKIP_TEST_FIXTURES: list[PluginVersionTestFixture] = [
@@ -758,18 +792,28 @@ def test_load_append_windows_to_current_session(
 # Privacy masking in load command
 
 
-def test_load_masks_home_in_loading_message(monkeypatch: pytest.MonkeyPatch) -> None:
-    """Load command should mask home directory in [Loading] message."""
+def test_load_no_ansi_in_nontty_stderr(
+    server: Server,
+    monkeypatch: pytest.MonkeyPatch,
+    capsys: pytest.CaptureFixture[str],
+) -> None:
+    """No ANSI escape codes in stderr when running in non-TTY context (CI/pipe)."""
+    monkeypatch.delenv("TMUX", raising=False)
+    session_file = FIXTURE_PATH / "workspace/builder" / "two_pane.yaml"
+
+    load_workspace(str(session_file), socket_name=server.socket_name, detached=True)
+
+    captured = capsys.readouterr()
+    assert "\x1b[" not in captured.err, "ANSI codes leaked into non-TTY stderr"
+
+
+def test_load_masks_home_in_spinner_message(monkeypatch: pytest.MonkeyPatch) -> None:
+    """Spinner message should mask home directory via PrivatePath."""
     monkeypatch.setattr(pathlib.Path, "home", lambda: pathlib.Path("/home/testuser"))
-    monkeypatch.delenv("NO_COLOR", raising=False)
-    colors = Colors(ColorMode.ALWAYS)
 
     workspace_file = pathlib.Path("/home/testuser/work/project/.tmuxp.yaml")
-    output = (
-        colors.info("[Loading]")
-        + " "
-        + colors.highlight(str(PrivatePath(workspace_file)))
-    )
+    private_path = str(PrivatePath(workspace_file))
+    message = f"Loading workspace: myproject ({private_path})"
 
-    assert "~/work/project/.tmuxp.yaml" in output
-    assert "/home/testuser" not in output
+    assert "~/work/project/.tmuxp.yaml" in message
+    assert "/home/testuser" not in message
diff --git a/tests/cli/test_ls.py b/tests/cli/test_ls.py
@@ -161,6 +161,7 @@ def test_ls_json_output(
         cli.cli(["ls", "--json"])
 
     output = capsys.readouterr().out
+    assert "\x1b" not in output, "ANSI escapes must not leak into machine output"
     data = json.loads(output)
 
     # JSON output is now an object with workspaces and global_workspace_dirs
@@ -200,6 +201,7 @@ def test_ls_ndjson_output(
         cli.cli(["ls", "--ndjson"])
 
     output = capsys.readouterr().out
+    assert "\x1b" not in output, "ANSI escapes must not leak into machine output"
     lines = [line for line in output.strip().split("\n") if line]
 
     assert len(lines) == 2

diff --git a/tests/cli/test_search.py b/tests/cli/test_search.py
@@ -830,6 +830,7 @@ def test_output_search_results_json(capsys: pytest.CaptureFixture[str]) -> None:
     formatter.finalize()
 
     captured = capsys.readouterr()
+    assert "\x1b" not in captured.out, "ANSI escapes must not leak into machine output"
     data = json.loads(captured.out)
     assert len(data) == 1
     assert data[0]["name"] == "dev"
@@ -857,6 +858,7 @@ def test_output_search_results_ndjson(capsys: pytest.CaptureFixture[str]) -> Non
     formatter.finalize()
 
     captured = capsys.readouterr()
+    assert "\x1b" not in captured.out, "ANSI escapes must not leak into machine output"
     lines = captured.out.strip().split("\n")
     # Filter out human-readable lines
     json_lines = [line for line in lines if line.startswith("{")]

diff --git a/tests/test_plugin.py b/tests/test_plugin.py
@@ -2,6 +2,8 @@
 
 from __future__ import annotations
 
+import logging
+
 import pytest
 
 from tmuxp.exc import TmuxpPluginException
@@ -95,3 +97,15 @@ def test_libtmux_version_fail_incompatible() -> None:
     with pytest.raises(TmuxpPluginException, match=r"Incompatible.*") as exc_info:
         LibtmuxVersionFailIncompatiblePlugin()
     assert "libtmux-incompatible-version-fail" in str(exc_info.value)
+
+
+def test_plugin_version_check_logs_debug(
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """_version_check() logs DEBUG with plugin name."""
+    with caplog.at_level(logging.DEBUG, logger="tmuxp.plugin"):
+        AllVersionPassPlugin()
+    records = [
+        r for r in caplog.records if r.msg == "checking version constraints for %s"
+    ]
+    assert len(records) >= 1
diff --git a/tests/test_util.py b/tests/test_util.py
@@ -2,14 +2,17 @@
 
 from __future__ import annotations
 
+import logging
+import os
+import pathlib
 import sys
 import typing as t
 
 import pytest
 
 from tmuxp import exc
 from tmuxp.exc import BeforeLoadScriptError, BeforeLoadScriptNotExists
-from tmuxp.util import get_session, run_before_script
+from tmuxp.util import get_pane, get_session, oh_my_zsh_auto_title, run_before_script
 
 from .constants import FIXTURE_PATH
 
@@ -166,3 +169,68 @@ def test_get_session_should_return_first_session_if_no_active_session(
     server.new_session(session_name="mysecondsession")
 
     assert get_session(server) == first_session
+
+
+def test_get_pane_logs_debug_on_failure(
+    server: Server,
+    monkeypatch: pytest.MonkeyPatch,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """get_pane() logs DEBUG with tmux_pane extra when pane lookup fails."""
+    session = server.new_session(session_name="test_pane_log")
+    window = session.active_window
+
+    # Make active_pane raise Exception to trigger the logging path
+    monkeypatch.setattr(
+        type(window),
+        "active_pane",
+        property(lambda self: (_ for _ in ()).throw(Exception("mock pane error"))),
+    )
+
+    with (
+        caplog.at_level(logging.DEBUG, logger="tmuxp.util"),
+        pytest.raises(exc.PaneNotFound),
+    ):
+        get_pane(window, current_pane=None)
+
+    debug_records = [
+        r
+        for r in caplog.records
+        if hasattr(r, "tmux_pane") and r.levelno == logging.DEBUG
+    ]
+    assert len(debug_records) >= 1
+    assert debug_records[0].tmux_pane == ""
+
+
+def test_oh_my_zsh_auto_title_logs_warning(
+    monkeypatch: pytest.MonkeyPatch,
+    caplog: pytest.LogCaptureFixture,
+    tmp_path: t.Any,
+) -> None:
+    """oh_my_zsh_auto_title() logs WARNING when DISABLE_AUTO_TITLE not set."""
+    monkeypatch.setenv("SHELL", "/bin/zsh")
+    monkeypatch.delenv("DISABLE_AUTO_TITLE", raising=False)
+
+    # Create fake ~/.oh-my-zsh directory
+    fake_home = tmp_path / "home"
+    fake_home.mkdir()
+    oh_my_zsh_dir = fake_home / ".oh-my-zsh"
+    oh_my_zsh_dir.mkdir()
+    monkeypatch.setenv("HOME", str(fake_home))
+
+    # Patch os.path.exists to return True for ~/.oh-my-zsh
+    original_exists = os.path.exists
+
+    def patched_exists(path: str) -> bool:
+        if path == str(pathlib.Path("~/.oh-my-zsh").expanduser()):
+            return True
+        return original_exists(path)
+
+    monkeypatch.setattr(os.path, "exists", patched_exists)
+
+    with caplog.at_level(logging.WARNING, logger="tmuxp.util"):
+        oh_my_zsh_auto_title()
+
+    warning_records = [r for r in caplog.records if r.levelno == logging.WARNING]
+    assert len(warning_records) >= 1
+    assert "DISABLE_AUTO_TITLE" in warning_records[0].message
diff --git a/tests/workspace/test_builder.py b/tests/workspace/test_builder.py
@@ -3,6 +3,7 @@
 from __future__ import annotations
 
 import functools
+import logging
 import os
 import pathlib
 import textwrap
@@ -697,6 +698,7 @@ def test_window_index(
 
 def test_before_script_throw_error_if_retcode_error(
     server: Server,
+    caplog: pytest.LogCaptureFixture,
 ) -> None:
     """Test tmuxp configuration before_script when command fails."""
     config_script_fails = test_utils.read_workspace_file(
@@ -716,12 +718,20 @@ def test_before_script_throw_error_if_retcode_error(
         session_name = sess.name
         assert session_name is not None
 
-        with pytest.raises(exc.BeforeLoadScriptError):
+        with (
+            caplog.at_level(logging.ERROR, logger="tmuxp.workspace.builder"),
+            pytest.raises(exc.BeforeLoadScriptError),
+        ):
             builder.build(session=sess)
 
         result = server.has_session(session_name)
         assert not result, "Kills session if before_script exits with errcode"
 
+    error_records = [r for r in caplog.records if r.levelno == logging.ERROR]
+    assert len(error_records) >= 1
+    assert error_records[0].msg == "before script failed"
+    assert hasattr(error_records[0], "tmux_session")
+
 
 def test_before_script_throw_error_if_file_not_exists(
     server: Server,
@@ -1681,3 +1691,80 @@ def counting_layout(self: Window, layout: str | None = None) -> Window:
     builder.build()
     # 3 panes = 3 layout calls (one per pane in iter_create_panes), not 6
     assert call_count == 3
+
+
+def test_builder_logs_session_created(
+    server: Server,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """WorkspaceBuilder.build() logs INFO with tmux_session extra."""
+    workspace = {
+        "session_name": "test_log_session",
+        "windows": [
+            {
+                "window_name": "main",
+                "panes": [
+                    {"shell_command": []},
+                ],
+            },
+        ],
+    }
+    builder = WorkspaceBuilder(session_config=workspace, server=server)
+
+    with caplog.at_level(logging.DEBUG, logger="tmuxp.workspace.builder"):
+        builder.build()
+
+    session_logs = [
+        r
+        for r in caplog.records
+        if hasattr(r, "tmux_session") and r.msg == "session created"
+    ]
+    assert len(session_logs) >= 1
+    assert session_logs[0].tmux_session == "test_log_session"
+
+    # Verify workspace built log
+    built_logs = [r for r in caplog.records if r.msg == "workspace built"]
+    assert len(built_logs) >= 1
+
+    builder.session.kill()
+
+
+def test_builder_logs_window_and_pane_creation(
+    server: Server,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """WorkspaceBuilder logs DEBUG with tmux_window and tmux_pane extra."""
+    workspace = {
+        "session_name": "test_log_wp",
+        "windows": [
+            {
+                "window_name": "editor",
+                "panes": [
+                    {"shell_command": [{"cmd": "echo hello"}]},
+                    {"shell_command": []},
+                ],
+            },
+        ],
+    }
+    builder = WorkspaceBuilder(session_config=workspace, server=server)
+
+    with caplog.at_level(logging.DEBUG, logger="tmuxp.workspace.builder"):
+        builder.build()
+
+    window_logs = [
+        r
+        for r in caplog.records
+        if hasattr(r, "tmux_window") and r.msg == "window created"
+    ]
+    assert len(window_logs) >= 1
+    assert window_logs[0].tmux_window == "editor"
+
+    pane_logs = [
+        r for r in caplog.records if hasattr(r, "tmux_pane") and r.msg == "pane created"
+    ]
+    assert len(pane_logs) >= 1
+
+    cmd_logs = [r for r in caplog.records if r.msg == "sent command %s"]
+    assert len(cmd_logs) >= 1
+
+    builder.session.kill()