fix(logs): delete and download only rotated copies under one rule
Rule R (#329): a file is a rotated copy only when it is a direct entry of the log folder named prompt_manager.log.<n> (n >= 1, no leading zero, compared after normcase) and a regular file that is not a symlink or a junction. Everything else is never deleted. - Clear (POST /logs/truncate) empties the active log and deletes only rotated copies; a .bak, a .1.gz, any other file and every link are kept. It runs off the event loop under one files lock and the file handler's lock, so no rollover renames a file mid-way, and logs only afterwards. - delete_rotated(expected) deletes exactly the reviewed copies, or nothing when one of them changed (size, mtime_ns, inode, missing, now a link). - The download serves only a listed regular, non-link file, opened without following links and read off the loop; a link or folder is a 404. - /logs/files rows gain kind; files and stats read links with lstat and stats no longer count a link's target. - The config update runs off the loop and swaps handlers under the files lock.
This commit is contained in:
Vito Sansevero
@@ -1,6 +1,13 @@
|
||||
"""Logging API routes for PromptManager."""
|
||||
"""Logging API routes for PromptManager.
|
||||
|
||||
Every route that names a log file goes through Rule R (#329,
|
||||
``utils/logging_config.py``): a download is served only for a regular,
|
||||
non-link file listed directly in the log folder, and Clear deletes only
|
||||
rotated copies. File work runs off the event loop.
|
||||
"""
|
||||
|
||||
import os
|
||||
import stat
|
||||
|
||||
from aiohttp import web
|
||||
|
||||
@@ -85,6 +92,31 @@ def _validate_log_config(data):
|
||||
return clean, None
|
||||
|
||||
|
||||
def _read_log_bytes(path):
|
||||
"""The whole file at ``path``, opened without following a link (blocking).
|
||||
|
||||
The file is checked again through the open handle (a regular file), so a
|
||||
name swapped for a link after it was listed is refused as missing. The
|
||||
handle is closed before this returns.
|
||||
"""
|
||||
flags = os.O_RDONLY | getattr(os, "O_BINARY", 0) | getattr(os, "O_NOFOLLOW", 0)
|
||||
try:
|
||||
fd = os.open(str(path), flags)
|
||||
except OSError as error:
|
||||
if getattr(os, "O_NOFOLLOW", 0) and os.path.islink(str(path)):
|
||||
raise FileNotFoundError("Log file not found") from error
|
||||
raise
|
||||
with os.fdopen(fd, "rb") as handle:
|
||||
if not stat.S_ISREG(os.fstat(handle.fileno()).st_mode):
|
||||
raise FileNotFoundError("Log file not found")
|
||||
return handle.read()
|
||||
|
||||
|
||||
def _download(logger_manager, filename):
|
||||
"""``bytes`` of a downloadable log file; FileNotFoundError otherwise."""
|
||||
return _read_log_bytes(logger_manager.log_file_entry(filename))
|
||||
|
||||
|
||||
class LoggingRoutesMixin:
|
||||
"""Mixin providing logging-related API endpoints."""
|
||||
|
||||
@@ -195,16 +227,16 @@ class LoggingRoutesMixin:
|
||||
{"success": False, "error": "Invalid filename"}, status=400
|
||||
)
|
||||
|
||||
log_file_path = logger_manager.log_dir / filename
|
||||
|
||||
if not log_file_path.exists():
|
||||
try:
|
||||
file_content = await self._run_in_executor(
|
||||
_download, logger_manager, filename
|
||||
)
|
||||
except FileNotFoundError:
|
||||
# Missing, a link, a folder or not listed: all read as absent.
|
||||
return web.json_response(
|
||||
{"success": False, "error": "Log file not found"}, status=404
|
||||
)
|
||||
|
||||
with open(log_file_path, "rb") as f:
|
||||
file_content = f.read()
|
||||
|
||||
return web.Response(
|
||||
body=file_content,
|
||||
content_type="text/plain",
|
||||
@@ -224,7 +256,7 @@ class LoggingRoutesMixin:
|
||||
"""Truncate all log files."""
|
||||
try:
|
||||
logger_manager = self._get_logger_manager()
|
||||
results = logger_manager.truncate_logs()
|
||||
results = await self._run_in_executor(logger_manager.truncate_logs)
|
||||
|
||||
return web.json_response(
|
||||
{
|
||||
@@ -266,7 +298,7 @@ class LoggingRoutesMixin:
|
||||
return web.json_response({"success": False, "error": error}, status=400)
|
||||
|
||||
logger_manager = self._get_logger_manager()
|
||||
logger_manager.update_config(clean)
|
||||
await self._run_in_executor(logger_manager.update_config, clean)
|
||||
|
||||
return web.json_response(
|
||||
{
|
||||
|
||||
+144
-11
@@ -5,9 +5,10 @@ import os
|
||||
import shutil
|
||||
import sys
|
||||
import tempfile
|
||||
import threading
|
||||
import unittest
|
||||
from pathlib import Path
|
||||
from unittest.mock import MagicMock
|
||||
from unittest.mock import MagicMock, patch
|
||||
|
||||
_mock_server = MagicMock()
|
||||
_mock_server.PromptServer.instance.routes = MagicMock()
|
||||
@@ -20,7 +21,9 @@ from aiohttp.test_utils import AioHTTPTestCase # noqa: E402
|
||||
|
||||
from database.operations import PromptDatabase # noqa: E402
|
||||
from py.api import PromptManagerAPI # noqa: E402
|
||||
from py.api import logging_routes # noqa: E402
|
||||
from py.api.logging_routes import LOG_CONFIG_KEYS # noqa: E402
|
||||
from utils import logging_config # noqa: E402
|
||||
|
||||
|
||||
class FakeLoggerManager:
|
||||
@@ -38,11 +41,16 @@ class FakeLoggerManager:
|
||||
}
|
||||
self.update_calls = []
|
||||
self.logs = []
|
||||
self.threads = {}
|
||||
|
||||
def update_config(self, new_config):
|
||||
self.threads["update_config"] = threading.current_thread()
|
||||
self.update_calls.append(dict(new_config))
|
||||
self.config.update(new_config)
|
||||
|
||||
def log_file_entry(self, name):
|
||||
return logging_config.log_file_entry(self.log_dir, name)
|
||||
|
||||
def get_config(self):
|
||||
return dict(self.config)
|
||||
|
||||
@@ -54,23 +62,36 @@ class FakeLoggerManager:
|
||||
|
||||
def get_log_files(self):
|
||||
files = []
|
||||
for path in sorted(self.log_dir.glob("*.log*")):
|
||||
for row in sorted(
|
||||
logging_config.scan_log_folder(self.log_dir), key=lambda r: r["name"]
|
||||
):
|
||||
if row["_dir"]:
|
||||
continue
|
||||
files.append(
|
||||
{
|
||||
"filename": path.name,
|
||||
"path": str(path),
|
||||
"size": path.stat().st_size,
|
||||
"filename": row["name"],
|
||||
"path": str(self.log_dir / row["name"]),
|
||||
"size": row["size"],
|
||||
"modified": "2026-10-07T00:00:00",
|
||||
"is_main": path.name == "prompt_manager.log",
|
||||
"is_main": row["kind"] == "active",
|
||||
"kind": row["kind"],
|
||||
}
|
||||
)
|
||||
return files
|
||||
|
||||
def truncate_logs(self):
|
||||
"""Rule R: empty the active log, delete rotated copies, keep the rest."""
|
||||
self.threads["truncate_logs"] = threading.current_thread()
|
||||
truncated = []
|
||||
for path in self.log_dir.glob("prompt_manager.log*"):
|
||||
path.write_text("")
|
||||
truncated.append(path.name)
|
||||
for row in logging_config.scan_log_folder(self.log_dir):
|
||||
path = self.log_dir / row["name"]
|
||||
if row["kind"] == "active":
|
||||
path.write_text("")
|
||||
elif row["kind"] == "rotated":
|
||||
path.unlink()
|
||||
else:
|
||||
continue
|
||||
truncated.append(row["name"])
|
||||
return {"truncated": truncated, "errors": []}
|
||||
|
||||
def get_log_stats(self):
|
||||
@@ -378,12 +399,90 @@ class TestLogFilesAndDownload(LoggingAPITestCase):
|
||||
self.assertEqual(resp.status, 400)
|
||||
|
||||
async def test_download_read_failure_is_500(self):
|
||||
(self.log_dir / "dir.log").mkdir()
|
||||
resp = await self.client.request("GET", "/prompt_manager/logs/download/dir.log")
|
||||
# Rewritten (#329): a directory is now a 404; inject a read error.
|
||||
(self.log_dir / "prompt_manager.log").write_bytes(b"x")
|
||||
secret = os.path.join(self.tmpdir, "logs", "prompt_manager.log")
|
||||
|
||||
def fail(path):
|
||||
raise PermissionError(13, "Permission denied", secret)
|
||||
|
||||
with patch.object(logging_routes, "_read_log_bytes", fail):
|
||||
resp = await self.client.request(
|
||||
"GET", "/prompt_manager/logs/download/prompt_manager.log"
|
||||
)
|
||||
body = await resp.text()
|
||||
self.assertEqual(resp.status, 500)
|
||||
self.assertNotIn(self.tmpdir, body)
|
||||
|
||||
async def test_directory_download_is_404(self):
|
||||
(self.log_dir / "dir.log").mkdir()
|
||||
resp = await self.client.request("GET", "/prompt_manager/logs/download/dir.log")
|
||||
self.assertEqual(resp.status, 404)
|
||||
|
||||
async def test_download_refuses_a_symlink(self):
|
||||
secret = Path(self.tmpdir) / "secret.txt"
|
||||
secret.write_text("the key")
|
||||
try:
|
||||
os.symlink(secret, self.log_dir / "prompt_manager.log.3")
|
||||
except (OSError, NotImplementedError): # pragma: no cover
|
||||
self.skipTest("this account cannot create symlinks")
|
||||
resp = await self.client.request(
|
||||
"GET", "/prompt_manager/logs/download/prompt_manager.log.3"
|
||||
)
|
||||
body = await resp.text()
|
||||
self.assertEqual(resp.status, 404)
|
||||
self.assertNotIn("the key", body)
|
||||
|
||||
async def test_download_reads_off_the_loop(self):
|
||||
(self.log_dir / "prompt_manager.log").write_bytes(b"line\n")
|
||||
seen = []
|
||||
real = logging_routes._read_log_bytes
|
||||
|
||||
def read(path):
|
||||
seen.append(threading.current_thread())
|
||||
return real(path)
|
||||
|
||||
with patch.object(logging_routes, "_read_log_bytes", read):
|
||||
resp = await self.client.request(
|
||||
"GET", "/prompt_manager/logs/download/prompt_manager.log"
|
||||
)
|
||||
self.assertEqual(resp.status, 200)
|
||||
self.assertEqual(len(seen), 1)
|
||||
self.assertIsNot(seen[0], threading.current_thread())
|
||||
|
||||
async def test_download_keeps_its_response_shape(self):
|
||||
(self.log_dir / "prompt_manager.log.2").write_bytes(b"a\nb\n")
|
||||
resp = await self.client.request(
|
||||
"GET", "/prompt_manager/logs/download/prompt_manager.log.2"
|
||||
)
|
||||
self.assertEqual(resp.status, 200)
|
||||
self.assertEqual(resp.content_type, "text/plain")
|
||||
self.assertEqual(
|
||||
resp.headers["Content-Disposition"],
|
||||
'attachment; filename="prompt_manager.log.2"',
|
||||
)
|
||||
self.assertEqual(resp.headers["Content-Length"], "4")
|
||||
self.assertEqual(await resp.read(), b"a\nb\n")
|
||||
|
||||
async def test_log_files_rows_carry_their_kind(self):
|
||||
for name in (
|
||||
"prompt_manager.log",
|
||||
"prompt_manager.log.1",
|
||||
"prompt_manager.log.bak",
|
||||
):
|
||||
(self.log_dir / name).write_text("x")
|
||||
resp = await self.client.request("GET", "/prompt_manager/logs/files")
|
||||
data = await resp.json()
|
||||
kinds = {row["filename"]: row["kind"] for row in data["files"]}
|
||||
self.assertEqual(
|
||||
kinds,
|
||||
{
|
||||
"prompt_manager.log": "active",
|
||||
"prompt_manager.log.1": "rotated",
|
||||
"prompt_manager.log.bak": "other",
|
||||
},
|
||||
)
|
||||
|
||||
|
||||
class TestTruncateConfigAndStats(LoggingAPITestCase):
|
||||
|
||||
@@ -395,6 +494,40 @@ class TestTruncateConfigAndStats(LoggingAPITestCase):
|
||||
self.assertEqual(data["results"]["truncated"], ["prompt_manager.log"])
|
||||
self.assertEqual((self.log_dir / "prompt_manager.log").read_text(), "")
|
||||
|
||||
async def test_truncate_keeps_other_files(self):
|
||||
for name in (
|
||||
"prompt_manager.log",
|
||||
"prompt_manager.log.1",
|
||||
"prompt_manager.log.bak",
|
||||
):
|
||||
(self.log_dir / name).write_text("data")
|
||||
resp = await self.client.request("POST", "/prompt_manager/logs/truncate")
|
||||
data = await resp.json()
|
||||
self.assertEqual(resp.status, 200)
|
||||
self.assertEqual(set(data), {"success", "message", "results"})
|
||||
self.assertEqual(
|
||||
sorted(data["results"]["truncated"]),
|
||||
["prompt_manager.log", "prompt_manager.log.1"],
|
||||
)
|
||||
self.assertEqual(
|
||||
sorted(p.name for p in self.log_dir.iterdir()),
|
||||
["prompt_manager.log", "prompt_manager.log.bak"],
|
||||
)
|
||||
|
||||
async def test_truncate_runs_off_the_loop(self):
|
||||
resp = await self.client.request("POST", "/prompt_manager/logs/truncate")
|
||||
self.assertEqual(resp.status, 200)
|
||||
self.assertIsNot(
|
||||
self.manager.threads["truncate_logs"], threading.current_thread()
|
||||
)
|
||||
|
||||
async def test_update_config_runs_off_the_loop(self):
|
||||
resp = await self._post_config({"level": "DEBUG"})
|
||||
self.assertEqual(resp.status, 200)
|
||||
self.assertIsNot(
|
||||
self.manager.threads["update_config"], threading.current_thread()
|
||||
)
|
||||
|
||||
async def test_truncate_failure_is_500(self):
|
||||
def boom():
|
||||
raise RuntimeError("locked")
|
||||
|
||||
@@ -1,6 +1,7 @@
|
||||
"""PromptManagerLogger: memory buffer, file rotation, level changes, truncation."""
|
||||
|
||||
import logging
|
||||
import ntpath
|
||||
import os
|
||||
import pathlib
|
||||
import sys
|
||||
@@ -11,14 +12,20 @@ import unittest.mock as mock
|
||||
|
||||
sys.path.insert(0, os.path.dirname(os.path.dirname(os.path.abspath(__file__))))
|
||||
|
||||
from utils import logging_config
|
||||
from utils.logging_config import (
|
||||
from utils import logging_config # noqa: E402
|
||||
from utils.logging_config import ( # noqa: E402
|
||||
MemoryBufferHandler,
|
||||
PromptManagerLogger,
|
||||
RotatedChanged,
|
||||
get_logger,
|
||||
get_logger_manager,
|
||||
)
|
||||
|
||||
try:
|
||||
from tests.open_handles import assert_closed # noqa: E402
|
||||
except ImportError: # discovered with tests/ as the top-level directory
|
||||
from open_handles import assert_closed # noqa: E402
|
||||
|
||||
|
||||
class IsolatedLoggerTestCase(unittest.TestCase):
|
||||
"""A logger manager whose log directory is a temporary folder."""
|
||||
@@ -32,6 +39,7 @@ class IsolatedLoggerTestCase(unittest.TestCase):
|
||||
with mock.patch.object(logging_config, "__file__", fake_file):
|
||||
self.manager = object.__new__(PromptManagerLogger) # bypass singleton
|
||||
self.manager.__init__()
|
||||
self.allowed_thread_names = set()
|
||||
self.manager.update_config({"console_logging": False})
|
||||
# Drop the "Updated logging configuration" entry.
|
||||
self.manager._log_buffer.clear()
|
||||
@@ -53,12 +61,21 @@ class IsolatedLoggerTestCase(unittest.TestCase):
|
||||
|
||||
def _filter_to_this_thread(self):
|
||||
this_thread = threading.get_ident()
|
||||
# A test may let named helper threads of its own through too.
|
||||
allowed_names = self.allowed_thread_names
|
||||
|
||||
def allowed(record):
|
||||
return record.thread == this_thread or record.threadName in allowed_names
|
||||
|
||||
for handler in self.manager.logger.handlers:
|
||||
handler.addFilter(lambda record: record.thread == this_thread)
|
||||
handler.filters.clear()
|
||||
handler.addFilter(allowed)
|
||||
|
||||
def _restore_global_logging(self):
|
||||
for handler in logging.getLogger("prompt_manager").handlers[:]:
|
||||
handler.close()
|
||||
# Windows refuses to delete an open log: prove every handle is closed.
|
||||
assert_closed(self, self.tmp.name)
|
||||
get_logger_manager()._setup_loggers()
|
||||
self.tmp.cleanup()
|
||||
|
||||
@@ -175,15 +192,14 @@ class TestFilesAndRotation(IsolatedLoggerTestCase):
|
||||
|
||||
def test_unreadable_files_are_skipped_in_the_listing(self):
|
||||
self.logger.info("something")
|
||||
original_stat = pathlib.Path.stat
|
||||
original_lstat = os.lstat
|
||||
|
||||
def stat_failing_for_logs(path, *args, **kwargs):
|
||||
if path.suffix == ".log":
|
||||
def lstat_failing_for_logs(path, *args, **kwargs):
|
||||
if str(path).endswith(".log"):
|
||||
raise OSError("denied")
|
||||
return original_stat(path, *args, **kwargs)
|
||||
return original_lstat(path, *args, **kwargs)
|
||||
|
||||
with mock.patch.object(pathlib.Path, "stat", autospec=True) as stat:
|
||||
stat.side_effect = stat_failing_for_logs
|
||||
with mock.patch.object(logging_config.os, "lstat", lstat_failing_for_logs):
|
||||
self.assertEqual(self.manager.get_log_files(), [])
|
||||
|
||||
def test_truncate_does_not_roll_the_log_over_while_deleting_backups(self):
|
||||
@@ -228,10 +244,477 @@ class TestFilesAndRotation(IsolatedLoggerTestCase):
|
||||
|
||||
def test_truncate_reports_files_it_cannot_remove(self):
|
||||
self._rotate()
|
||||
with mock.patch.object(pathlib.Path, "unlink", side_effect=OSError("busy")):
|
||||
|
||||
def busy(path, *args, **kwargs):
|
||||
raise PermissionError(13, "busy", str(path))
|
||||
|
||||
with mock.patch.object(logging_config.os, "unlink", busy):
|
||||
result = self.manager.truncate_logs()
|
||||
self.assertEqual(len(result["errors"]), 2)
|
||||
self.assertEqual(result["truncated"], ["prompt_manager.log"])
|
||||
for error in result["errors"]:
|
||||
self.assertNotIn(self.tmp.name, error)
|
||||
self.assertRegex(error, r"prompt_manager\.log\.[12]")
|
||||
|
||||
|
||||
class TestRotatedCopyRule(IsolatedLoggerTestCase):
|
||||
"""Rule R (#329): only prompt_manager.log.<n> regular files are deletable."""
|
||||
|
||||
def setUp(self):
|
||||
super().setUp()
|
||||
self.logger.info("active log line") # the active log exists
|
||||
self.outside = os.path.join(self.tmp.name, "outside")
|
||||
os.makedirs(self.outside)
|
||||
|
||||
def _path(self, name):
|
||||
return os.path.join(self.log_dir, name)
|
||||
|
||||
def _write(self, name, data=b"rotated\n"):
|
||||
with open(self._path(name), "wb") as handle:
|
||||
handle.write(data)
|
||||
return self._path(name)
|
||||
|
||||
def _symlink(self, name, target_name="secret.txt", data=b"secret " * 1000):
|
||||
"""A symlink in the log folder to a file outside it, or None."""
|
||||
target = os.path.join(self.outside, target_name)
|
||||
with open(target, "wb") as handle:
|
||||
handle.write(data)
|
||||
try:
|
||||
os.symlink(target, self._path(name))
|
||||
except (OSError, NotImplementedError): # pragma: no cover - no privilege
|
||||
return None
|
||||
return target
|
||||
|
||||
def _require_symlink(self, name, **kwargs):
|
||||
target = self._symlink(name, **kwargs)
|
||||
if target is None: # pragma: no cover - Windows without the privilege
|
||||
self.skipTest("this account cannot create symlinks")
|
||||
return target
|
||||
|
||||
def _kinds(self):
|
||||
return {row["name"]: row["kind"] for row in self.manager.scan_log_folder()}
|
||||
|
||||
def _rotated_rows(self):
|
||||
return [r for r in self.manager.scan_log_folder() if r["kind"] == "rotated"]
|
||||
|
||||
def _names(self):
|
||||
return sorted(os.listdir(self.log_dir))
|
||||
|
||||
def _file_handler(self):
|
||||
return next(
|
||||
h
|
||||
for h in self.manager.logger.handlers
|
||||
if isinstance(h, logging.FileHandler)
|
||||
)
|
||||
|
||||
def test_scan_classes_rotated_active_link_and_other(self):
|
||||
for name in ("prompt_manager.log.1", "prompt_manager.log.2"):
|
||||
self._write(name)
|
||||
self._write("prompt_manager.log.3", b"x" * 3000)
|
||||
for name in (
|
||||
"prompt_manager.log.0",
|
||||
"prompt_manager.log.01",
|
||||
"prompt_manager.log.bak",
|
||||
"prompt_manager.log.1.gz",
|
||||
"prompt_manager.log.-1",
|
||||
"notes.txt",
|
||||
):
|
||||
self._write(name)
|
||||
os.makedirs(self._path("prompt_manager.log.5"))
|
||||
self._require_symlink("prompt_manager.log.4")
|
||||
kinds = self._kinds()
|
||||
self.assertEqual(
|
||||
kinds,
|
||||
{
|
||||
"prompt_manager.log": "active",
|
||||
"prompt_manager.log.1": "rotated",
|
||||
"prompt_manager.log.2": "rotated",
|
||||
"prompt_manager.log.3": "rotated",
|
||||
"prompt_manager.log.0": "other",
|
||||
"prompt_manager.log.01": "other",
|
||||
"prompt_manager.log.bak": "other",
|
||||
"prompt_manager.log.1.gz": "other",
|
||||
"prompt_manager.log.-1": "other",
|
||||
"notes.txt": "other",
|
||||
"prompt_manager.log.5": "other",
|
||||
"prompt_manager.log.4": "link",
|
||||
},
|
||||
)
|
||||
row = next(
|
||||
r
|
||||
for r in self.manager.scan_log_folder()
|
||||
if r["name"] == "prompt_manager.log.3"
|
||||
)
|
||||
self.assertEqual(
|
||||
set(row), {"name", "kind", "size", "mtime_ns", "ino", "modified"}
|
||||
)
|
||||
stat = os.lstat(self._path("prompt_manager.log.3"))
|
||||
self.assertEqual(row["size"], 3000)
|
||||
self.assertEqual(row["mtime_ns"], stat.st_mtime_ns)
|
||||
self.assertEqual(row["ino"], stat.st_ino)
|
||||
|
||||
def test_scan_matches_names_case_insensitively_on_windows(self):
|
||||
self._write("PROMPT_MANAGER.LOG.2")
|
||||
if os.name == "nt": # pragma: no cover - native case folding
|
||||
self.assertEqual(self._kinds()["PROMPT_MANAGER.LOG.2"], "rotated")
|
||||
return
|
||||
# POSIX names are case-sensitive: another file, never deleted.
|
||||
self.assertEqual(self._kinds()["PROMPT_MANAGER.LOG.2"], "other")
|
||||
with mock.patch.object(logging_config, "_name_key", ntpath.normcase):
|
||||
self.assertEqual(self._kinds()["PROMPT_MANAGER.LOG.2"], "rotated")
|
||||
result = self.manager.delete_rotated(self._rotated_rows())
|
||||
self.assertEqual(result["removed"], ["PROMPT_MANAGER.LOG.2"])
|
||||
|
||||
def test_a_junction_is_classed_as_a_link_and_kept(self):
|
||||
# Portable control: whatever os.path.isjunction reports is a link.
|
||||
self._write("prompt_manager.log.4")
|
||||
self._write("prompt_manager.log.1")
|
||||
junction = self._path("prompt_manager.log.4")
|
||||
real_isjunction = os.path.isjunction
|
||||
|
||||
def isjunction(path):
|
||||
return os.fspath(path) == junction or real_isjunction(path)
|
||||
|
||||
with mock.patch.object(logging_config.os.path, "isjunction", isjunction):
|
||||
self.assertEqual(self._kinds()["prompt_manager.log.4"], "link")
|
||||
self.manager.delete_rotated(self._rotated_rows())
|
||||
self.manager.truncate_logs()
|
||||
self.assertIn("prompt_manager.log.4", self._names())
|
||||
self.assertNotIn("prompt_manager.log.1", self._names())
|
||||
|
||||
@unittest.skipUnless(os.name == "nt", "junctions exist only on Windows")
|
||||
def test_junction_is_never_deleted_on_windows(self): # pragma: no cover
|
||||
import _winapi
|
||||
|
||||
target = os.path.join(self.outside, "kept")
|
||||
os.makedirs(target)
|
||||
with open(os.path.join(target, "inside.txt"), "wb") as handle:
|
||||
handle.write(b"keep me")
|
||||
_winapi.CreateJunction(target, self._path("prompt_manager.log.4"))
|
||||
self._write("prompt_manager.log.1")
|
||||
self.assertEqual(self._kinds()["prompt_manager.log.4"], "link")
|
||||
self.manager.delete_rotated(self._rotated_rows())
|
||||
self.manager.truncate_logs()
|
||||
self.assertIn("prompt_manager.log.4", self._names())
|
||||
self.assertTrue(os.path.exists(os.path.join(target, "inside.txt")))
|
||||
with self.assertRaises(FileNotFoundError):
|
||||
self.manager.log_file_entry("prompt_manager.log.4")
|
||||
os.rmdir(self._path("prompt_manager.log.4")) # removes the junction only
|
||||
|
||||
def test_delete_rotated_removes_exactly_the_listed_files(self):
|
||||
for n in (1, 2, 3):
|
||||
self._write(f"prompt_manager.log.{n}", b"r" * n)
|
||||
self._write("prompt_manager.log.bak")
|
||||
os.makedirs(self._path("prompt_manager.log.7"))
|
||||
target = self._symlink("prompt_manager.log.4")
|
||||
listed = [
|
||||
r for r in self._rotated_rows() if r["name"] != "prompt_manager.log.3"
|
||||
]
|
||||
result = self.manager.delete_rotated(listed)
|
||||
self.assertEqual(
|
||||
result,
|
||||
{"removed": ["prompt_manager.log.1", "prompt_manager.log.2"], "failed": []},
|
||||
)
|
||||
expected = [
|
||||
"prompt_manager.log",
|
||||
"prompt_manager.log.3",
|
||||
"prompt_manager.log.7",
|
||||
"prompt_manager.log.bak",
|
||||
]
|
||||
if target is not None:
|
||||
expected.append("prompt_manager.log.4")
|
||||
self.assertTrue(os.path.exists(target))
|
||||
self.assertEqual(self._names(), sorted(expected))
|
||||
|
||||
def test_delete_rotated_refuses_all_when_one_changed(self):
|
||||
def change_size(path):
|
||||
with open(path, "ab") as handle:
|
||||
handle.write(b"more")
|
||||
|
||||
def change_mtime(path):
|
||||
stat = os.lstat(path)
|
||||
os.utime(path, ns=(stat.st_atime_ns, stat.st_mtime_ns + 5_000_000_000))
|
||||
|
||||
def change_inode(path):
|
||||
stat = os.lstat(path)
|
||||
with open(path, "rb") as handle:
|
||||
data = handle.read()
|
||||
other = path + ".new"
|
||||
with open(other, "wb") as handle:
|
||||
handle.write(data)
|
||||
os.utime(other, ns=(stat.st_atime_ns, stat.st_mtime_ns))
|
||||
os.replace(other, path)
|
||||
if os.lstat(path).st_ino in (0, stat.st_ino): # pragma: no cover
|
||||
self.skipTest("this filesystem reports no inode numbers")
|
||||
|
||||
def remove(path):
|
||||
os.unlink(path)
|
||||
|
||||
def replace_by_link(path):
|
||||
os.unlink(path)
|
||||
target = os.path.join(self.outside, "elsewhere.txt")
|
||||
with open(target, "wb") as handle:
|
||||
handle.write(b"rotated\n")
|
||||
try:
|
||||
os.symlink(target, path)
|
||||
except (OSError, NotImplementedError): # pragma: no cover
|
||||
self.skipTest("this account cannot create symlinks")
|
||||
|
||||
changes = {
|
||||
"size": change_size,
|
||||
"mtime": change_mtime,
|
||||
"inode": change_inode,
|
||||
"missing": remove,
|
||||
"link": replace_by_link,
|
||||
}
|
||||
for label, change in changes.items():
|
||||
with self.subTest(change=label):
|
||||
for n in (1, 2, 3):
|
||||
self._write(f"prompt_manager.log.{n}", b"rotated\n")
|
||||
reviewed = self._rotated_rows()
|
||||
change(self._path("prompt_manager.log.2"))
|
||||
before = self._names()
|
||||
with self.assertRaises(RotatedChanged):
|
||||
self.manager.delete_rotated(reviewed)
|
||||
self.assertEqual(self._names(), before)
|
||||
self.assertIn("prompt_manager.log.1", before)
|
||||
self.assertIn("prompt_manager.log.3", before)
|
||||
for name in self._names():
|
||||
if name.startswith("prompt_manager.log."):
|
||||
os.unlink(self._path(name))
|
||||
|
||||
def test_rollover_waits_while_cleanup_holds_the_handler_lock(self):
|
||||
# The file is already over its limit: the next record rolls it over,
|
||||
# renaming .1 to .2 and the active log to .1.
|
||||
self.manager.update_config({"max_file_size": 64, "backup_count": 3})
|
||||
self.logger.info("x" * 100)
|
||||
self._write("prompt_manager.log.1", b"first copy\n")
|
||||
self._write("prompt_manager.log.2", b"second copy\n")
|
||||
reviewed = self._rotated_rows()
|
||||
holding = threading.Event()
|
||||
release = threading.Event()
|
||||
logged = threading.Event()
|
||||
real_unlink = os.unlink
|
||||
self.allowed_thread_names.add("pm-test-rollover")
|
||||
|
||||
def log_from_another_thread():
|
||||
self.logger.info("rolls the log over")
|
||||
logged.set()
|
||||
|
||||
worker = threading.Thread(
|
||||
target=log_from_another_thread, name="pm-test-rollover", daemon=True
|
||||
)
|
||||
|
||||
def slow_unlink(path, *args, **kwargs):
|
||||
if not holding.is_set():
|
||||
worker.start() # its record must wait for the cleanup's lock
|
||||
holding.set()
|
||||
if not release.wait(10):
|
||||
raise RuntimeError("the test never released the cleanup")
|
||||
return real_unlink(path, *args, **kwargs)
|
||||
|
||||
result = {}
|
||||
|
||||
def cleanup():
|
||||
result.update(self.manager.delete_rotated(reviewed))
|
||||
|
||||
with mock.patch.object(logging_config.os, "unlink", slow_unlink):
|
||||
cleaner = threading.Thread(target=cleanup, daemon=True)
|
||||
cleaner.start()
|
||||
self.assertTrue(holding.wait(10), "the cleanup never started deleting")
|
||||
# The record waits on the handler lock the cleanup holds.
|
||||
self.assertFalse(logged.wait(0.3), "a record was written mid-cleanup")
|
||||
release.set()
|
||||
cleaner.join(10)
|
||||
worker.join(10)
|
||||
self.assertFalse(cleaner.is_alive())
|
||||
self.assertTrue(logged.is_set())
|
||||
self.assertEqual(
|
||||
result,
|
||||
{"removed": ["prompt_manager.log.1", "prompt_manager.log.2"], "failed": []},
|
||||
)
|
||||
# The rollover ran after the cleanup: only the old active log moved.
|
||||
self.assertEqual(self._names(), ["prompt_manager.log", "prompt_manager.log.1"])
|
||||
with open(self._path("prompt_manager.log.1"), "rb") as handle:
|
||||
self.assertIn(b"x" * 100, handle.read())
|
||||
|
||||
def test_open_rotated_copy_is_reported_not_deleted(self):
|
||||
for n in (1, 2, 3):
|
||||
self._write(f"prompt_manager.log.{n}")
|
||||
real_unlink = os.unlink
|
||||
held = self._path("prompt_manager.log.2")
|
||||
|
||||
def unlink(path, *args, **kwargs):
|
||||
if os.fspath(path) == held:
|
||||
error = PermissionError(
|
||||
13,
|
||||
"The process cannot access the file because it is being "
|
||||
"used by another process",
|
||||
held,
|
||||
)
|
||||
error.winerror = 32
|
||||
raise error
|
||||
return real_unlink(path, *args, **kwargs)
|
||||
|
||||
with mock.patch.object(logging_config.os, "unlink", unlink):
|
||||
result = self.manager.delete_rotated(self._rotated_rows())
|
||||
self.assertEqual(
|
||||
result["removed"], ["prompt_manager.log.1", "prompt_manager.log.3"]
|
||||
)
|
||||
[(name, error)] = result["failed"]
|
||||
self.assertEqual(name, "prompt_manager.log.2")
|
||||
self.assertIsInstance(error, PermissionError)
|
||||
self.assertIn("prompt_manager.log.2", self._names())
|
||||
|
||||
@unittest.skipUnless(os.name == "nt", "only Windows refuses to unlink an open file")
|
||||
def test_open_rotated_copy_is_reported_not_deleted_on_windows(
|
||||
self,
|
||||
): # pragma: no cover
|
||||
for n in (1, 2, 3):
|
||||
self._write(f"prompt_manager.log.{n}")
|
||||
reviewed = self._rotated_rows()
|
||||
handle = open(self._path("prompt_manager.log.2"), "rb")
|
||||
try:
|
||||
result = self.manager.delete_rotated(reviewed)
|
||||
finally:
|
||||
handle.close()
|
||||
self.assertEqual(
|
||||
result["removed"], ["prompt_manager.log.1", "prompt_manager.log.3"]
|
||||
)
|
||||
[(name, error)] = result["failed"]
|
||||
self.assertEqual(name, "prompt_manager.log.2")
|
||||
self.assertIsInstance(error, PermissionError)
|
||||
self.assertIn("prompt_manager.log.2", self._names())
|
||||
|
||||
def test_cleanup_never_logs_while_holding_the_handler_lock(self):
|
||||
for n in (1, 2):
|
||||
self._write(f"prompt_manager.log.{n}")
|
||||
handler = self._file_handler()
|
||||
depth = 0
|
||||
calls = []
|
||||
real_acquire, real_release = handler.acquire, handler.release
|
||||
|
||||
def acquire():
|
||||
nonlocal depth
|
||||
real_acquire()
|
||||
depth += 1
|
||||
|
||||
def release():
|
||||
nonlocal depth
|
||||
depth -= 1
|
||||
real_release()
|
||||
|
||||
real_call_handlers = logging.Logger.callHandlers
|
||||
|
||||
def call_handlers(logger_self, record):
|
||||
calls.append((record.getMessage(), depth))
|
||||
return real_call_handlers(logger_self, record)
|
||||
|
||||
with (
|
||||
mock.patch.object(handler, "acquire", acquire),
|
||||
mock.patch.object(handler, "release", release),
|
||||
mock.patch.object(logging.Logger, "callHandlers", call_handlers),
|
||||
):
|
||||
self.manager.delete_rotated(self._rotated_rows())
|
||||
self.assertEqual(depth, 0)
|
||||
self._write("prompt_manager.log.1")
|
||||
self.manager.truncate_logs()
|
||||
self.assertEqual(depth, 0)
|
||||
self.assertTrue(calls, "the cleanup logged no summary")
|
||||
self.assertEqual([c for c in calls if c[1]], [])
|
||||
|
||||
def test_truncate_keeps_other_files_and_links(self):
|
||||
# Corrected (#329): the legacy glob deleted every prompt_manager.log*.
|
||||
self._rotate()
|
||||
self._write("prompt_manager.log.bak", b"mine")
|
||||
self._write("prompt_manager.log.1.gz", b"zip")
|
||||
target = self._symlink("prompt_manager.log.4")
|
||||
result = self.manager.truncate_logs()
|
||||
self.assertEqual(result["errors"], [])
|
||||
self.assertEqual(
|
||||
sorted(result["truncated"]),
|
||||
["prompt_manager.log", "prompt_manager.log.1", "prompt_manager.log.2"],
|
||||
)
|
||||
names = self._names()
|
||||
self.assertIn("prompt_manager.log.bak", names)
|
||||
self.assertIn("prompt_manager.log.1.gz", names)
|
||||
self.assertNotIn("prompt_manager.log.1", names)
|
||||
if target is not None:
|
||||
self.assertIn("prompt_manager.log.4", names)
|
||||
self.assertTrue(os.path.islink(self._path("prompt_manager.log.4")))
|
||||
with open(target, "rb") as handle:
|
||||
self.assertEqual(handle.read(), b"secret " * 1000)
|
||||
|
||||
def test_truncate_with_file_logging_off_never_creates_the_active_log(self):
|
||||
self.manager.update_config({"file_logging": False})
|
||||
os.unlink(self._path("prompt_manager.log"))
|
||||
self._write("prompt_manager.log.1")
|
||||
result = self.manager.truncate_logs()
|
||||
self.assertEqual(result, {"truncated": ["prompt_manager.log.1"], "errors": []})
|
||||
self.assertEqual(self._names(), [])
|
||||
|
||||
def test_truncate_never_empties_a_linked_active_log(self):
|
||||
self.manager.update_config({"file_logging": False})
|
||||
os.unlink(self._path("prompt_manager.log"))
|
||||
target = self._require_symlink("prompt_manager.log", data=b"keep")
|
||||
self.manager.truncate_logs()
|
||||
with open(target, "rb") as handle:
|
||||
self.assertEqual(handle.read(), b"keep")
|
||||
|
||||
def test_log_files_mark_kind_and_lstat_links(self):
|
||||
self._write("prompt_manager.log.1", b"r" * 10)
|
||||
self._write("prompt_manager.log.bak", b"b")
|
||||
target = self._require_symlink("prompt_manager.log.4")
|
||||
rows = {row["filename"]: row for row in self.manager.get_log_files()}
|
||||
self.assertEqual(rows["prompt_manager.log"]["kind"], "active")
|
||||
self.assertTrue(rows["prompt_manager.log"]["is_main"])
|
||||
self.assertEqual(rows["prompt_manager.log.1"]["kind"], "rotated")
|
||||
self.assertEqual(rows["prompt_manager.log.bak"]["kind"], "other")
|
||||
link = rows["prompt_manager.log.4"]
|
||||
self.assertEqual(link["kind"], "link")
|
||||
self.assertEqual(
|
||||
link["size"], os.lstat(self._path("prompt_manager.log.4")).st_size
|
||||
)
|
||||
self.assertNotEqual(link["size"], os.path.getsize(target))
|
||||
for row in rows.values():
|
||||
self.assertEqual(
|
||||
set(row), {"filename", "path", "size", "modified", "is_main", "kind"}
|
||||
)
|
||||
|
||||
def test_stats_exclude_links(self):
|
||||
self._write("prompt_manager.log.1", b"r" * 10)
|
||||
before = self.manager.get_log_stats()
|
||||
self._require_symlink("prompt_manager.log.4")
|
||||
after = self.manager.get_log_stats()
|
||||
self.assertEqual(after["log_files_count"], before["log_files_count"])
|
||||
self.assertEqual(after["total_log_size"], before["total_log_size"])
|
||||
|
||||
def test_log_file_entry_accepts_only_listed_regular_files(self):
|
||||
self._write("prompt_manager.log.1")
|
||||
self._write("prompt_manager.log.bak")
|
||||
os.makedirs(self._path("folder.log"))
|
||||
self._symlink("prompt_manager.log.4")
|
||||
self.assertEqual(
|
||||
os.path.normcase(str(self.manager.log_file_entry("prompt_manager.log.1"))),
|
||||
os.path.normcase(self._path("prompt_manager.log.1")),
|
||||
)
|
||||
self.manager.log_file_entry("prompt_manager.log")
|
||||
self.manager.log_file_entry("prompt_manager.log.bak")
|
||||
for name in (
|
||||
"prompt_manager.log.4",
|
||||
"folder.log",
|
||||
"missing.log",
|
||||
"",
|
||||
".",
|
||||
"..",
|
||||
"../outside/secret.txt",
|
||||
"..\\outside\\secret.txt",
|
||||
"prompt_manager.log:stream",
|
||||
"prompt_manager.log\x00",
|
||||
):
|
||||
with self.subTest(name=name):
|
||||
with self.assertRaises(FileNotFoundError):
|
||||
self.manager.log_file_entry(name)
|
||||
|
||||
|
||||
class TestConfiguration(IsolatedLoggerTestCase):
|
||||
|
||||
+268
-44
@@ -10,9 +10,12 @@ This module provides centralized logging configuration with support for:
|
||||
"""
|
||||
|
||||
import collections
|
||||
import fnmatch
|
||||
import logging
|
||||
import logging.handlers
|
||||
import os
|
||||
import re
|
||||
import stat
|
||||
import threading
|
||||
from datetime import datetime
|
||||
from typing import Dict, Any, Optional, List
|
||||
@@ -20,6 +23,131 @@ from pathlib import Path
|
||||
|
||||
from . import library_location
|
||||
|
||||
ACTIVE_LOG_NAME = "prompt_manager.log"
|
||||
# Rule R (#329): a rotated copy is prompt_manager.log.<n>, n >= 1, no leading 0.
|
||||
_ROTATED_NAME = re.compile(r"prompt_manager\.log\.([1-9][0-9]*)")
|
||||
# The legacy listing's pattern (GET /logs/files and /logs/stats).
|
||||
_LISTED_PATTERN = "*.log*"
|
||||
LOG_FILE_KINDS = ("active", "rotated", "link", "other")
|
||||
|
||||
|
||||
class RotatedChanged(Exception):
|
||||
"""A reviewed rotated copy changed since the review; nothing was deleted."""
|
||||
|
||||
def __init__(self, name):
|
||||
super().__init__(f"{name} changed since the review")
|
||||
self.name = name
|
||||
|
||||
|
||||
def _name_key(name: str) -> str:
|
||||
"""How a name compares: case-folded where the filesystem folds it (Windows)."""
|
||||
return os.path.normcase(name)
|
||||
|
||||
|
||||
def _rotated_number(name: str) -> Optional[int]:
|
||||
match = _ROTATED_NAME.fullmatch(_name_key(name))
|
||||
return int(match.group(1)) if match else None
|
||||
|
||||
|
||||
def _is_link(path: str, st: os.stat_result) -> bool:
|
||||
return stat.S_ISLNK(st.st_mode) or os.path.isjunction(path)
|
||||
|
||||
|
||||
def _kind(name: str, path: str, st: os.stat_result) -> str:
|
||||
"""Rule R: ``active``, ``rotated``, ``link`` or ``other`` (never deleted)."""
|
||||
if _is_link(path, st):
|
||||
return "link"
|
||||
if not stat.S_ISREG(st.st_mode):
|
||||
return "other"
|
||||
if _name_key(name) == _name_key(ACTIVE_LOG_NAME):
|
||||
return "active"
|
||||
if _rotated_number(name) is not None:
|
||||
return "rotated"
|
||||
return "other"
|
||||
|
||||
|
||||
def scan_log_folder(log_dir) -> List[Dict[str, Any]]:
|
||||
"""Every direct entry of ``log_dir`` with its Rule R kind (blocking).
|
||||
|
||||
Rows are ``{name, kind, size, mtime_ns, ino, modified}``, read with
|
||||
``lstat`` so a link is described, never followed. An entry that cannot
|
||||
be read is left out. Never logs: the cleanup calls it while it holds the
|
||||
file handler's lock.
|
||||
"""
|
||||
rows = []
|
||||
try:
|
||||
names = [entry.name for entry in os.scandir(log_dir)]
|
||||
except OSError:
|
||||
return rows
|
||||
for name in names:
|
||||
path = os.path.join(log_dir, name)
|
||||
try:
|
||||
st = os.lstat(path)
|
||||
kind = _kind(name, path, st)
|
||||
except OSError:
|
||||
continue
|
||||
rows.append(
|
||||
{
|
||||
"name": name,
|
||||
"kind": kind,
|
||||
"size": st.st_size,
|
||||
"mtime_ns": st.st_mtime_ns,
|
||||
"ino": st.st_ino,
|
||||
"modified": datetime.fromtimestamp(st.st_mtime).isoformat(),
|
||||
"_dir": stat.S_ISDIR(st.st_mode) and kind != "link",
|
||||
}
|
||||
)
|
||||
return rows
|
||||
|
||||
|
||||
def public_row(row: Dict[str, Any]) -> Dict[str, Any]:
|
||||
"""A scan row without its private keys."""
|
||||
return {key: value for key, value in row.items() if not key.startswith("_")}
|
||||
|
||||
|
||||
def rotated_sort_key(row: Dict[str, Any]) -> int:
|
||||
return _rotated_number(row["name"]) or 0
|
||||
|
||||
|
||||
def log_file_entry(log_dir, name) -> Path:
|
||||
"""The path of a downloadable log file named ``name`` (blocking).
|
||||
|
||||
Only a regular, non-link file listed directly in ``log_dir`` under that
|
||||
exact name; a separator, ``..``, a stream suffix or any unlisted name
|
||||
raises FileNotFoundError, as a missing file does.
|
||||
"""
|
||||
if not isinstance(name, str) or not name or name in (".", ".."):
|
||||
raise FileNotFoundError("Log file not found")
|
||||
if any(ch in name for ch in ("/", "\\", "\x00", ":")):
|
||||
raise FileNotFoundError("Log file not found")
|
||||
for row in scan_log_folder(log_dir):
|
||||
if row["name"] == name and row["kind"] in ("active", "rotated", "other"):
|
||||
if row["_dir"]:
|
||||
break
|
||||
return Path(log_dir) / row["name"]
|
||||
raise FileNotFoundError("Log file not found")
|
||||
|
||||
|
||||
def _error_text(error: BaseException) -> str:
|
||||
"""An OSError's reason and file name, without the folder it is in."""
|
||||
if isinstance(error, OSError):
|
||||
parts = [error.strerror or type(error).__name__]
|
||||
if error.filename:
|
||||
parts.append(os.path.basename(str(error.filename)))
|
||||
return ": ".join(parts)
|
||||
return str(error) or type(error).__name__
|
||||
|
||||
|
||||
def _matches_review(row: Optional[Dict[str, Any]], reviewed: Dict[str, Any]) -> bool:
|
||||
if row is None or row["kind"] != "rotated":
|
||||
return False
|
||||
if row["size"] != reviewed.get("size") or row["mtime_ns"] != reviewed.get(
|
||||
"mtime_ns"
|
||||
):
|
||||
return False
|
||||
ino = reviewed.get("ino") or 0
|
||||
return not (ino and row["ino"] and row["ino"] != ino)
|
||||
|
||||
|
||||
class _OwnedRotatingFileHandler(logging.handlers.RotatingFileHandler):
|
||||
"""Keep a retired owned sink closed when an in-flight record resumes."""
|
||||
@@ -87,6 +215,9 @@ class PromptManagerLogger:
|
||||
# Memory buffer for recent logs (for web viewer)
|
||||
self._log_buffer = collections.deque(maxlen=self.config["buffer_size"])
|
||||
self._buffer_lock = threading.Lock()
|
||||
# Held while a handler is replaced or log files are deleted (#329):
|
||||
# taken before any file handler's own lock, never the other way round.
|
||||
self._files_lock = threading.Lock()
|
||||
|
||||
# Initialize loggers
|
||||
self._setup_loggers()
|
||||
@@ -238,6 +369,14 @@ class PromptManagerLogger:
|
||||
# Return most recent first
|
||||
return list(reversed(logs[-limit:]))
|
||||
|
||||
def scan_log_folder(self) -> List[Dict[str, Any]]:
|
||||
"""Every entry of the log folder with its Rule R kind (blocking)."""
|
||||
return [public_row(row) for row in scan_log_folder(self.log_dir)]
|
||||
|
||||
def log_file_entry(self, name: str) -> Path:
|
||||
"""A downloadable (regular, non-link) log file; FileNotFoundError else."""
|
||||
return log_file_entry(self.log_dir, name)
|
||||
|
||||
def get_log_files(self) -> List[Dict[str, Any]]:
|
||||
"""Get information about available log files.
|
||||
|
||||
@@ -245,26 +384,27 @@ class PromptManagerLogger:
|
||||
List of dictionaries containing file information:
|
||||
- filename: Name of the log file
|
||||
- path: Full path to the log file
|
||||
- size: File size in bytes
|
||||
- size: File size in bytes (a link's own size: links are not followed)
|
||||
- modified: ISO formatted modification timestamp
|
||||
- is_main: True if this is the main log file
|
||||
- kind: ``active``, ``rotated``, ``link`` or ``other`` (Rule R)
|
||||
"""
|
||||
log_files = []
|
||||
|
||||
for log_file in self.log_dir.glob("*.log*"):
|
||||
try:
|
||||
stat = log_file.stat()
|
||||
log_files.append(
|
||||
{
|
||||
"filename": log_file.name,
|
||||
"path": str(log_file),
|
||||
"size": stat.st_size,
|
||||
"modified": datetime.fromtimestamp(stat.st_mtime).isoformat(),
|
||||
"is_main": log_file.name == "prompt_manager.log",
|
||||
}
|
||||
)
|
||||
except Exception as e:
|
||||
self.logger.error(f"Error getting info for log file {log_file}: {e}")
|
||||
for row in scan_log_folder(self.log_dir):
|
||||
if row["_dir"]:
|
||||
continue
|
||||
if not fnmatch.fnmatchcase(_name_key(row["name"]), _LISTED_PATTERN):
|
||||
continue
|
||||
log_files.append(
|
||||
{
|
||||
"filename": row["name"],
|
||||
"path": str(self.log_dir / row["name"]),
|
||||
"size": row["size"],
|
||||
"modified": row["modified"],
|
||||
"is_main": row["kind"] == "active",
|
||||
"kind": row["kind"],
|
||||
}
|
||||
)
|
||||
|
||||
# Sort by modification time, newest first
|
||||
log_files.sort(key=lambda x: x["modified"], reverse=True)
|
||||
@@ -302,6 +442,31 @@ class PromptManagerLogger:
|
||||
self.logger.error(f"Error reading log file {filename}: {e}")
|
||||
raise
|
||||
|
||||
def _file_handlers(self) -> List[logging.Handler]:
|
||||
return [h for h in self.logger.handlers if isinstance(h, logging.FileHandler)]
|
||||
|
||||
def _acquire_file_handlers(self) -> List[logging.Handler]:
|
||||
"""Take every file handler's lock: no rollover renames a file meanwhile.
|
||||
|
||||
The caller holds ``_files_lock`` (so no handler is replaced) and must
|
||||
not log until it released them: the lock is re-entrant, so a record
|
||||
logged here could roll the log over under the caller's feet.
|
||||
"""
|
||||
held = []
|
||||
try:
|
||||
for handler in self._file_handlers():
|
||||
handler.acquire()
|
||||
held.append(handler)
|
||||
except BaseException:
|
||||
self._release_handlers(held)
|
||||
raise
|
||||
return held
|
||||
|
||||
@staticmethod
|
||||
def _release_handlers(held) -> None:
|
||||
for handler in reversed(held):
|
||||
handler.release()
|
||||
|
||||
def _truncate_main_log(self, log_file: Path) -> None:
|
||||
"""Empty the main log through the handler that writes to it.
|
||||
|
||||
@@ -309,7 +474,8 @@ class PromptManagerLogger:
|
||||
stream at its old offset: later records land past the new end
|
||||
(zero-padded on POSIX) and ``tell()`` keeps reporting the old size, so
|
||||
the next record rolls the file over. Truncating the handler's stream
|
||||
keeps position and size in step.
|
||||
keeps position and size in step. Without a handler on it (file logging
|
||||
off) the existing file is emptied in place, never through a link.
|
||||
"""
|
||||
handled = False
|
||||
target = os.path.normcase(os.path.realpath(str(log_file)))
|
||||
@@ -329,14 +495,65 @@ class PromptManagerLogger:
|
||||
finally:
|
||||
handler.release()
|
||||
if not handled:
|
||||
with open(log_file, "w", encoding="utf-8", errors="replace") as f:
|
||||
f.write("")
|
||||
flags = os.O_WRONLY | os.O_TRUNC | getattr(os, "O_NOFOLLOW", 0)
|
||||
os.close(os.open(str(log_file), flags))
|
||||
|
||||
def delete_rotated(self, expected: List[Dict[str, Any]]) -> Dict[str, Any]:
|
||||
"""Delete exactly the reviewed rotated copies, or none of them (blocking).
|
||||
|
||||
``expected`` are scan rows (``name``, ``size``, ``mtime_ns``,
|
||||
``ino``). Under ``_files_lock`` and every file handler's lock the
|
||||
folder is scanned again; when any expected file is missing, is no
|
||||
longer a rotated copy (Rule R) or differs in size, ``mtime_ns`` or a
|
||||
non-zero ``ino``, RotatedChanged is raised with nothing deleted.
|
||||
Otherwise each is unlinked in ``<n>`` order.
|
||||
|
||||
Returns ``{"removed": [names], "failed": [(name, OSError)]}``. One
|
||||
summary line is logged once both locks are released.
|
||||
"""
|
||||
removed, failed = [], []
|
||||
changed = None
|
||||
with self._files_lock:
|
||||
held = self._acquire_file_handlers()
|
||||
try:
|
||||
current = {
|
||||
_name_key(row["name"]): row for row in scan_log_folder(self.log_dir)
|
||||
}
|
||||
targets = []
|
||||
for reviewed in sorted(expected, key=rotated_sort_key):
|
||||
row = current.get(_name_key(str(reviewed.get("name", ""))))
|
||||
if not _matches_review(row, reviewed):
|
||||
changed = str(reviewed.get("name", ""))
|
||||
break
|
||||
targets.append(row["name"])
|
||||
if changed is None:
|
||||
for name in targets:
|
||||
try:
|
||||
os.unlink(os.path.join(self.log_dir, name))
|
||||
removed.append(name)
|
||||
except OSError as error:
|
||||
failed.append((name, error))
|
||||
finally:
|
||||
self._release_handlers(held)
|
||||
if changed is not None:
|
||||
self.logger.warning(
|
||||
"Rotated log cleanup refused: %s changed since the review", changed
|
||||
)
|
||||
raise RotatedChanged(changed)
|
||||
self.logger.info(
|
||||
"Deleted %d rotated log copies%s",
|
||||
len(removed),
|
||||
f", {len(failed)} could not be deleted" if failed else "",
|
||||
)
|
||||
return {"removed": removed, "failed": failed}
|
||||
|
||||
def truncate_logs(self) -> Dict[str, Any]:
|
||||
"""Truncate all log files.
|
||||
"""Empty the active log and delete its rotated copies (Rule R).
|
||||
|
||||
Clears the main log file and deletes rotated log files.
|
||||
Also clears the memory buffer.
|
||||
Every other file in the log folder, and every link, is kept. Also
|
||||
clears the memory buffer. Runs under ``_files_lock`` and the file
|
||||
handlers' locks, so no rollover recreates a just-deleted copy, and
|
||||
logs only once they are released.
|
||||
|
||||
Returns:
|
||||
Dictionary with:
|
||||
@@ -345,28 +562,31 @@ class PromptManagerLogger:
|
||||
"""
|
||||
results = {"truncated": [], "errors": []}
|
||||
|
||||
# Collect first and stay silent until every file has been handled:
|
||||
# a log line written mid-way can roll the just-emptied main log over
|
||||
# and recreate the backup that was deleted a moment earlier.
|
||||
log_files = sorted(self.log_dir.glob("prompt_manager.log*"))
|
||||
for log_file in log_files:
|
||||
with self._files_lock:
|
||||
held = self._acquire_file_handlers()
|
||||
try:
|
||||
if log_file.name == "prompt_manager.log":
|
||||
self._truncate_main_log(log_file)
|
||||
else:
|
||||
# For rotated files, delete them
|
||||
log_file.unlink()
|
||||
|
||||
results["truncated"].append(log_file.name)
|
||||
|
||||
except Exception as e:
|
||||
results["errors"].append(
|
||||
f"Failed to truncate {log_file.name}: {str(e)}"
|
||||
rows = scan_log_folder(self.log_dir)
|
||||
active = [row for row in rows if row["kind"] == "active"]
|
||||
rotated = sorted(
|
||||
(row for row in rows if row["kind"] == "rotated"),
|
||||
key=rotated_sort_key,
|
||||
)
|
||||
|
||||
# Clear memory buffer
|
||||
with self._buffer_lock:
|
||||
self._log_buffer.clear()
|
||||
for row in active + rotated:
|
||||
path = os.path.join(self.log_dir, row["name"])
|
||||
try:
|
||||
if row["kind"] == "active":
|
||||
self._truncate_main_log(Path(path))
|
||||
else:
|
||||
os.unlink(path)
|
||||
results["truncated"].append(row["name"])
|
||||
except OSError as error:
|
||||
results["errors"].append(
|
||||
f"Failed to truncate {row['name']}: {_error_text(error)}"
|
||||
)
|
||||
with self._buffer_lock:
|
||||
self._log_buffer.clear()
|
||||
finally:
|
||||
self._release_handlers(held)
|
||||
|
||||
if results["truncated"]:
|
||||
self.logger.info("Truncated log files: %s", ", ".join(results["truncated"]))
|
||||
@@ -409,7 +629,9 @@ class PromptManagerLogger:
|
||||
"backup_count",
|
||||
]
|
||||
):
|
||||
self._setup_loggers()
|
||||
# No cleanup may hold the old handler while it is replaced.
|
||||
with self._files_lock:
|
||||
self._setup_loggers()
|
||||
|
||||
self.logger.info(f"Updated logging configuration: {new_config}")
|
||||
|
||||
@@ -440,7 +662,9 @@ class PromptManagerLogger:
|
||||
level = entry["level"]
|
||||
level_counts[level] = level_counts.get(level, 0) + 1
|
||||
|
||||
log_files = self.get_log_files()
|
||||
# A link's target is not a log file of this folder: neither counted
|
||||
# nor sized.
|
||||
log_files = [f for f in self.get_log_files() if f["kind"] != "link"]
|
||||
total_log_size = sum(f["size"] for f in log_files)
|
||||
|
||||
return {
|
||||
|
||||
Reference in New Issue
Block a user