feat(system): log cleanup rule, reviewed rotated-log cleanup and diagnostic report (#329, PR 1) (#367)
* 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. * feat(logs): review and apply rotated-log cleanup as a maintenance plan POST /maintenance/preview {operation: "rotated_logs", options: {}} lists the rotated copies Rule R allows, with size and time, and what it keeps (the active log, links, other files); it writes nothing and answers the Plan shape with basenames only, backup policy none and no disk key. POST /maintenance/apply starts the "Rotated log copies" maintenance job (admission read: runs beside a scan, refused beside another maintenance job or an exclusive one). It deletes exactly the reviewed copies, or nothing and fails plan-changed when any of them changed after the review; a copy that cannot be deleted becomes an errors row. The token is consumed on the loop turn the job starts. (#329) * feat(diagnostics): add a shareable report without secrets or paths GET /system/diagnostics builds the report on the server, off the event loop and under a registry lease (409 busy while a restore runs): the project and Viewer.js versions, Python and the platform, the four legacy checks (one helper, legacy_checks, that GET /diagnostics also calls), public database info, source counts, the log configuration and statistics, the last health summary and the config.json-only keys from an explicit list. The CivitAI key is reported only as has_civitai_api_key; every path is relative to ComfyUI or reads "outside ComfyUI". A scrub replaces anything still absolute, the key or the home folder and counts it in redacted (0 for a correct build). The version parser moves unchanged to utils/version.py. (#329) * fix(logs): never empty a renamed log or serve a swapped file; keep root anchors private Review findings on #329 PR 1: - Clear empties the active log through the handler only when the handler's open stream is the listed file (same inode); a log the user renamed while ComfyUI runs is no longer emptied. - A download is refused when the opened file is not the one listed (inode), or has another name (a hard link). - Windows reparse points that name another file (the name-surrogate bit: symlinks, junctions, WSL links) are links under Rule R; cloud placeholders stay regular files. - The report's paths use the closest anchor that is not a filesystem root, and the scrub also catches the home folder without its root. * fix(diagnostics): never anchor a report path above the home folder; serve only regular log files Review findings on #329 PR 1: - report_path never uses a filesystem root or a strict ancestor of the home folder (/home, C:\Users) as its anchor, so a path inside home needs an anchor at or below it and otherwise reads "outside ComfyUI"; no path starts with a user name. The scrub matches the home folder only as whole path parts (in full, without its root, and its name). - A download serves only a regular file (a FIFO, socket or device is a 404) and opens it non-blocking. - One unreadable timestamp no longer breaks the log listing, stats, download, review or Clear. - The report tests read a temporary log folder, never the process's own. * fix(diagnostics): match the bare home folder name only inside paths A home folder named like a word (/home/info) no longer removes the log level INFO from the report; the name still goes when it is a part of a path. Documents the accepted residual risk of another user's home. (#329)
This commit is contained in:
Vito
+6
-10
@@ -23,24 +23,20 @@ Features:
|
||||
"""
|
||||
|
||||
import atexit
|
||||
import re
|
||||
import threading
|
||||
import time
|
||||
from pathlib import Path
|
||||
|
||||
|
||||
def get_version():
|
||||
"""Parse version from pyproject.toml"""
|
||||
"""Parse version from pyproject.toml (``utils/version.py``)."""
|
||||
from .utils.version import project_version
|
||||
|
||||
try:
|
||||
pyproject_path = Path(__file__).parent / "pyproject.toml"
|
||||
if pyproject_path.exists():
|
||||
content = pyproject_path.read_text()
|
||||
match = re.search(r'version\s*=\s*["\']([^"\']+)["\']', content)
|
||||
if match:
|
||||
return match.group(1)
|
||||
root = Path(__file__).parent
|
||||
except Exception:
|
||||
pass
|
||||
return "unknown"
|
||||
return "unknown"
|
||||
return project_version(root)
|
||||
|
||||
|
||||
from .prompt_manager import ( # noqa: E402
|
||||
|
||||
@@ -5,6 +5,8 @@ Split into domain-specific mixins for maintainability:
|
||||
- ImageRoutesMixin: gallery, thumbnails, image serving and linking
|
||||
- AdminRoutesMixin: duplicates, stats, settings, diagnostics, maintenance, backup, scan
|
||||
- LoggingRoutesMixin: log management endpoints
|
||||
- LogCleanupMixin: the reviewed rotated-log cleanup (a maintenance plan)
|
||||
- DiagnosticsReportMixin: the shareable diagnostic report, without secrets or paths
|
||||
- AutotagRoutesMixin: auto-tagging model management and tagging
|
||||
- JobRoutesMixin: the session job registry behind Activity (py/api/jobs.py)
|
||||
- ImageTagJobsMixin: bulk Add tags / Auto-tag as image-tags jobs
|
||||
@@ -65,6 +67,8 @@ from .duplicate_files import DuplicateFilesMixin
|
||||
from .maintenance_plans import PlanStore
|
||||
from .jobs import JobRegistry
|
||||
from .logging_routes import LoggingRoutesMixin
|
||||
from .log_cleanup import LogCleanupMixin
|
||||
from .diagnostics_report import DiagnosticsReportMixin
|
||||
from .autotag_routes import AutotagRoutesMixin
|
||||
from .lora_integration import LoraIntegrationMixin
|
||||
from .lora_import_routes import LoraImportRoutesMixin
|
||||
@@ -323,6 +327,8 @@ class PromptManagerAPI(
|
||||
WorkflowStorageRoutesMixin,
|
||||
DuplicateFilesMixin,
|
||||
LoggingRoutesMixin,
|
||||
LogCleanupMixin,
|
||||
DiagnosticsReportMixin,
|
||||
AutotagRoutesMixin,
|
||||
LoraIntegrationMixin,
|
||||
LoraImportRoutesMixin,
|
||||
@@ -678,6 +684,7 @@ class PromptManagerAPI(
|
||||
self._register_settings_routes(routes)
|
||||
self._register_job_routes(routes)
|
||||
self._register_system_routes(routes)
|
||||
self._register_diagnostics_report_routes(routes)
|
||||
self._register_library_location_routes(routes)
|
||||
self._register_maintenance_routes(routes)
|
||||
self._register_backup_restore_routes(routes)
|
||||
|
||||
+24
-12
@@ -489,9 +489,29 @@ def _diagnose_dependencies():
|
||||
}
|
||||
|
||||
|
||||
def _diagnose_output_dirs(configured_dirs):
|
||||
def legacy_checks(db_path, public_path=None):
|
||||
"""The four checks of ``GET /diagnostics`` (blocking).
|
||||
|
||||
Shared with the diagnostic report (``py/api/diagnostics_report.py``),
|
||||
which passes its own ``public_path`` so a folder outside ComfyUI is never
|
||||
named.
|
||||
"""
|
||||
from ..config import GalleryConfig
|
||||
|
||||
return {
|
||||
"database": _diagnose_database(db_path),
|
||||
"dependencies": _diagnose_dependencies(),
|
||||
"comfyui_output": _diagnose_output_dirs(
|
||||
GalleryConfig.MONITORING_DIRECTORIES, public_path
|
||||
),
|
||||
"image_monitor": _diagnose_image_monitor(public_path),
|
||||
}
|
||||
|
||||
|
||||
def _diagnose_output_dirs(configured_dirs, public_path=None):
|
||||
"""Configured gallery roots, ComfyUI's output dir, or relative fallbacks."""
|
||||
_public_path, _ = _public_helpers()
|
||||
_public_path = public_path or _public_path
|
||||
candidates = list(configured_dirs)
|
||||
try:
|
||||
import folder_paths
|
||||
@@ -525,9 +545,10 @@ def _diagnose_output_dirs(configured_dirs):
|
||||
}
|
||||
|
||||
|
||||
def _diagnose_image_monitor():
|
||||
def _diagnose_image_monitor(public_path=None):
|
||||
"""Status of the running image monitor, with public directory names."""
|
||||
_public_path, _public_error = _public_helpers()
|
||||
_public_path = public_path or _public_path
|
||||
try:
|
||||
monitor = _current_image_monitor()
|
||||
if monitor is None:
|
||||
@@ -1055,16 +1076,7 @@ class AdminRoutesMixin:
|
||||
async def run_diagnostics(self, request):
|
||||
"""Run comprehensive system diagnostics and health checks."""
|
||||
try:
|
||||
from ..config import GalleryConfig
|
||||
|
||||
results = {
|
||||
"database": _diagnose_database(self.db.model.db_path),
|
||||
"dependencies": _diagnose_dependencies(),
|
||||
"comfyui_output": _diagnose_output_dirs(
|
||||
GalleryConfig.MONITORING_DIRECTORIES
|
||||
),
|
||||
"image_monitor": _diagnose_image_monitor(),
|
||||
}
|
||||
results = legacy_checks(self.db.model.db_path)
|
||||
return web.json_response({"success": True, "diagnostics": results})
|
||||
|
||||
except Exception as e:
|
||||
|
||||
@@ -0,0 +1,289 @@
|
||||
"""The shareable diagnostic report (#329 System S12).
|
||||
|
||||
``GET /prompt_manager/system/diagnostics`` answers a report built on the
|
||||
server from an explicit list of fields: the project and Viewer.js versions,
|
||||
Python and the platform, the four checks of the legacy ``GET /diagnostics``
|
||||
(one helper, ``admin.legacy_checks``), the database's public info, source
|
||||
counts, the log configuration and statistics, the last health summary and
|
||||
the configuration keys that only ``config.json`` holds. It never copies
|
||||
``PromptManagerConfig.get_config()``: no path leaf is listed, and the CivitAI
|
||||
key is reported only as ``has_civitai_api_key``.
|
||||
|
||||
Every path in the report goes through ``report_path``: relative to the
|
||||
closest public anchor that is not a filesystem root, else ``"outside
|
||||
ComfyUI"``, never a basename that could be a user name. As a backstop,
|
||||
``scrub`` replaces any string that still looks like an absolute path, holds
|
||||
the saved key or the home folder (with or without its root), and counts each
|
||||
replacement in ``redacted`` (0 for a correct builder).
|
||||
|
||||
The report opens the database, so it takes a registry lease: it is refused
|
||||
(409 ``busy``) while an ``exclusive`` job (a restore) runs, and a restore
|
||||
waits for it. It is built off the event loop.
|
||||
"""
|
||||
|
||||
import datetime
|
||||
import json
|
||||
import ntpath
|
||||
import os
|
||||
import platform
|
||||
import posixpath
|
||||
import re
|
||||
from pathlib import Path, PurePosixPath, PureWindowsPath
|
||||
|
||||
from aiohttp import web
|
||||
|
||||
from . import admin as _admin
|
||||
from .job_routes import busy_response
|
||||
from .jobs import JobBusy
|
||||
from .system import health_summary
|
||||
|
||||
try:
|
||||
from ...utils.version import project_version
|
||||
except ImportError: # loaded as the top-level ``py`` package (tests)
|
||||
from utils.version import project_version
|
||||
|
||||
DIAGNOSTICS_LEASE = "Diagnostics"
|
||||
_ROOT = Path(__file__).resolve().parents[2]
|
||||
VIEWERJS_PROVENANCE = str(_ROOT / "web" / "lib" / "viewerjs" / "provenance.json")
|
||||
OUTSIDE = "outside ComfyUI"
|
||||
REMOVED = "[removed]"
|
||||
# The CivitAI key is searched for only when it is long enough to be a key.
|
||||
MIN_KEY_LENGTH = 8
|
||||
_WINDOWS_ABSOLUTE = re.compile(r"^[A-Za-z]:[\\/]")
|
||||
|
||||
|
||||
def anchored_path(canonical, anchors, home, pathmod=os.path):
|
||||
"""``canonical`` relative to the closest usable anchor, else ``outside ComfyUI``.
|
||||
|
||||
All three are already canonical (``normcase``) in ``pathmod``'s spelling.
|
||||
A filesystem root is never usable, nor is a strict ancestor of ``home``
|
||||
(``/home``, ``C:\\Users``), whose relative paths would start with a user
|
||||
name; so a path inside the home folder needs an anchor at or below it.
|
||||
"""
|
||||
flavor = PureWindowsPath if pathmod is ntpath else PurePosixPath
|
||||
target = flavor(canonical)
|
||||
home_path = flavor(home) if home else None
|
||||
usable = []
|
||||
for anchor in map(flavor, anchors):
|
||||
if anchor.parent == anchor:
|
||||
continue
|
||||
if home_path is not None and home_path != anchor:
|
||||
if home_path.is_relative_to(anchor):
|
||||
continue
|
||||
if target.is_relative_to(anchor):
|
||||
usable.append(anchor)
|
||||
if not usable:
|
||||
return OUTSIDE
|
||||
anchor = max(usable, key=lambda a: len(a.parts))
|
||||
return target.relative_to(anchor).as_posix() or "."
|
||||
|
||||
|
||||
def _canonical(path):
|
||||
return os.path.normcase(os.path.realpath(str(path)))
|
||||
|
||||
|
||||
def report_path(path):
|
||||
"""``path`` relative to a public anchor (POSIX style), else ``outside ComfyUI``."""
|
||||
if not path:
|
||||
return ""
|
||||
from ..config import GalleryConfig
|
||||
|
||||
try:
|
||||
canonical = _canonical(path)
|
||||
anchors = [_canonical(anchor) for anchor in GalleryConfig.path_anchors()]
|
||||
home = os.path.expanduser("~")
|
||||
home = _canonical(home) if home and home != "~" else None
|
||||
except (OSError, ValueError):
|
||||
return OUTSIDE
|
||||
return anchored_path(canonical, anchors, home)
|
||||
|
||||
|
||||
def _looks_absolute(text):
|
||||
return (
|
||||
posixpath.isabs(text)
|
||||
or ntpath.isabs(text)
|
||||
or _WINDOWS_ABSOLUTE.match(text) is not None
|
||||
or text.startswith("\\\\")
|
||||
)
|
||||
|
||||
|
||||
# The home folder is matched only as whole path parts, never inside a word.
|
||||
_PART = r"(?<![\w.-]){}(?![\w.-])"
|
||||
MIN_HOME_NAME = 3
|
||||
|
||||
|
||||
def _home_patterns():
|
||||
"""``(pattern, paths_only)`` for the home folder: in full, rootless, its name.
|
||||
|
||||
Accepted residual risk: only this process's own home folder is known, so
|
||||
another user's home (an output folder under /home/<them> while ComfyUI
|
||||
runs as a service account) can still be named by a report path.
|
||||
"""
|
||||
home = os.path.expanduser("~")
|
||||
if not home or home == "~" or len(home) < 4 or home in ("/", "\\"):
|
||||
return ()
|
||||
spellings = {home, home.replace("\\", "/")}
|
||||
relative = os.path.splitdrive(home)[1].strip("\\/")
|
||||
for spelling in (relative, relative.replace("\\", "/")):
|
||||
if "/" in spelling or "\\" in spelling:
|
||||
spellings.add(spelling)
|
||||
patterns = [
|
||||
(re.compile(_PART.format(re.escape(spelling)), re.IGNORECASE), False)
|
||||
for spelling in spellings
|
||||
]
|
||||
name = re.split(r"[\\/]", relative)[-1] if relative else ""
|
||||
if len(name) >= MIN_HOME_NAME:
|
||||
# The bare name only inside a path ("info/x"), not a word ("INFO").
|
||||
patterns.append(
|
||||
(re.compile(_PART.format(re.escape(name)), re.IGNORECASE), True)
|
||||
)
|
||||
return tuple(patterns)
|
||||
|
||||
|
||||
def scrub(report, key):
|
||||
"""``report`` with leaked paths and the key replaced, counted in ``redacted``."""
|
||||
key = key if isinstance(key, str) and len(key) >= MIN_KEY_LENGTH else None
|
||||
homes = _home_patterns()
|
||||
count = 0
|
||||
|
||||
def clean(value):
|
||||
nonlocal count
|
||||
if isinstance(value, str):
|
||||
if (
|
||||
_looks_absolute(value)
|
||||
or (key and key in value)
|
||||
or any(
|
||||
pattern.search(value)
|
||||
for pattern, paths_only in homes
|
||||
if not paths_only or "/" in value or "\\" in value
|
||||
)
|
||||
):
|
||||
count += 1
|
||||
return REMOVED
|
||||
return value
|
||||
if isinstance(value, dict):
|
||||
return {name: clean(item) for name, item in value.items()}
|
||||
if isinstance(value, (list, tuple)):
|
||||
return [clean(item) for item in value]
|
||||
return value
|
||||
|
||||
cleaned = clean(report)
|
||||
cleaned["redacted"] = int(cleaned.get("redacted") or 0) + count
|
||||
return cleaned
|
||||
|
||||
|
||||
def viewerjs_version(path=None):
|
||||
"""The pinned Viewer.js version from its provenance file, or ``unknown``."""
|
||||
try:
|
||||
with open(path or VIEWERJS_PROVENANCE, encoding="utf-8") as handle:
|
||||
version = json.load(handle).get("version")
|
||||
except (OSError, ValueError, AttributeError):
|
||||
return "unknown"
|
||||
return version if isinstance(version, str) and version else "unknown"
|
||||
|
||||
|
||||
def public_config():
|
||||
"""The configuration keys only ``config.json`` holds, from an explicit list."""
|
||||
from ..config import GalleryConfig, IntegrationConfig, PromptManagerConfig
|
||||
|
||||
return {
|
||||
"database": {
|
||||
"enable_duplicate_detection": (
|
||||
PromptManagerConfig.ENABLE_DUPLICATE_DETECTION
|
||||
),
|
||||
"enable_auto_save": PromptManagerConfig.ENABLE_AUTO_SAVE,
|
||||
},
|
||||
"web_ui": {
|
||||
"result_timeout": PromptManagerConfig.RESULT_TIMEOUT,
|
||||
"show_test_button": PromptManagerConfig.SHOW_TEST_BUTTON,
|
||||
"webui_display_mode": PromptManagerConfig.WEBUI_DISPLAY_MODE,
|
||||
"infinite_scroll": PromptManagerConfig.INFINITE_SCROLL,
|
||||
},
|
||||
"performance": {
|
||||
"max_search_results": PromptManagerConfig.MAX_SEARCH_RESULTS,
|
||||
"enable_fuzzy_search": PromptManagerConfig.ENABLE_FUZZY_SEARCH,
|
||||
"auto_backup_interval": PromptManagerConfig.AUTO_BACKUP_INTERVAL,
|
||||
"worker_threads": PromptManagerConfig.WORKER_THREADS,
|
||||
},
|
||||
"gallery": {
|
||||
"processing_delay": GalleryConfig.PROCESSING_DELAY,
|
||||
"prompt_timeout": GalleryConfig.PROMPT_TIMEOUT,
|
||||
"cleanup_interval": GalleryConfig.CLEANUP_INTERVAL,
|
||||
"auto_cleanup_missing_files": GalleryConfig.AUTO_CLEANUP_MISSING_FILES,
|
||||
"max_image_age_days": GalleryConfig.MAX_IMAGE_AGE_DAYS,
|
||||
"max_concurrent_processing": GalleryConfig.MAX_CONCURRENT_PROCESSING,
|
||||
"metadata_extraction_timeout": GalleryConfig.METADATA_EXTRACTION_TIMEOUT,
|
||||
},
|
||||
"integrations": {
|
||||
"lora_manager_enabled": bool(IntegrationConfig.LORA_MANAGER_ENABLED),
|
||||
"has_civitai_api_key": bool(IntegrationConfig.CIVITAI_API_KEY),
|
||||
},
|
||||
}
|
||||
|
||||
|
||||
def _source_counts(sources):
|
||||
configured = sources.get("configured") or []
|
||||
effective = sources.get("effective") or []
|
||||
return {
|
||||
"configured": len(configured),
|
||||
"effective": len(effective),
|
||||
"watching": sum(1 for row in effective if row.get("watch") == "watching"),
|
||||
"unavailable": sum(1 for row in configured if row.get("valid") is False),
|
||||
}
|
||||
|
||||
|
||||
class DiagnosticsReportMixin:
|
||||
"""Mixin providing ``GET /prompt_manager/system/diagnostics``."""
|
||||
|
||||
def _register_diagnostics_report_routes(self, routes):
|
||||
@routes.get("/prompt_manager/system/diagnostics")
|
||||
async def diagnostics_report_route(request):
|
||||
return await self.get_diagnostics_report(request)
|
||||
|
||||
async def get_diagnostics_report(self, request):
|
||||
"""The report, built off the loop under a lease (409 ``busy`` in a restore)."""
|
||||
from ..config import IntegrationConfig
|
||||
|
||||
try:
|
||||
async with self._jobs.lease(DIAGNOSTICS_LEASE):
|
||||
report = await self._run_in_executor(self.build_report)
|
||||
except JobBusy as busy:
|
||||
return busy_response(busy)
|
||||
except Exception:
|
||||
self.logger.exception("The diagnostic report could not be built")
|
||||
return web.json_response(
|
||||
{
|
||||
"success": False,
|
||||
"code": None,
|
||||
"error": "The diagnostic report could not be built.",
|
||||
},
|
||||
status=500,
|
||||
)
|
||||
report = scrub(report, IntegrationConfig.CIVITAI_API_KEY)
|
||||
return web.json_response(report, headers={"Cache-Control": "no-store"})
|
||||
|
||||
def build_report(self):
|
||||
"""The report's fields (blocking: reads the database and the log folder)."""
|
||||
db = self.db
|
||||
manager = self._get_logger_manager()
|
||||
stats = dict(manager.get_log_stats())
|
||||
stats["log_directory"] = report_path(stats.get("log_directory"))
|
||||
info = dict(db.model.get_database_info() or {})
|
||||
if "database_path" in info:
|
||||
info["database_path"] = report_path(info["database_path"])
|
||||
sources, _monitor = self._source_status()
|
||||
return {
|
||||
"success": True,
|
||||
"generated_at": datetime.datetime.now().replace(microsecond=0).isoformat(),
|
||||
"version": project_version(_ROOT),
|
||||
"python": platform.python_version(),
|
||||
"platform": {"system": platform.system(), "release": platform.release()},
|
||||
"viewerjs": viewerjs_version(VIEWERJS_PROVENANCE),
|
||||
"checks": _admin.legacy_checks(db.model.db_path, report_path),
|
||||
"database_info": info,
|
||||
"sources": _source_counts(sources),
|
||||
"logging": {"config": dict(manager.get_config()), "stats": stats},
|
||||
"health": health_summary(self._current_health_report()),
|
||||
"config": public_config(),
|
||||
"redacted": 0,
|
||||
}
|
||||
@@ -0,0 +1,207 @@
|
||||
"""Reviewed rotated-log cleanup as a maintenance plan (#329 System S12).
|
||||
|
||||
``POST /prompt_manager/maintenance/preview {operation: "rotated_logs",
|
||||
options: {}}`` lists the rotated copies of the active log that Rule R allows
|
||||
(``utils/logging_config.py``: ``prompt_manager.log.<n>`` regular files that
|
||||
are not links, directly in the log folder) and writes nothing. The plan keeps
|
||||
each copy's name, size, ``mtime_ns`` and inode under its token; the response
|
||||
is the maintenance ``Plan`` shape with basenames only, a ``none`` backup
|
||||
policy (no library record changes) and no ``disk`` key.
|
||||
|
||||
``POST /prompt_manager/maintenance/apply {token}`` starts a ``maintenance``
|
||||
job titled "Rotated log copies" with admission ``read``: it may run beside a
|
||||
scan and is refused only beside another maintenance job or an ``exclusive``
|
||||
one. The job deletes exactly the reviewed copies under the logger's files
|
||||
lock and the file handler's lock, or nothing, failing ``plan-changed``, when
|
||||
any of them is missing, is no longer a rotated copy or differs in size,
|
||||
``mtime_ns`` or inode. A copy that cannot be deleted (open in another program
|
||||
on Windows) is an ``errors`` row; the others are deleted.
|
||||
"""
|
||||
|
||||
import datetime
|
||||
import json
|
||||
|
||||
from aiohttp import web
|
||||
|
||||
try:
|
||||
from ...utils.logging_config import RotatedChanged, rotated_sort_key
|
||||
except ImportError: # loaded as the top-level ``py`` package (tests)
|
||||
from utils.logging_config import RotatedChanged, rotated_sort_key
|
||||
|
||||
from .jobs import MAINTENANCE_JOB_KIND
|
||||
from .maintenance_plans import ScopeTooLarge
|
||||
|
||||
ROTATED_LOGS = "rotated_logs"
|
||||
LOG_CLEANUP_TITLE = "Rotated log copies"
|
||||
LOGS_CHANGED = (
|
||||
"The log files changed since the review; nothing was deleted. Review again."
|
||||
)
|
||||
LOG_CLEANUP_FAILED = "The log cleanup failed."
|
||||
TOO_MANY_LOG_FILES = "Too many log files to review at once."
|
||||
LOG_CLEANUP_MEDIA = (
|
||||
"Deletes only the listed log files. No image, video or library record changes."
|
||||
)
|
||||
_GROUPS = ("changed", "protected", "errors")
|
||||
|
||||
|
||||
def size_label(size):
|
||||
"""``1000 bytes``, ``2.0 KB``, ``10.0 MB`` or ``1.2 GB`` (1 KB = 1024 bytes)."""
|
||||
size = max(0, int(size or 0))
|
||||
if size < 1024:
|
||||
return f"{size} {'byte' if size == 1 else 'bytes'}"
|
||||
for unit, scale in (("KB", 2**10), ("MB", 2**20)):
|
||||
if size < scale * 1024:
|
||||
return f"{size / scale:.1f} {unit}"
|
||||
return f"{size / 2**30:.1f} GB"
|
||||
|
||||
|
||||
def time_label(mtime_ns):
|
||||
"""The local modification time as ``YYYY-MM-DD HH:MM``."""
|
||||
try:
|
||||
moment = datetime.datetime.fromtimestamp(mtime_ns / 1e9)
|
||||
except (OSError, OverflowError, ValueError): # a time before 1970 on Windows
|
||||
return "unknown time"
|
||||
return moment.strftime("%Y-%m-%d %H:%M")
|
||||
|
||||
|
||||
def _count(count, singular, plural):
|
||||
return f"{count} {singular if count == 1 else plural}"
|
||||
|
||||
|
||||
def _protected_reasons(rows):
|
||||
"""The plan's Protected reasons: what the cleanup keeps, zero counts left out."""
|
||||
active = sum(1 for row in rows if row["kind"] == "active")
|
||||
links = sum(1 for row in rows if row["kind"] == "link")
|
||||
other = sum(1 for row in rows if row["kind"] == "other")
|
||||
reasons = []
|
||||
if active:
|
||||
reasons.append("Kept: the active log")
|
||||
if links:
|
||||
reasons.append(f"Kept: {_count(links, 'link', 'links')}")
|
||||
if other:
|
||||
reasons.append(f"Kept: {_count(other, 'other file', 'other files')}")
|
||||
return active + links + other, reasons
|
||||
|
||||
|
||||
def _scope_label(files):
|
||||
if not files:
|
||||
return "No rotated log copies"
|
||||
total = sum(row["size"] for row in files)
|
||||
return (
|
||||
f"{_count(len(files), 'rotated log copy', 'rotated log copies')}"
|
||||
f" · {size_label(total)}"
|
||||
)
|
||||
|
||||
|
||||
class LogCleanupMixin:
|
||||
"""The ``rotated_logs`` maintenance plan and its job.
|
||||
|
||||
The logger manager is reached only through ``_get_logger_manager``
|
||||
(``logging_routes.py``), so the tests can point it at a temporary folder.
|
||||
"""
|
||||
|
||||
async def preview_log_cleanup(self):
|
||||
"""The ``rotated_logs`` plan (runs inside the preview's lease)."""
|
||||
from . import maintenance
|
||||
|
||||
manager = self._get_logger_manager()
|
||||
try:
|
||||
rows = await self._run_in_executor(manager.scan_log_folder)
|
||||
except Exception:
|
||||
self.logger.exception("Rotated log review failed")
|
||||
return maintenance._failure("Failed to review maintenance", 500)
|
||||
rotated = sorted(
|
||||
(row for row in rows if row["kind"] == "rotated"),
|
||||
key=rotated_sort_key,
|
||||
)
|
||||
files = [
|
||||
{
|
||||
"name": row["name"],
|
||||
"size": row["size"],
|
||||
"mtime_ns": row["mtime_ns"],
|
||||
"ino": row["ino"],
|
||||
}
|
||||
for row in rotated
|
||||
]
|
||||
protected, reasons = _protected_reasons(rows)
|
||||
store = self._maintenance_plans
|
||||
try:
|
||||
token = store.issue(
|
||||
ROTATED_LOGS,
|
||||
json.dumps(files, sort_keys=True),
|
||||
{"files": files, "protected": protected},
|
||||
(),
|
||||
)
|
||||
except ScopeTooLarge:
|
||||
return maintenance._failure(TOO_MANY_LOG_FILES, 413, "too-large")
|
||||
plan = store.peek(token, ROTATED_LOGS)
|
||||
return web.json_response(
|
||||
{
|
||||
"success": True,
|
||||
"token": token,
|
||||
"operation": ROTATED_LOGS,
|
||||
"expires_at": maintenance._iso(plan.expires_at),
|
||||
"scope": {"count": len(files), "label": _scope_label(files)},
|
||||
"protected": {"count": protected, "reasons": reasons},
|
||||
"backup": {
|
||||
"policy": "none",
|
||||
"destination_label": None,
|
||||
"expected_bytes": None,
|
||||
},
|
||||
"media": {"deletes_files": True, "label": LOG_CLEANUP_MEDIA},
|
||||
"details": [
|
||||
{
|
||||
"label": row["name"],
|
||||
"detail": (
|
||||
f"{size_label(row['size'])} · {time_label(row['mtime_ns'])}"
|
||||
),
|
||||
}
|
||||
for row in files
|
||||
],
|
||||
},
|
||||
headers={"Cache-Control": "no-store"},
|
||||
)
|
||||
|
||||
def _start_log_cleanup(self, plan):
|
||||
"""Register the cleanup job (on the loop); raises JobBusy when refused."""
|
||||
return self._jobs.start(
|
||||
MAINTENANCE_JOB_KIND,
|
||||
LOG_CLEANUP_TITLE,
|
||||
admission="read",
|
||||
cancellable=False,
|
||||
scope={"operation": ROTATED_LOGS},
|
||||
groups=_GROUPS,
|
||||
runner=lambda job: self._run_log_cleanup(job, plan),
|
||||
)
|
||||
|
||||
async def _run_log_cleanup(self, job, plan):
|
||||
from . import maintenance
|
||||
|
||||
files = plan.payload["files"]
|
||||
sizes = {row["name"]: row["size"] for row in files}
|
||||
job.update(total=len(files), status_line="Deleting rotated log copies")
|
||||
manager = self._get_logger_manager()
|
||||
try:
|
||||
result = await self._run_in_executor(manager.delete_rotated, files)
|
||||
except RotatedChanged:
|
||||
return maintenance._fail_job(job, "plan-changed", LOGS_CHANGED)
|
||||
except Exception:
|
||||
self.logger.exception("Rotated log cleanup failed")
|
||||
return maintenance._fail_job(job, None, LOG_CLEANUP_FAILED)
|
||||
for name in result["removed"]:
|
||||
detail = f"Deleted · {size_label(sizes.get(name, 0))}"
|
||||
job.record(
|
||||
"changed", {"path": name, "detail": detail}, f"- {name} · {detail}"
|
||||
)
|
||||
for name, error in result["failed"]:
|
||||
detail = self._public_error(error)
|
||||
job.record(
|
||||
"errors", {"path": name, "detail": detail}, f"! {name} · {detail}"
|
||||
)
|
||||
job.record_counted("protected", plan.payload["protected"])
|
||||
removed, failed = len(result["removed"]), len(result["failed"])
|
||||
line = f"Deleted {_count(removed, 'rotated log copy', 'rotated log copies')}"
|
||||
if failed:
|
||||
line += f", {failed} could not be deleted"
|
||||
job.log_line(line)
|
||||
job.update(processed=len(files), progress=100, status_line=line)
|
||||
@@ -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,41 @@ 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 with
|
||||
one name and, when ``path`` carries it, the inode it was listed with. A
|
||||
name swapped for a link or another file after it was listed, or a hard
|
||||
link to a file elsewhere, 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)
|
||||
# A FIFO swapped in after the listing must not block the executor thread.
|
||||
flags |= getattr(os, "O_NONBLOCK", 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
|
||||
listed_ino = getattr(path, "listed_ino", 0)
|
||||
with os.fdopen(fd, "rb") as handle:
|
||||
opened = os.fstat(handle.fileno())
|
||||
if (
|
||||
not stat.S_ISREG(opened.st_mode)
|
||||
or opened.st_nlink > 1 # a hard link to a file elsewhere
|
||||
or (listed_ino and opened.st_ino and opened.st_ino != listed_ino)
|
||||
):
|
||||
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 +237,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 +266,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 +308,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(
|
||||
{
|
||||
|
||||
+19
-2
@@ -2,7 +2,9 @@
|
||||
|
||||
``POST /prompt_manager/maintenance/preview {operation, options:{}}`` reviews
|
||||
one operation (``duplicate_prompts``, ``optimize``, ``unused_components`` or
|
||||
``missing_links``; ``database/maintenance.py``) off the event loop and
|
||||
``missing_links``; ``database/maintenance.py``; ``duplicate_files``,
|
||||
``py/api/duplicate_files.py``; ``rotated_logs``, the rotated log copies,
|
||||
``py/api/log_cleanup.py``, which has its own apply job) off the event loop and
|
||||
answers a ``Plan``: ``{success, token, operation, expires_at, scope:{count,
|
||||
label}, protected:{count, reasons}, backup:{policy, destination_label},
|
||||
media:{deletes_files, label}, details:[≤50 {label, detail}]}``. The preview
|
||||
@@ -54,6 +56,7 @@ from aiohttp import web
|
||||
from .admin import _prune_safety_backups, _scan_location, _scan_roots
|
||||
from .job_routes import busy_response
|
||||
from .jobs import MAINTENANCE_JOB_KIND, JobBusy
|
||||
from .log_cleanup import ROTATED_LOGS
|
||||
from .maintenance_plans import PlanExpired, PlanUsed, ScopeTooLarge
|
||||
|
||||
try:
|
||||
@@ -83,7 +86,8 @@ MAINTENANCE_PREVIEW_LEASE = "Maintenance preview"
|
||||
DUPLICATE_PREVIEW_BODY_MAX = 1024 * 1024
|
||||
DUPLICATE_FILES = "duplicate_files"
|
||||
WORKFLOW_STORAGE = "workflow_storage" # applied by py/api/workflow_storage.py
|
||||
PREVIEW_OPERATIONS = MAINTENANCE_OPERATIONS + (DUPLICATE_FILES,)
|
||||
# rotated_logs (#329, py/api/log_cleanup.py) reviews log files, not records.
|
||||
PREVIEW_OPERATIONS = MAINTENANCE_OPERATIONS + (DUPLICATE_FILES, ROTATED_LOGS)
|
||||
# Room left over beyond what a step writes, so a disk is never filled to 0.
|
||||
DISK_MARGIN_BYTES = 16 * 2**20
|
||||
# The concept's Maintenance row titles, which name each operation's job.
|
||||
@@ -391,6 +395,8 @@ class MaintenanceRoutesMixin:
|
||||
return await self.preview_duplicate_files(options)
|
||||
if not isinstance(options, dict) or options:
|
||||
return _invalid(f"{operation} takes no options")
|
||||
if operation == ROTATED_LOGS:
|
||||
return await self.preview_log_cleanup()
|
||||
db = self.db
|
||||
identity = self._database_identity(db)
|
||||
try:
|
||||
@@ -492,6 +498,17 @@ class MaintenanceRoutesMixin:
|
||||
if refused is not None:
|
||||
return refused
|
||||
store = self._maintenance_plans
|
||||
if plan.operation == ROTATED_LOGS:
|
||||
# Log files only: no database identity, backup or disk check.
|
||||
try:
|
||||
job = self._start_log_cleanup(plan)
|
||||
except JobBusy as busy:
|
||||
return busy_response(busy) # the token stays usable
|
||||
# Same loop turn as the peek and the start: the runner has not run.
|
||||
store.consume(token, plan.operation, job_id=job.id)
|
||||
return web.json_response(
|
||||
{"success": True, "job": job.summary()}, status=202
|
||||
)
|
||||
db = self.db
|
||||
if plan.db_identity != self._database_identity(db):
|
||||
store.discard(token)
|
||||
|
||||
@@ -0,0 +1,409 @@
|
||||
"""The shareable diagnostic report (#329, py/api/diagnostics_report.py).
|
||||
|
||||
``GET /prompt_manager/system/diagnostics`` builds the report on the server
|
||||
from an explicit list of fields: the project version, the four legacy checks,
|
||||
public paths only and no secret. A scrub replaces anything that still looks
|
||||
like an absolute path or holds the CivitAI key and counts it in ``redacted``;
|
||||
these tests require ``redacted == 0`` so a builder mistake fails instead of
|
||||
being hidden.
|
||||
"""
|
||||
|
||||
import json
|
||||
import ntpath
|
||||
import os
|
||||
import posixpath
|
||||
import re
|
||||
import sqlite3
|
||||
import sys
|
||||
import unittest
|
||||
from unittest import mock
|
||||
from unittest.mock import MagicMock
|
||||
|
||||
_mock_server = MagicMock()
|
||||
_mock_server.PromptServer.instance.routes = MagicMock()
|
||||
sys.modules.setdefault("server", _mock_server)
|
||||
|
||||
sys.path.insert(0, os.path.dirname(os.path.dirname(os.path.abspath(__file__))))
|
||||
|
||||
from py.api import admin, diagnostics_report # noqa: E402
|
||||
from py.api.diagnostics_report import OUTSIDE, report_path, scrub # noqa: E402
|
||||
from py.config import (
|
||||
GalleryConfig,
|
||||
IntegrationConfig,
|
||||
PromptManagerConfig,
|
||||
) # noqa: E402
|
||||
|
||||
try:
|
||||
from tests.test_api_log_cleanup import LogCleanupTestCase # noqa: E402
|
||||
except ImportError: # discovered with tests/ as the top-level directory
|
||||
from test_api_log_cleanup import LogCleanupTestCase # noqa: E402
|
||||
|
||||
REPORT = "/prompt_manager/system/diagnostics"
|
||||
KEY = "civitai-secret-0123456789abcdef"
|
||||
SEEDED_PATHS = (
|
||||
"/home/someone/private/LoraManager",
|
||||
"/srv/someone/renders",
|
||||
"C:\\Users\\someone\\Documents\\renders",
|
||||
"D:/Users/someone/prompts.db",
|
||||
"\\\\nas\\share\\someone\\renders",
|
||||
)
|
||||
_WINDOWS_ABSOLUTE = re.compile(r"^[A-Za-z]:[\\/]")
|
||||
TOP_KEYS = {
|
||||
"success",
|
||||
"generated_at",
|
||||
"version",
|
||||
"python",
|
||||
"platform",
|
||||
"viewerjs",
|
||||
"checks",
|
||||
"database_info",
|
||||
"sources",
|
||||
"logging",
|
||||
"health",
|
||||
"config",
|
||||
"redacted",
|
||||
}
|
||||
CONFIG = {
|
||||
"database": {"enable_duplicate_detection", "enable_auto_save"},
|
||||
"web_ui": {
|
||||
"result_timeout",
|
||||
"show_test_button",
|
||||
"webui_display_mode",
|
||||
"infinite_scroll",
|
||||
},
|
||||
"performance": {
|
||||
"max_search_results",
|
||||
"enable_fuzzy_search",
|
||||
"auto_backup_interval",
|
||||
"worker_threads",
|
||||
},
|
||||
"gallery": {
|
||||
"processing_delay",
|
||||
"prompt_timeout",
|
||||
"cleanup_interval",
|
||||
"auto_cleanup_missing_files",
|
||||
"max_image_age_days",
|
||||
"max_concurrent_processing",
|
||||
"metadata_extraction_timeout",
|
||||
},
|
||||
"integrations": {"lora_manager_enabled", "has_civitai_api_key"},
|
||||
}
|
||||
|
||||
|
||||
def _strings(value):
|
||||
if isinstance(value, str):
|
||||
yield value
|
||||
elif isinstance(value, dict):
|
||||
for key, item in value.items():
|
||||
yield str(key)
|
||||
yield from _strings(item)
|
||||
elif isinstance(value, (list, tuple)):
|
||||
for item in value:
|
||||
yield from _strings(item)
|
||||
|
||||
|
||||
class DiagnosticsReportTestCase(LogCleanupTestCase):
|
||||
"""The admin app with its logger manager on a temporary log folder."""
|
||||
|
||||
async def get_application(self):
|
||||
app = await super().get_application()
|
||||
saved = IntegrationConfig.get_config()
|
||||
self.addCleanup(IntegrationConfig.update_config, saved)
|
||||
return app
|
||||
|
||||
async def report(self, status=200):
|
||||
response = await self.client.request("GET", REPORT)
|
||||
text = await response.text()
|
||||
self.assertEqual(response.status, status, text)
|
||||
return json.loads(text), text
|
||||
|
||||
def seed_secrets(self):
|
||||
IntegrationConfig.update_config(
|
||||
{
|
||||
"lora_manager": {
|
||||
"enabled": True,
|
||||
"path": SEEDED_PATHS[0],
|
||||
"civitai_api_key": KEY,
|
||||
}
|
||||
}
|
||||
)
|
||||
GalleryConfig.MONITORING_DIRECTORIES = list(SEEDED_PATHS[1:3]) + [
|
||||
SEEDED_PATHS[4]
|
||||
]
|
||||
PromptManagerConfig.update_config(
|
||||
{"database": {"default_path": SEEDED_PATHS[3]}}
|
||||
)
|
||||
|
||||
def assert_no_paths_or_key(self, report, text):
|
||||
self.assertNotIn(KEY, text)
|
||||
self.assertNotIn(self.tmpdir, text)
|
||||
self.assertNotIn(self.tmpdir.replace("\\", "/"), text)
|
||||
for seeded in SEEDED_PATHS:
|
||||
self.assertNotIn(seeded, text)
|
||||
self.assertNotIn(json.dumps(seeded)[1:-1], text)
|
||||
self.assertNotIn("someone", text)
|
||||
for value in _strings(report):
|
||||
self.assertFalse(posixpath.isabs(value), value)
|
||||
self.assertFalse(ntpath.isabs(value), value)
|
||||
self.assertIsNone(_WINDOWS_ABSOLUTE.match(value), value)
|
||||
self.assertFalse(value.startswith("\\\\"), value)
|
||||
|
||||
|
||||
class TestReport(DiagnosticsReportTestCase):
|
||||
async def test_report_has_version_viewerjs_and_the_four_checks(self):
|
||||
report, _text = await self.report()
|
||||
self.assertEqual(set(report), TOP_KEYS)
|
||||
self.assertTrue(report["success"])
|
||||
with open(
|
||||
os.path.join(os.path.dirname(os.path.dirname(__file__)), "pyproject.toml"),
|
||||
encoding="utf-8",
|
||||
) as handle:
|
||||
version = re.search(r'version\s*=\s*["\']([^"\']+)["\']', handle.read())
|
||||
self.assertEqual(report["version"], version.group(1))
|
||||
self.assertRegex(report["viewerjs"], r"^\d+\.\d+\.\d+$")
|
||||
self.assertRegex(report["python"], r"^3\.\d+\.\d+")
|
||||
self.assertEqual(set(report["platform"]), {"system", "release"})
|
||||
self.assertEqual(
|
||||
set(report["checks"]),
|
||||
{"database", "dependencies", "comfyui_output", "image_monitor"},
|
||||
)
|
||||
self.assertEqual(report["checks"]["database"]["status"], "ok")
|
||||
self.assertEqual(
|
||||
set(report["sources"]),
|
||||
{"configured", "effective", "watching", "unavailable"},
|
||||
)
|
||||
self.assertEqual(set(report["logging"]), {"config", "stats"})
|
||||
self.assertIsNone(report["health"])
|
||||
self.assertEqual(report["redacted"], 0)
|
||||
self.assertRegex(report["generated_at"], r"^\d{4}-\d\d-\d\dT\d\d:\d\d:\d\d$")
|
||||
|
||||
async def test_report_has_no_secret_or_absolute_path(self):
|
||||
self.seed_secrets()
|
||||
with mock.patch.object(
|
||||
admin.sqlite3,
|
||||
"connect",
|
||||
side_effect=sqlite3.DatabaseError("file is not a database"),
|
||||
):
|
||||
report, text = await self.report()
|
||||
self.assertEqual(report["checks"]["database"]["status"], "error")
|
||||
self.assertTrue(report["config"]["integrations"]["has_civitai_api_key"])
|
||||
self.assertTrue(report["config"]["integrations"]["lora_manager_enabled"])
|
||||
self.assertEqual(report["sources"]["configured"], 3)
|
||||
self.assert_no_paths_or_key(report, text)
|
||||
self.assertEqual(report["redacted"], 0)
|
||||
|
||||
async def test_report_leaves_get_config_unchanged(self):
|
||||
self.seed_secrets()
|
||||
before = json.dumps(PromptManagerConfig.get_config(), sort_keys=True)
|
||||
directories = GalleryConfig.MONITORING_DIRECTORIES
|
||||
await self.report()
|
||||
self.assertEqual(
|
||||
json.dumps(PromptManagerConfig.get_config(), sort_keys=True), before
|
||||
)
|
||||
self.assertIs(GalleryConfig.MONITORING_DIRECTORIES, directories)
|
||||
self.assertEqual(IntegrationConfig.CIVITAI_API_KEY, KEY)
|
||||
|
||||
def test_outside_path_reads_outside_comfyui(self):
|
||||
inside = os.path.join(str(self.comfy_dir), "user", "__promptmanager", "logs")
|
||||
self.assertEqual(report_path(inside), "user/__promptmanager/logs")
|
||||
self.assertEqual(
|
||||
report_path(os.path.join(str(self.outside_dir), "vito")), "outside ComfyUI"
|
||||
)
|
||||
self.assertEqual(report_path(""), "")
|
||||
self.assertEqual(report_path(None), "")
|
||||
|
||||
def test_a_filesystem_root_anchor_never_makes_a_path_public(self):
|
||||
# --output-directory /renders makes "/" an anchor; a path outside
|
||||
# ComfyUI must still read "outside ComfyUI", never "home/<user>/...".
|
||||
root = os.path.abspath(os.sep)
|
||||
anchors = [str(self.comfy_dir), root]
|
||||
with mock.patch.object(GalleryConfig, "path_anchors", return_value=anchors):
|
||||
self.assertEqual(
|
||||
report_path(os.path.join(str(self.outside_dir), "x")), OUTSIDE
|
||||
)
|
||||
self.assertEqual(
|
||||
report_path(os.path.join(str(self.comfy_dir), "output")), "output"
|
||||
)
|
||||
|
||||
def test_scrub_removes_the_home_folder_without_its_root(self):
|
||||
home = os.path.expanduser("~")
|
||||
relative = os.path.splitdrive(home)[1].lstrip("\\/").replace("\\", "/")
|
||||
cleaned = scrub({"a": f"{relative}/area/prompts.db", "redacted": 0}, None)
|
||||
self.assertEqual(cleaned, {"a": "[removed]", "redacted": 1})
|
||||
|
||||
def test_the_home_folder_is_matched_as_a_whole_path_part(self):
|
||||
with mock.patch.object(
|
||||
diagnostics_report.os.path, "expanduser", return_value="/root"
|
||||
):
|
||||
cleaned = scrub(
|
||||
{
|
||||
"a": "output/rootfiles",
|
||||
"b": "output/root/x",
|
||||
"c": "see /root/x",
|
||||
"redacted": 0,
|
||||
},
|
||||
None,
|
||||
)
|
||||
self.assertEqual(cleaned["a"], "output/rootfiles")
|
||||
# The home folder's name is a whole path part here: removed.
|
||||
self.assertEqual(cleaned["b"], "[removed]")
|
||||
self.assertEqual(cleaned["c"], "[removed]")
|
||||
self.assertEqual(cleaned["redacted"], 2)
|
||||
|
||||
async def test_report_reads_only_the_temporary_log_folder(self):
|
||||
self.write("prompt_manager.log.1", b"x" * 1234)
|
||||
report, _text = await self.report()
|
||||
stats = report["logging"]["stats"]
|
||||
self.assertEqual(stats["log_files_count"], 2)
|
||||
self.assertEqual(
|
||||
stats["total_log_size"],
|
||||
1234 + os.path.getsize(self.path("prompt_manager.log")),
|
||||
)
|
||||
|
||||
def test_an_ancestor_of_home_is_never_an_anchor_on_linux(self):
|
||||
anchored = diagnostics_report.anchored_path
|
||||
home = "/home/someone"
|
||||
anchors = ["/home", "/opt/ComfyUI"]
|
||||
self.assertEqual(
|
||||
anchored("/home/someone/renders/a.png", anchors, home, posixpath), OUTSIDE
|
||||
)
|
||||
self.assertEqual(
|
||||
anchored("/home/other/renders", anchors, home, posixpath), OUTSIDE
|
||||
)
|
||||
self.assertEqual(
|
||||
anchored("/opt/ComfyUI/output", anchors, home, posixpath), "output"
|
||||
)
|
||||
|
||||
def test_an_ancestor_of_home_is_never_an_anchor_on_windows(self):
|
||||
anchored = diagnostics_report.anchored_path
|
||||
home = ntpath.normcase("C:\\Users\\someone")
|
||||
anchors = [ntpath.normcase(a) for a in ("C:\\Users", "C:\\", "D:\\ComfyUI")]
|
||||
path = ntpath.normcase("C:\\Users\\someone\\renders\\a.png")
|
||||
self.assertEqual(anchored(path, anchors, home, ntpath), OUTSIDE)
|
||||
inside = ntpath.normcase("D:\\ComfyUI\\output\\x")
|
||||
self.assertEqual(anchored(inside, anchors, home, ntpath), "output/x")
|
||||
|
||||
def test_an_anchor_that_is_home_names_no_user(self):
|
||||
anchored = diagnostics_report.anchored_path
|
||||
home = "/home/someone"
|
||||
self.assertEqual(
|
||||
anchored("/home/someone/ComfyUI/output", [home], home, posixpath),
|
||||
"ComfyUI/output",
|
||||
)
|
||||
self.assertEqual(
|
||||
anchored(
|
||||
"/home/someone/ComfyUI/output",
|
||||
[home, "/home/someone/ComfyUI"],
|
||||
home,
|
||||
posixpath,
|
||||
),
|
||||
"output",
|
||||
)
|
||||
|
||||
def test_the_home_folder_name_is_removed_only_from_paths(self):
|
||||
with mock.patch.object(
|
||||
diagnostics_report.os.path, "expanduser", return_value="/home/info"
|
||||
):
|
||||
cleaned = scrub({"level": "INFO", "p": "logs/info/x", "redacted": 0}, None)
|
||||
self.assertEqual(cleaned, {"level": "INFO", "p": "[removed]", "redacted": 1})
|
||||
|
||||
def test_scrub_removes_the_home_folder_name(self):
|
||||
with mock.patch.object(
|
||||
diagnostics_report.os.path, "expanduser", return_value="/home/someone"
|
||||
):
|
||||
cleaned = scrub(
|
||||
{"a": "someone/renders", "b": "someones", "redacted": 0}, None
|
||||
)
|
||||
self.assertEqual(cleaned["a"], "[removed]")
|
||||
self.assertEqual(cleaned["b"], "someones")
|
||||
|
||||
def test_scrub_removes_a_leaked_path_and_counts_it(self):
|
||||
leaked = {
|
||||
"a": "/home/someone/x",
|
||||
"b": ["C:\\Users\\someone", "D:/data", "\\\\nas\\share", "ok"],
|
||||
"c": {"d": f"token {KEY} here", "e": 3, "f": None, "g": "relative/path"},
|
||||
"redacted": 0,
|
||||
}
|
||||
cleaned = scrub(leaked, KEY)
|
||||
self.assertEqual(cleaned["redacted"], 5)
|
||||
self.assertEqual(cleaned["a"], "[removed]")
|
||||
self.assertEqual(cleaned["b"], ["[removed]"] * 3 + ["ok"])
|
||||
self.assertEqual(
|
||||
cleaned["c"], {"d": "[removed]", "e": 3, "f": None, "g": "relative/path"}
|
||||
)
|
||||
# A short key is not searched for (it would match ordinary words).
|
||||
self.assertEqual(scrub({"x": "abc", "redacted": 0}, "abc")["redacted"], 0)
|
||||
|
||||
async def test_report_refused_while_exclusive_job_runs(self):
|
||||
async with self.api._jobs.hold(
|
||||
"restore", "Database restore", admission="exclusive"
|
||||
) as restore:
|
||||
report, _text = await self.report(status=409)
|
||||
self.assertEqual(report["code"], "busy")
|
||||
self.assertEqual(
|
||||
report["running"], {"id": restore.id, "title": "Database restore"}
|
||||
)
|
||||
|
||||
async def test_report_lists_config_only_keys(self):
|
||||
self.seed_secrets()
|
||||
report, _text = await self.report()
|
||||
self.assertEqual({k: set(v) for k, v in report["config"].items()}, CONFIG)
|
||||
self.assertNotIn("default_path", json.dumps(report["config"]))
|
||||
self.assertNotIn("directories", json.dumps(report["config"]))
|
||||
self.assertNotIn(
|
||||
"civitai_api_key",
|
||||
json.dumps(report["config"]).replace("has_civitai_api_key", ""),
|
||||
)
|
||||
|
||||
async def test_report_logging_has_public_directory(self):
|
||||
report, _text = await self.report()
|
||||
stats = report["logging"]["stats"]
|
||||
self.assertFalse(posixpath.isabs(stats["log_directory"]))
|
||||
self.assertIn("level", report["logging"]["config"])
|
||||
|
||||
async def test_report_survives_an_unreadable_viewerjs_provenance(self):
|
||||
with mock.patch.object(
|
||||
diagnostics_report,
|
||||
"VIEWERJS_PROVENANCE",
|
||||
os.path.join(self.tmpdir, "nope.json"),
|
||||
):
|
||||
report, _text = await self.report()
|
||||
self.assertEqual(report["viewerjs"], "unknown")
|
||||
|
||||
async def test_a_build_failure_is_coded_without_details(self):
|
||||
with mock.patch.object(
|
||||
self.api, "build_report", side_effect=RuntimeError(self.tmpdir)
|
||||
):
|
||||
with self.assertLogs("prompt_manager", "ERROR"):
|
||||
report, text = await self.report(status=500)
|
||||
self.assertNotIn(self.tmpdir, text)
|
||||
self.assertFalse(report["success"])
|
||||
|
||||
|
||||
class TestLegacyDiagnostics(DiagnosticsReportTestCase):
|
||||
async def test_legacy_diagnostics_keeps_its_four_checks(self):
|
||||
response = await self.client.request("GET", "/prompt_manager/diagnostics")
|
||||
data = await response.json()
|
||||
self.assertEqual(response.status, 200)
|
||||
self.assertEqual(set(data), {"success", "diagnostics"})
|
||||
self.assertEqual(
|
||||
set(data["diagnostics"]),
|
||||
{"database", "dependencies", "comfyui_output", "image_monitor"},
|
||||
)
|
||||
report, _text = await self.report()
|
||||
self.assertEqual(report["checks"]["database"], data["diagnostics"]["database"])
|
||||
self.assertEqual(
|
||||
report["checks"]["dependencies"], data["diagnostics"]["dependencies"]
|
||||
)
|
||||
|
||||
async def test_both_routes_build_their_checks_with_one_helper(self):
|
||||
with mock.patch.object(
|
||||
admin, "legacy_checks", wraps=admin.legacy_checks
|
||||
) as spy:
|
||||
await self.client.request("GET", "/prompt_manager/diagnostics")
|
||||
await self.report()
|
||||
self.assertEqual(spy.call_count, 2)
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
unittest.main()
|
||||
@@ -0,0 +1,419 @@
|
||||
"""Reviewed rotated-log cleanup as a maintenance plan (#329, py/api/log_cleanup.py).
|
||||
|
||||
``POST /maintenance/preview {operation: "rotated_logs"}`` lists exactly the
|
||||
rotated copies Rule R allows and writes nothing; ``POST /maintenance/apply``
|
||||
deletes exactly those as a ``maintenance`` job (admission ``read``), or
|
||||
nothing, failing ``plan-changed``, when any of them changed after the review.
|
||||
|
||||
Every test runs on a real ``PromptManagerLogger`` whose log folder is a
|
||||
temporary folder, never the real one.
|
||||
"""
|
||||
|
||||
import asyncio
|
||||
import json
|
||||
import logging
|
||||
import ntpath
|
||||
import os
|
||||
import posixpath
|
||||
import re
|
||||
import sys
|
||||
import threading
|
||||
import unittest
|
||||
import unittest.mock as mock
|
||||
|
||||
sys.path.insert(0, os.path.dirname(os.path.dirname(os.path.abspath(__file__))))
|
||||
|
||||
from py.api.maintenance_plans import PlanStore # noqa: E402
|
||||
from utils import logging_config # noqa: E402
|
||||
from utils.logging_config import PromptManagerLogger, get_logger_manager # noqa: E402
|
||||
|
||||
try:
|
||||
from tests.open_handles import assert_closed # noqa: E402
|
||||
from tests.test_api_maintenance import MaintenanceAPITestCase # noqa: E402
|
||||
except ImportError: # discovered with tests/ as the top-level directory
|
||||
from open_handles import assert_closed # noqa: E402
|
||||
from test_api_maintenance import MaintenanceAPITestCase # noqa: E402
|
||||
|
||||
WAIT = 10
|
||||
PREVIEW = "/prompt_manager/maintenance/preview"
|
||||
APPLY = "/prompt_manager/maintenance/apply"
|
||||
CHANGED = "The log files changed since the review; nothing was deleted. Review again."
|
||||
MEDIA = "Deletes only the listed log files. No image, video or library record changes."
|
||||
_WINDOWS_ABSOLUTE = re.compile(r"^[A-Za-z]:[\\/]")
|
||||
|
||||
|
||||
def _strings(value):
|
||||
if isinstance(value, str):
|
||||
yield value
|
||||
elif isinstance(value, dict):
|
||||
for item in value.values():
|
||||
yield from _strings(item)
|
||||
elif isinstance(value, (list, tuple)):
|
||||
for item in value:
|
||||
yield from _strings(item)
|
||||
|
||||
|
||||
class LogCleanupTestCase(MaintenanceAPITestCase):
|
||||
async def get_application(self):
|
||||
app = await super().get_application()
|
||||
package = os.path.join(self.tmpdir, "pkg")
|
||||
os.makedirs(os.path.join(package, "utils"))
|
||||
fake_file = os.path.join(package, "utils", "logging_config.py")
|
||||
with mock.patch.object(logging_config, "__file__", fake_file):
|
||||
self.manager = object.__new__(PromptManagerLogger) # bypass singleton
|
||||
self.manager.__init__()
|
||||
self.addCleanup(self._restore_global_logging)
|
||||
self.manager.update_config({"console_logging": False})
|
||||
self._only_this_thread()
|
||||
self.log_dir = str(self.manager.log_dir)
|
||||
self.app_logger = logging.getLogger("prompt_manager.log_cleanup_test")
|
||||
self.app_logger.info("active log line")
|
||||
self.api._get_logger_manager = lambda: self.manager
|
||||
self.outside = os.path.join(self.tmpdir, "link-targets")
|
||||
os.makedirs(self.outside)
|
||||
return app
|
||||
|
||||
def _only_this_thread(self):
|
||||
"""Only this test's records reach the temporary log (not other threads')."""
|
||||
this_thread = threading.get_ident()
|
||||
for handler in self.manager.logger.handlers:
|
||||
handler.filters.clear()
|
||||
handler.addFilter(lambda record: record.thread == this_thread)
|
||||
|
||||
def _restore_global_logging(self):
|
||||
for handler in logging.getLogger("prompt_manager").handlers[:]:
|
||||
handler.close()
|
||||
assert_closed(self, self.log_dir)
|
||||
get_logger_manager()._setup_loggers()
|
||||
|
||||
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)
|
||||
|
||||
def symlink(self, name):
|
||||
target = os.path.join(self.outside, "secret.txt")
|
||||
with open(target, "wb") as handle:
|
||||
handle.write(b"secret " * 100)
|
||||
try:
|
||||
os.symlink(target, self.path(name))
|
||||
except (OSError, NotImplementedError): # pragma: no cover - no privilege
|
||||
return False
|
||||
return True
|
||||
|
||||
def names(self):
|
||||
return sorted(os.listdir(self.log_dir))
|
||||
|
||||
def snapshot(self):
|
||||
"""Every entry but the active log, with its bytes (None for a folder)."""
|
||||
state = {}
|
||||
for name in self.names():
|
||||
if name == "prompt_manager.log":
|
||||
continue
|
||||
path = self.path(name)
|
||||
if os.path.islink(path):
|
||||
state[name] = ("link", os.readlink(path))
|
||||
elif os.path.isdir(path):
|
||||
state[name] = None
|
||||
else:
|
||||
with open(path, "rb") as handle:
|
||||
state[name] = handle.read()
|
||||
return state
|
||||
|
||||
def seed(self):
|
||||
"""CUJ 5's folder: three rotated copies, a .bak, a folder and a link."""
|
||||
self.write("prompt_manager.log.1", b"a" * 1000)
|
||||
self.write("prompt_manager.log.2", b"b" * 2000)
|
||||
self.write("prompt_manager.log.3", b"c" * 3000)
|
||||
self.write("prompt_manager.log.bak", b"mine")
|
||||
os.makedirs(self.path("prompt_manager.log.9"))
|
||||
return self.symlink("prompt_manager.log.4")
|
||||
|
||||
async def preview(self, status=200, **body):
|
||||
return await self.post(
|
||||
PREVIEW, {"operation": "rotated_logs", "options": {}, **body}, status
|
||||
)
|
||||
|
||||
async def apply(self, token, status=202):
|
||||
return await self.post(APPLY, {"token": token}, status)
|
||||
|
||||
async def run_apply(self, plan):
|
||||
body = await self.apply(plan["token"])
|
||||
job = self.api._jobs.get(body["job"]["id"])
|
||||
await asyncio.wait_for(asyncio.shield(job.task), WAIT)
|
||||
return body["job"], job
|
||||
|
||||
|
||||
class TestPreview(LogCleanupTestCase):
|
||||
async def test_preview_lists_only_rotated_copies(self):
|
||||
linked = self.seed()
|
||||
plan = await self.preview()
|
||||
self.assertEqual(
|
||||
set(plan),
|
||||
{
|
||||
"success",
|
||||
"token",
|
||||
"operation",
|
||||
"expires_at",
|
||||
"scope",
|
||||
"protected",
|
||||
"backup",
|
||||
"media",
|
||||
"details",
|
||||
},
|
||||
)
|
||||
self.assertEqual(plan["operation"], "rotated_logs")
|
||||
self.assertEqual(
|
||||
plan["scope"], {"count": 3, "label": "3 rotated log copies · 5.9 KB"}
|
||||
)
|
||||
self.assertEqual(
|
||||
[row["label"] for row in plan["details"]],
|
||||
["prompt_manager.log.1", "prompt_manager.log.2", "prompt_manager.log.3"],
|
||||
)
|
||||
self.assertRegex(
|
||||
plan["details"][2]["detail"], r"^2\.9 KB · \d{4}-\d\d-\d\d \d\d:\d\d$"
|
||||
)
|
||||
reasons = ["Kept: the active log"]
|
||||
if linked:
|
||||
reasons.append("Kept: 1 link")
|
||||
reasons.append("Kept: 2 other files")
|
||||
self.assertEqual(
|
||||
plan["protected"], {"count": len(reasons) + 1, "reasons": reasons}
|
||||
)
|
||||
self.assertEqual(
|
||||
plan["backup"],
|
||||
{"policy": "none", "destination_label": None, "expected_bytes": None},
|
||||
)
|
||||
self.assertEqual(plan["media"], {"deletes_files": True, "label": MEDIA})
|
||||
self.assertTrue(plan["expires_at"].endswith("+00:00"))
|
||||
self.assertNotIn("mtime_ns", json.dumps(plan))
|
||||
|
||||
async def test_preview_writes_nothing(self):
|
||||
self.seed()
|
||||
before = self.snapshot()
|
||||
await self.preview()
|
||||
self.assertEqual(self.snapshot(), before)
|
||||
|
||||
async def test_preview_has_no_paths(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
for text in _strings(plan):
|
||||
self.assertFalse(posixpath.isabs(text), text)
|
||||
self.assertFalse(ntpath.isabs(text), text)
|
||||
self.assertIsNone(_WINDOWS_ABSOLUTE.match(text), text)
|
||||
|
||||
async def test_preview_rejects_non_empty_options(self):
|
||||
for options in ({"all": True}, [], "x"):
|
||||
with self.subTest(options=options):
|
||||
reply = await self.preview(status=400, options=options)
|
||||
self.assertEqual(reply["code"], "invalid-request")
|
||||
|
||||
async def test_preview_too_large_is_413(self):
|
||||
self.seed()
|
||||
self.api._maintenance_plans = PlanStore(max_bytes=10)
|
||||
reply = await self.preview(status=413)
|
||||
self.assertEqual(
|
||||
reply,
|
||||
{
|
||||
"success": False,
|
||||
"code": "too-large",
|
||||
"error": "Too many log files to review at once.",
|
||||
},
|
||||
)
|
||||
|
||||
async def test_empty_folder_plan_has_scope_zero(self):
|
||||
plan = await self.preview()
|
||||
self.assertEqual(plan["scope"], {"count": 0, "label": "No rotated log copies"})
|
||||
self.assertEqual(plan["details"], [])
|
||||
self.assertEqual(
|
||||
plan["protected"], {"count": 1, "reasons": ["Kept: the active log"]}
|
||||
)
|
||||
|
||||
async def test_preview_refused_while_an_exclusive_job_runs(self):
|
||||
async with self.api._jobs.hold(
|
||||
"restore", "Database restore", admission="exclusive"
|
||||
):
|
||||
reply = await self.preview(status=409)
|
||||
self.assertEqual(reply["code"], "busy")
|
||||
|
||||
|
||||
class TestApply(LogCleanupTestCase):
|
||||
async def test_apply_deletes_exactly_the_reviewed_files(self):
|
||||
linked = self.seed()
|
||||
plan = await self.preview()
|
||||
summary, job = await self.run_apply(plan)
|
||||
self.assertEqual(summary["kind"], "maintenance")
|
||||
self.assertEqual(summary["title"], "Rotated log copies")
|
||||
self.assertEqual(summary["admission"], "read")
|
||||
self.assertFalse(summary["cancellable"])
|
||||
self.assertEqual(summary["scope"], {"operation": "rotated_logs"})
|
||||
self.assertEqual(job.state, "finished", job.log)
|
||||
self.assertEqual(
|
||||
job.counters,
|
||||
{"changed": 3, "protected": plan["protected"]["count"], "errors": 0},
|
||||
)
|
||||
expected = [
|
||||
"prompt_manager.log",
|
||||
"prompt_manager.log.9",
|
||||
"prompt_manager.log.bak",
|
||||
]
|
||||
if linked:
|
||||
expected.append("prompt_manager.log.4")
|
||||
self.assertEqual(self.names(), sorted(expected))
|
||||
self.assertEqual(job.status_line, "Deleted 3 rotated log copies")
|
||||
report = json.dumps(job.report())
|
||||
self.assertNotIn(self.tmpdir, report)
|
||||
|
||||
async def test_apply_rows_name_each_file(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
_summary, job = await self.run_apply(plan)
|
||||
self.assertEqual(
|
||||
job.outcomes["changed"],
|
||||
[
|
||||
{
|
||||
"path": "prompt_manager.log.1",
|
||||
"root": "",
|
||||
"root_index": None,
|
||||
"detail": "Deleted · 1000 bytes",
|
||||
},
|
||||
{
|
||||
"path": "prompt_manager.log.2",
|
||||
"root": "",
|
||||
"root_index": None,
|
||||
"detail": "Deleted · 2.0 KB",
|
||||
},
|
||||
{
|
||||
"path": "prompt_manager.log.3",
|
||||
"root": "",
|
||||
"root_index": None,
|
||||
"detail": "Deleted · 2.9 KB",
|
||||
},
|
||||
],
|
||||
)
|
||||
log = "\n".join(job.log)
|
||||
for n in (1, 2, 3):
|
||||
self.assertIn(f"prompt_manager.log.{n}", log)
|
||||
|
||||
async def test_apply_after_rollover_fails_plan_changed_and_deletes_nothing(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
handler = next(
|
||||
h
|
||||
for h in self.manager.logger.handlers
|
||||
if isinstance(h, logging.FileHandler)
|
||||
)
|
||||
handler.acquire()
|
||||
try:
|
||||
handler.doRollover() # every listed name now holds another file
|
||||
finally:
|
||||
handler.release()
|
||||
before = self.snapshot()
|
||||
_summary, job = await self.run_apply(plan)
|
||||
self.assertEqual(job.state, "failed")
|
||||
self.assertEqual(job.scope["failure"], "plan-changed")
|
||||
self.assertEqual(job.status_line, CHANGED)
|
||||
self.assertEqual(job.counters["changed"], 0)
|
||||
self.assertEqual(self.snapshot(), before)
|
||||
|
||||
async def test_apply_reports_a_file_in_use(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
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):
|
||||
_summary, job = await self.run_apply(plan)
|
||||
self.assertEqual(job.counters["changed"], 2)
|
||||
self.assertEqual(job.counters["errors"], 1)
|
||||
[row] = job.outcomes["errors"]
|
||||
self.assertEqual(row["path"], "prompt_manager.log.2")
|
||||
self.assertIn("being used by another process", row["detail"])
|
||||
self.assertNotIn(self.tmpdir, json.dumps(job.report()))
|
||||
self.assertIn("prompt_manager.log.2", self.names())
|
||||
self.assertEqual(
|
||||
job.status_line, "Deleted 2 rotated log copies, 1 could not be deleted"
|
||||
)
|
||||
|
||||
async def test_token_is_single_use(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
summary, _job = await self.run_apply(plan)
|
||||
again = await self.apply(plan["token"], 409)
|
||||
self.assertEqual(again["code"], "plan-used")
|
||||
self.assertEqual(
|
||||
again["job"], {"id": summary["id"], "title": "Rotated log copies"}
|
||||
)
|
||||
|
||||
async def test_apply_runs_beside_a_scan(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
async with self.api._jobs.hold("scan", "Metadata scan", admission="records"):
|
||||
_summary, job = await self.run_apply(plan)
|
||||
self.assertEqual(job.state, "finished", job.log)
|
||||
self.assertNotIn("prompt_manager.log.1", self.names())
|
||||
|
||||
async def test_apply_refused_while_restore_runs(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
async with self.api._jobs.hold(
|
||||
"restore", "Database restore", admission="exclusive"
|
||||
) as restore:
|
||||
busy = await self.apply(plan["token"], 409)
|
||||
self.assertEqual(busy["code"], "busy")
|
||||
self.assertEqual(
|
||||
busy["running"], {"id": restore.id, "title": "Database restore"}
|
||||
)
|
||||
self.assertIn("prompt_manager.log.1", self.names())
|
||||
# The refused apply kept the token.
|
||||
_summary, job = await self.run_apply(plan)
|
||||
self.assertEqual(job.state, "finished", job.log)
|
||||
|
||||
async def test_apply_refused_beside_another_maintenance_job(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
async with self.api._jobs.hold(
|
||||
"maintenance", "Optimize database", admission="records"
|
||||
):
|
||||
busy = await self.apply(plan["token"], 409)
|
||||
self.assertEqual(busy["code"], "busy")
|
||||
|
||||
async def test_active_log_survives_and_keeps_growing(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
await self.run_apply(plan)
|
||||
self.app_logger.info("written after the cleanup")
|
||||
with open(self.path("prompt_manager.log"), "rb") as handle:
|
||||
content = handle.read()
|
||||
self.assertIn(b"active log line", content)
|
||||
self.assertIn(b"written after the cleanup", content)
|
||||
|
||||
async def test_an_unexpected_failure_fails_the_job_without_details(self):
|
||||
self.seed()
|
||||
plan = await self.preview()
|
||||
with mock.patch.object(
|
||||
self.manager, "delete_rotated", side_effect=RuntimeError(self.tmpdir)
|
||||
):
|
||||
with self.assertLogs("prompt_manager", "ERROR"):
|
||||
_summary, job = await self.run_apply(plan)
|
||||
self.assertEqual(job.state, "failed")
|
||||
self.assertNotIn(self.tmpdir, json.dumps(job.report()))
|
||||
self.assertEqual(job.status_line, "The log cleanup failed.")
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
unittest.main()
|
||||
+183
-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,129 @@ 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_refuses_a_hard_link(self):
|
||||
secret = Path(self.tmpdir) / "secret.txt"
|
||||
secret.write_text("the key")
|
||||
try:
|
||||
os.link(secret, self.log_dir / "prompt_manager.log.3")
|
||||
except (OSError, NotImplementedError): # pragma: no cover
|
||||
self.skipTest("this filesystem cannot create hard links")
|
||||
resp = await self.client.request(
|
||||
"GET", "/prompt_manager/logs/download/prompt_manager.log.3"
|
||||
)
|
||||
self.assertEqual(resp.status, 404)
|
||||
self.assertNotIn("the key", await resp.text())
|
||||
|
||||
async def test_download_refuses_a_file_swapped_after_it_was_listed(self):
|
||||
(self.log_dir / "prompt_manager.log.2").write_text("listed")
|
||||
other = Path(self.tmpdir) / "other.txt"
|
||||
other.write_text("swapped in")
|
||||
real_entry = self.manager.log_file_entry
|
||||
|
||||
def entry_then_swap(name):
|
||||
path = real_entry(name)
|
||||
os.replace(other, path) # another file now has the listed name
|
||||
return path
|
||||
|
||||
self.manager.log_file_entry = entry_then_swap
|
||||
resp = await self.client.request(
|
||||
"GET", "/prompt_manager/logs/download/prompt_manager.log.2"
|
||||
)
|
||||
self.assertEqual(resp.status, 404)
|
||||
self.assertNotIn("swapped in", await resp.text())
|
||||
|
||||
@unittest.skipUnless(hasattr(os, "mkfifo"), "FIFOs are POSIX only")
|
||||
async def test_download_refuses_a_fifo_without_blocking(self):
|
||||
os.mkfifo(self.log_dir / "pipe.log")
|
||||
resp = await self.client.request(
|
||||
"GET", "/prompt_manager/logs/download/pipe.log"
|
||||
)
|
||||
self.assertEqual(resp.status, 404)
|
||||
|
||||
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 +533,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,8 +1,10 @@
|
||||
"""PromptManagerLogger: memory buffer, file rotation, level changes, truncation."""
|
||||
|
||||
import logging
|
||||
import ntpath
|
||||
import os
|
||||
import pathlib
|
||||
import stat
|
||||
import sys
|
||||
import tempfile
|
||||
import threading
|
||||
@@ -11,14 +13,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 +40,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 +62,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 +193,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 +245,522 @@ 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)
|
||||
|
||||
@unittest.skipIf(os.name == "nt", "Windows cannot rename a log that is open")
|
||||
def test_truncate_never_empties_a_renamed_log_the_handler_still_writes(self):
|
||||
# The user renamed the active log to keep it; the handler still has it
|
||||
# open. Clear must empty the new prompt_manager.log, not the kept copy.
|
||||
self.logger.info("worth keeping")
|
||||
kept = os.path.join(self.log_dir, "saved_copy.txt")
|
||||
os.rename(self._path("prompt_manager.log"), kept)
|
||||
with open(kept, "rb") as handle:
|
||||
before = handle.read()
|
||||
self._write("prompt_manager.log", b"fresh active log\n")
|
||||
result = self.manager.truncate_logs()
|
||||
self.assertEqual(result["errors"], [])
|
||||
with open(kept, "rb") as handle:
|
||||
self.assertTrue(handle.read().startswith(before))
|
||||
with open(self._path("prompt_manager.log"), "rb") as handle:
|
||||
self.assertEqual(handle.read(), b"")
|
||||
|
||||
def test_name_surrogate_reparse_points_are_links_and_placeholders_are_not(self):
|
||||
regular = stat.S_IFREG | 0o644
|
||||
path = self._write("prompt_manager.log.3")
|
||||
for tag, is_link in (
|
||||
(0xA000001D, True), # WSL symlink
|
||||
(0xA0000003, True), # mount point (junction)
|
||||
(0x9000001A, False), # OneDrive cloud placeholder: a regular file
|
||||
(0, False),
|
||||
):
|
||||
with self.subTest(tag=hex(tag)):
|
||||
st = mock.Mock(st_mode=regular, st_reparse_tag=tag)
|
||||
self.assertIs(logging_config._is_link(path, st), is_link)
|
||||
|
||||
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_an_unreadable_timestamp_does_not_break_the_scan(self):
|
||||
self._write("prompt_manager.log.1")
|
||||
real = logging_config.datetime
|
||||
|
||||
class Clock:
|
||||
@staticmethod
|
||||
def fromtimestamp(value):
|
||||
raise OSError(22, "Invalid argument")
|
||||
|
||||
with mock.patch.object(logging_config, "datetime", Clock):
|
||||
rows = {r["name"]: r for r in self.manager.scan_log_folder()}
|
||||
self.assertIs(logging_config.datetime, real)
|
||||
self.assertEqual(rows["prompt_manager.log.1"]["kind"], "rotated")
|
||||
self.assertEqual(rows["prompt_manager.log.1"]["modified"], "")
|
||||
|
||||
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):
|
||||
|
||||
+304
-45
@@ -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,160 @@ 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
|
||||
|
||||
|
||||
# Windows reparse tags with the name-surrogate bit name another file or
|
||||
# folder (symlinks, junctions, WSL symlinks); cloud placeholders do not.
|
||||
_NAME_SURROGATE = 0x20000000
|
||||
|
||||
|
||||
def _is_link(path: str, st: os.stat_result) -> bool:
|
||||
if getattr(st, "st_reparse_tag", 0) & _NAME_SURROGATE:
|
||||
return True
|
||||
return stat.S_ISLNK(st.st_mode) or os.path.isjunction(path)
|
||||
|
||||
|
||||
class LogFilePath(type(Path())):
|
||||
"""A listed log file's path, with the inode it had when it was listed."""
|
||||
|
||||
listed_ino = 0
|
||||
|
||||
|
||||
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
|
||||
try:
|
||||
modified = datetime.fromtimestamp(st.st_mtime).isoformat()
|
||||
except (OSError, OverflowError, ValueError): # a time before 1970 on Windows
|
||||
modified = ""
|
||||
rows.append(
|
||||
{
|
||||
"name": name,
|
||||
"kind": kind,
|
||||
"size": st.st_size,
|
||||
"mtime_ns": st.st_mtime_ns,
|
||||
"ino": st.st_ino,
|
||||
"modified": modified,
|
||||
"_dir": stat.S_ISDIR(st.st_mode) and kind != "link",
|
||||
"_regular": stat.S_ISREG(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 not row["_regular"]: # a folder, FIFO, socket or device
|
||||
break
|
||||
entry = LogFilePath(log_dir, row["name"])
|
||||
entry.listed_ino = row["ino"]
|
||||
return entry
|
||||
raise FileNotFoundError("Log file not found")
|
||||
|
||||
|
||||
def _stream_is(stream, ino: int) -> bool:
|
||||
"""Whether ``stream`` is open on the file with inode ``ino`` (0: unknown)."""
|
||||
try:
|
||||
open_ino = os.fstat(stream.fileno()).st_ino
|
||||
except (OSError, ValueError, AttributeError):
|
||||
return False
|
||||
return not (ino and open_ino and open_ino != ino)
|
||||
|
||||
|
||||
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 +244,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 +398,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 +413,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,14 +471,44 @@ class PromptManagerLogger:
|
||||
self.logger.error(f"Error reading log file {filename}: {e}")
|
||||
raise
|
||||
|
||||
def _truncate_main_log(self, log_file: Path) -> None:
|
||||
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, expected_ino: int = 0) -> None:
|
||||
"""Empty the main log through the handler that writes to it.
|
||||
|
||||
Opening the file a second time with ``"w"`` leaves the handler's own
|
||||
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.
|
||||
|
||||
A handler whose open stream is not the listed file (``expected_ino``:
|
||||
the user renamed the log, which the handler still writes to) is left
|
||||
alone: the file under the active name is emptied instead.
|
||||
"""
|
||||
handled = False
|
||||
target = os.path.normcase(os.path.realpath(str(log_file)))
|
||||
@@ -320,6 +519,8 @@ class PromptManagerLogger:
|
||||
continue
|
||||
if os.path.normcase(os.path.realpath(base)) != target:
|
||||
continue
|
||||
if not _stream_is(stream, expected_ino):
|
||||
continue
|
||||
handler.acquire()
|
||||
try:
|
||||
stream.flush()
|
||||
@@ -329,14 +530,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 +597,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), row["ino"])
|
||||
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 +664,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 +697,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 {
|
||||
|
||||
@@ -0,0 +1,18 @@
|
||||
"""The project version, read from ``pyproject.toml`` (#329)."""
|
||||
|
||||
import re
|
||||
from pathlib import Path
|
||||
|
||||
|
||||
def project_version(root):
|
||||
"""The version in ``root``'s ``pyproject.toml``; ``"unknown"`` on failure."""
|
||||
try:
|
||||
pyproject_path = Path(root) / "pyproject.toml"
|
||||
if pyproject_path.exists():
|
||||
content = pyproject_path.read_text()
|
||||
match = re.search(r'version\s*=\s*["\']([^"\']+)["\']', content)
|
||||
if match:
|
||||
return match.group(1)
|
||||
except Exception: # nosec B110 - an unreadable file reads as unknown
|
||||
pass
|
||||
return "unknown"
|
||||
Reference in New Issue
Block a user