From 48866782c02ef21caa205e5cf38e47c84df0f601 Mon Sep 17 00:00:00 2001 From: NoHudd <86909140+NoHudd@users.noreply.github.com> Date: Tue, 29 Sep 2026 16:53:57 -0500 Subject: [PATCH] fix: debug logging stays out of the terminal; fresh log every launch debug_log wrote every line to debug.log and also printed it to stderr. Lines printed while the world loaded sat behind the game screen, and they (plus the teardown lines) were left in the terminal when the player quit. The log panel (L) already shows them from the file, so debug_log now writes the file only. main.py already emptied debug.log on each launch (keeping the previous session as combat.log), but only after the game modules were imported, and some of them log while importing, so each session lost its first lines. rotate_logs() now runs before those imports and uses the configured DEBUG_LOG_FILE instead of a hard-coded name. Co-Authored-By: Claude Opus 5.5 --- main.py | 37 +++++++++++++++-------------- tests/test_logging.py | 54 +++++++++++++++++++++++++++++++++++++++++++ utils/debug_tools.py | 10 ++++---- 3 files changed, 77 insertions(+), 24 deletions(-) create mode 100644 tests/test_logging.py diff --git a/main.py b/main.py index 9ed1f2b..e9cc120 100644 --- a/main.py +++ b/main.py @@ -3,29 +3,28 @@ import shutil # Content, saves, logs and user settings are all addressed relative to the -# repo, and some are opened at import time, so this runs before any game import. +# repo, and some are opened at import time, so this runs before anything else. os.chdir(os.path.dirname(os.path.abspath(__file__))) -from src.game_engine import main # noqa: E402 -from src.ui.textual_ui import TextualGameUI # noqa: E402 composition root: the frontend is chosen HERE -if __name__ == "__main__": - # Create necessary directories if they don't exist - os.makedirs("data/rooms", exist_ok=True) - os.makedirs("data/items", exist_ok=True) - os.makedirs("data/enemies", exist_ok=True) - os.makedirs("data/npcs", exist_ok=True) - - # Copy debug.log to combat.log on each restart (overwrites old combat.log) - if os.path.exists("debug.log"): - shutil.copy2("debug.log", "combat.log") - # Clear debug.log for fresh logging this session - with open("debug.log", "w") as f: - f.write("") +def rotate_logs(log_file: str, previous: str = "combat.log") -> None: + """Start the session with an empty log; keep the last session's as `previous`.""" + if os.path.exists(log_file): + shutil.copy2(log_file, previous) else: - # Create empty combat.log if debug.log doesn't exist - with open("combat.log", "w") as f: + with open(previous, "w") as f: f.write("=== Combat Log (Fresh Session) ===\n") + open(log_file, "w").close() + + +if __name__ == "__main__": + from config.dev_config import DEBUG_LOG_FILE + + # Before the game modules load: some of them log while importing. + rotate_logs(DEBUG_LOG_FILE) + + from src.game_engine import main + from src.ui.textual_ui import TextualGameUI # composition root: the frontend is chosen HERE # Run the game — build the concrete frontend and inject it into the backend. - main(TextualGameUI()) \ No newline at end of file + main(TextualGameUI()) diff --git a/tests/test_logging.py b/tests/test_logging.py new file mode 100644 index 0000000..825ce6a --- /dev/null +++ b/tests/test_logging.py @@ -0,0 +1,54 @@ +"""Debug logging goes to the log file only, and each launch starts a fresh one. + +debug_log used to echo every line to the terminal as well. Lines printed while +the world loaded sat behind the game screen and reappeared in the terminal when +the player quit; the log panel (L) already shows them from the file. +""" +from __future__ import annotations + +from pathlib import Path + +import pytest + +import main +import utils.debug_tools as debug_tools + + +def test_debug_log_writes_the_file_not_the_terminal( + tmp_path: Path, monkeypatch: pytest.MonkeyPatch, capsys: pytest.CaptureFixture[str], +) -> None: + log = tmp_path / "debug.log" + monkeypatch.setattr(debug_tools, "DEBUG_MODE", True) + monkeypatch.setattr(debug_tools, "DEBUG_LOG_FILE", str(log)) + + debug_tools.debug_log("world loaded", "system") + + captured = capsys.readouterr() + assert captured.out == "" and captured.err == "" + assert "world loaded" in log.read_text() + + +def test_each_launch_starts_an_empty_log_and_keeps_the_last_one(tmp_path: Path) -> None: + log, previous = tmp_path / "debug.log", tmp_path / "combat.log" + log.write_text("last session\n") + + main.rotate_logs(str(log), str(previous)) + + assert log.read_text() == "" + assert previous.read_text() == "last session\n" + + +def test_first_launch_creates_both_files(tmp_path: Path) -> None: + log, previous = tmp_path / "debug.log", tmp_path / "combat.log" + + main.rotate_logs(str(log), str(previous)) + + assert log.read_text() == "" + assert previous.exists() + + +def test_logs_rotate_before_the_game_modules_load() -> None: + """Some modules log while importing (the combat system's attack table); + rotating after the imports erased those lines from the new session.""" + source = Path(main.__file__).read_text() + assert source.index("rotate_logs(") < source.index("from src.") diff --git a/utils/debug_tools.py b/utils/debug_tools.py index 95ba993..33c8523 100644 --- a/utils/debug_tools.py +++ b/utils/debug_tools.py @@ -27,7 +27,11 @@ def debug_log(message: object, category: str = "system") -> None: """ - Log a debug message to the debug log file and console if DEBUG_MODE is True. + Log a debug message to the debug log file if DEBUG_MODE is True. + + File only: the game screen owns the terminal, and anything printed there + is left behind in the player's scrollback when they quit. The log panel + (L) shows the file. Args: message (str): The message to log @@ -52,10 +56,6 @@ def debug_log(message: object, category: str = "system") -> None: # Format the log message log_message = f"[{timestamp}] [{category.upper()}] [{filename}:{function_name}:{line_number}] {message}" - # Print to console - print(log_message, file=sys.stderr) - - # Write to log file try: with open(DEBUG_LOG_FILE, "a") as f: f.write(log_message + "\n")