diff --git a/CHANGELOG.md b/CHANGELOG.md index 21bd003e..bf73dc0c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -50,6 +50,8 @@ the frozen-backend fallback mirror it for their toolchains. ### Fixed +- The Backend log tab keeps showing history across a log rollover, instead of going nearly empty until new lines arrive (#1782) +- Clearing the logs now empties the rotated log files too, so it frees the space it appears to (#1782) - Install documentation help now prints correctly on Windows consoles using legacy encodings (#1815) — thanks @dajiaohuang! - Saved transcriptions with missing or invalid timestamps now remain readable (#1799) — thanks @yunaremaia and @tvbht! - Copying a saved transcription now uses the shared clipboard helper and reports failed copies accurately (#1803) — thanks @tvbht! diff --git a/backend/api/routers/system.py b/backend/api/routers/system.py index aa5c0caf..aabdba25 100644 --- a/backend/api/routers/system.py +++ b/backend/api/routers/system.py @@ -297,6 +297,53 @@ def _tail_file(path: str, tail: int): return all_lines[-tail:], len(all_lines) +# Must track main.py's _WindowsSafeRotatingFileHandler(backupCount=3). The +# handler rolls omnivoice.log at 2 MB into .1/.2/.3, so up to 6 MB of history +# lives in files this module used to ignore entirely. +_LOG_BACKUP_COUNT = 3 + + +def _rotated_log_paths(base: str) -> list[str]: + """Existing `.1 … .N`, newest first.""" + return [p for p in (f"{base}.{i}" for i in range(1, _LOG_BACKUP_COUNT + 1)) if os.path.exists(p)] + + +def _tail_rolling(base: str, tail: int): + """Tail `base`, reaching into its rotated siblings when it runs short. + + A rollover leaves omnivoice.log nearly empty, and the Backend tab then + showed a handful of lines — or none — while the failure the user was asked + to copy sat in omnivoice.log.1. Reading the current file first keeps the + common case at one file read; the backups are only touched when they are + the only place the requested lines can come from. + + Returns (lines oldest-first, total lines across the files read, paths read + oldest-first). The total counts only the files it had to open — it stops as + soon as `tail` is satisfied, so it is "how much is behind these lines", + not the size of the whole rotation set. + """ + chunks: list[list[str]] = [] + paths: list[str] = [] + total = 0 + remaining = tail + candidates = [p for p in [base, *_rotated_log_paths(base)] if os.path.exists(p)] + for path in candidates: + if remaining <= 0: + break + lines, count = _tail_file(path, remaining) + if count == 0: + continue + chunks.append(lines) + paths.append(path) + total += count + remaining -= len(lines) + # Files were visited newest-first; the reader wants oldest-first. + out: list[str] = [] + for chunk in reversed(chunks): + out.extend(chunk) + return out, total, list(reversed(paths)) + + def _tauri_log_candidates(): """Likely paths for Tauri-side logs, most useful first. @@ -356,12 +403,24 @@ async def system_logs(tail: int = 200): except Exception: tail = 200 - path = LOG_PATH if os.path.exists(LOG_PATH) else CRASH_LOG_PATH - if not os.path.exists(path): + if os.path.exists(LOG_PATH) or _rotated_log_paths(LOG_PATH): + base = LOG_PATH + else: + base = CRASH_LOG_PATH + if not os.path.exists(base) and not _rotated_log_paths(base): return {"lines": [], "path": LOG_PATH, "exists": False} + path = base try: - lines, total = await asyncio.to_thread(_tail_file, path, tail) - return {"lines": lines, "path": path, "exists": True, "total_lines": total} + lines, total, paths = await asyncio.to_thread(_tail_rolling, base, tail) + return { + "lines": lines, + "path": path, + "exists": True, + "total_lines": total, + # Which files the tail actually came from, oldest first. A bug + # report can then say whether it crossed a rollover. + "paths": paths, + } except Exception as e: raise HTTPException( status_code=500, @@ -467,9 +526,15 @@ def _read_from_pos(path: str, pos: int) -> list[str]: @router.post("/system/logs/clear") async def clear_system_logs(): - """Truncate the rolling runtime log and the crash log (what the Backend tab reads).""" + """Truncate the rolling runtime log and the crash log (what the Backend tab reads). + + Includes the rotated siblings. Truncating only omnivoice.log left up to + 6 MB in .1/.2/.3, so Clear freed almost nothing and — now that the tail + reaches into those files — would have looked like it did nothing at all. + """ cleared_any = False - for p in (LOG_PATH, CRASH_LOG_PATH): + targets = [LOG_PATH, *_rotated_log_paths(LOG_PATH), CRASH_LOG_PATH] + for p in targets: if os.path.exists(p): try: await asyncio.to_thread(_truncate_file, p) diff --git a/tests/backend/api/routers/test_system_logs_rotation.py b/tests/backend/api/routers/test_system_logs_rotation.py new file mode 100644 index 00000000..02049c9f --- /dev/null +++ b/tests/backend/api/routers/test_system_logs_rotation.py @@ -0,0 +1,112 @@ +"""The Backend log tab must survive a log rollover. + +`main.py` attaches a `RotatingFileHandler(maxBytes=2MB, backupCount=3)`, so +`omnivoice.log` is rolled into `.1/.2/.3` and starts again from empty. The tail +endpoint read only the current file, so for the minutes after a rollover the +panel showed a handful of lines — or none — while up to 6 MB of history, the +failure included, sat in `omnivoice.log.1`. + +That matters more than a cosmetic gap: `.github/ISSUE_TEMPLATE` and the engine +guides both ask a reporter to paste "the backend log" from that panel, and +#1782 is a thread where three rounds went into an empty Logs panel. A rollover +is not the only way to get one, but it is one this endpoint can rule out. + +Measured before the fix, with 3 lines in the current file and 500 in each of +two backups: `tail=200` returned 3 lines and reported `total_lines: 3`. + +Clear is in the same file because the two are coupled — once the tail reaches +into the backups, a Clear that truncates only `omnivoice.log` looks like it did +nothing. +""" +from __future__ import annotations + +import asyncio +import os + +import pytest + + +@pytest.fixture +def system_mod(): + from api.routers import system + + return system + + +@pytest.fixture +def rolling(tmp_path, system_mod, monkeypatch): + """A rolled-over log set: 3 fresh lines, 500 + 500 in the backups.""" + base = tmp_path / "omnivoice.log" + base.write_text("".join(f"fresh {i}\n" for i in range(3)), encoding="utf-8") + (tmp_path / "omnivoice.log.1").write_text( + "".join(f"older {i}\n" for i in range(500)), encoding="utf-8" + ) + (tmp_path / "omnivoice.log.2").write_text( + "".join(f"oldest {i}\n" for i in range(500)), encoding="utf-8" + ) + monkeypatch.setattr(system_mod, "LOG_PATH", str(base)) + monkeypatch.setattr(system_mod, "CRASH_LOG_PATH", str(tmp_path / "crash_log.txt")) + return tmp_path + + +def test_tail_reaches_across_a_rollover(system_mod, rolling): + res = asyncio.run(system_mod.system_logs(tail=200)) + + assert len(res["lines"]) == 200 + # Oldest first, and the newest line is still the newest line on disk. + assert res["lines"][0].strip() == "older 303" + assert res["lines"][-1].strip() == "fresh 2" + # It crossed exactly one boundary and stopped there. + assert [os.path.basename(p) for p in res["paths"]] == ["omnivoice.log.1", "omnivoice.log"] + + +def test_the_common_case_still_reads_one_file(system_mod, tmp_path, monkeypatch): + """No rollover in play → the backups are not opened at all. + + The panel polls every 5s, so reaching into 6 MB of backups on every call + would be a poor trade for a case that only matters right after a roll. + """ + base = tmp_path / "omnivoice.log" + base.write_text("".join(f"line {i}\n" for i in range(500)), encoding="utf-8") + (tmp_path / "omnivoice.log.1").write_text("stale\n" * 500, encoding="utf-8") + monkeypatch.setattr(system_mod, "LOG_PATH", str(base)) + monkeypatch.setattr(system_mod, "CRASH_LOG_PATH", str(tmp_path / "crash_log.txt")) + + res = asyncio.run(system_mod.system_logs(tail=200)) + + assert [os.path.basename(p) for p in res["paths"]] == ["omnivoice.log"] + assert res["lines"][0].strip() == "line 300" + assert "stale" not in "".join(res["lines"]) + + +def test_a_backup_alone_is_still_a_log(system_mod, tmp_path, monkeypatch): + """The window between the roll and the first new line is not "no log".""" + base = tmp_path / "omnivoice.log" + (tmp_path / "omnivoice.log.1").write_text("only in the backup\n", encoding="utf-8") + monkeypatch.setattr(system_mod, "LOG_PATH", str(base)) + monkeypatch.setattr(system_mod, "CRASH_LOG_PATH", str(tmp_path / "crash_log.txt")) + assert not base.exists() + + res = asyncio.run(system_mod.system_logs(tail=200)) + + assert res["exists"] is True + assert [line.strip() for line in res["lines"]] == ["only in the backup"] + + +def test_no_log_at_all_still_reports_absent(system_mod, tmp_path, monkeypatch): + monkeypatch.setattr(system_mod, "LOG_PATH", str(tmp_path / "omnivoice.log")) + monkeypatch.setattr(system_mod, "CRASH_LOG_PATH", str(tmp_path / "crash_log.txt")) + + res = asyncio.run(system_mod.system_logs(tail=200)) + + assert res == {"lines": [], "path": str(tmp_path / "omnivoice.log"), "exists": False} + + +def test_clear_empties_the_backups_too(system_mod, rolling, monkeypatch): + monkeypatch.setattr(system_mod, "prefs_delete", lambda _key: None, raising=False) + + res = asyncio.run(system_mod.clear_system_logs()) + + assert res == {"cleared": True} + for name in ("omnivoice.log", "omnivoice.log.1", "omnivoice.log.2"): + assert (rolling / name).stat().st_size == 0, f"{name} survived Clear"