215 lines
8.7 KiB
Python
215 lines
8.7 KiB
Python
# Copyright (c) 2025 Patrick Motsch
|
|
"""Per-run NDJSON logs for persisted Automation2 / graphical-editor runs."""
|
|
|
|
from __future__ import annotations
|
|
|
|
import asyncio
|
|
import json
|
|
import logging
|
|
import os
|
|
from datetime import datetime, timezone
|
|
from typing import Any, Dict, Optional
|
|
|
|
from modules.shared.configuration import APP_CONFIG
|
|
from modules.shared.debugLogger import ensureDir, resolve_app_log_dir
|
|
|
|
logger = logging.getLogger(__name__)
|
|
|
|
|
|
RUN_FILE_LOG_RELATIVE_ROOT = "graphical_editor_runs"
|
|
CONTEXT_KEY = "_geRunFileLogRelativeDir"
|
|
EXECUTION_FILENAME = "node_execution.ndjson"
|
|
CONTEXT_SNAPSHOT_FILENAME = "workflow_context.ndjson"
|
|
|
|
|
|
def graphical_editor_run_file_logging_enabled() -> bool:
|
|
"""True when NDJSON files should be written for each persisted run."""
|
|
raw = APP_CONFIG.get("APP_GRAPHICAL_EDITOR_RUN_FILE_LOGGING", False)
|
|
if isinstance(raw, bool):
|
|
return raw
|
|
s = str(raw).strip().lower()
|
|
return s in ("1", "true", "yes", "on")
|
|
|
|
|
|
def merge_run_context_with_ge_log_prefix(
|
|
base_context: Optional[Dict[str, Any]],
|
|
incoming: Dict[str, Any],
|
|
) -> Dict[str, Any]:
|
|
"""Copy ``CONTEXT_KEY`` from *base_context* onto *incoming* if present (pause paths)."""
|
|
out = dict(incoming or {})
|
|
prev = (base_context or {}).get(CONTEXT_KEY)
|
|
if prev is not None:
|
|
out[CONTEXT_KEY] = prev
|
|
return out
|
|
|
|
|
|
def merge_persisted_run_context(
|
|
automation2_interface: Any,
|
|
run_id: str,
|
|
replacement: Dict[str, Any],
|
|
) -> Dict[str, Any]:
|
|
"""``{**db_context, **replacement}`` so *_geRunFileLogRelativeDir* and other keys survive pause updates."""
|
|
prev = dict((automation2_interface.getRun(run_id) or {}).get("context") or {})
|
|
return {**prev, **(replacement or {})}
|
|
|
|
|
|
class RunFileLogger:
|
|
"""Append-only NDJSON log for one run folder under ``resolve_app_log_dir()``."""
|
|
|
|
__slots__ = ("_exec_path", "_ctx_path", "_lock", "_run_id")
|
|
|
|
def __init__(self, run_id: str, absolute_run_dir: str) -> None:
|
|
self._run_id = run_id
|
|
ensureDir(absolute_run_dir)
|
|
self._exec_path = os.path.join(absolute_run_dir, EXECUTION_FILENAME)
|
|
self._ctx_path = os.path.join(absolute_run_dir, CONTEXT_SNAPSHOT_FILENAME)
|
|
self._lock = asyncio.Lock()
|
|
|
|
@property
|
|
def run_id(self) -> str:
|
|
return self._run_id
|
|
|
|
@staticmethod
|
|
def fresh_run_subdirectory_name(run_id: str) -> str:
|
|
ts = datetime.now(timezone.utc).strftime("%Y_%m_%d_%H_%M_%S")
|
|
return f"{ts}__{run_id}"
|
|
|
|
@staticmethod
|
|
def relative_run_path(subdir_name: str) -> str:
|
|
"""Path relative to ``APP_LOGGING_LOG_DIR`` (POSIX-style segments)."""
|
|
return "/".join((RUN_FILE_LOG_RELATIVE_ROOT, subdir_name))
|
|
|
|
@classmethod
|
|
def bootstrap_new_run(cls, automation2_interface: Any, run_id: str, run_context: Dict[str, Any]) -> RunFileLogger | None:
|
|
"""Create filesystem folder + persist CONTEXT_KEY via ``updateRun``."""
|
|
if not graphical_editor_run_file_logging_enabled():
|
|
return None
|
|
if not automation2_interface or not run_id:
|
|
return None
|
|
subdir = cls.fresh_run_subdirectory_name(run_id)
|
|
rel = cls.relative_run_path(subdir)
|
|
base = resolve_app_log_dir()
|
|
absolute = os.path.join(base, RUN_FILE_LOG_RELATIVE_ROOT, subdir)
|
|
|
|
merged = dict(run_context or {})
|
|
merged[CONTEXT_KEY] = rel
|
|
try:
|
|
automation2_interface.updateRun(run_id, context=merged)
|
|
except Exception as ex:
|
|
logger.warning("GeRunFileLog: could not persist log dir on run=%s: %s", run_id, ex)
|
|
return None
|
|
|
|
logger.info(
|
|
"GeRunFileLog: created run folder %s (run=%s)",
|
|
absolute,
|
|
run_id,
|
|
)
|
|
return cls(run_id, absolute)
|
|
|
|
@classmethod
|
|
def open_from_run_record(cls, automation2_interface: Any, run_id: str) -> RunFileLogger | None:
|
|
"""Open logger for an existing run using CONTEXT_KEY from DB."""
|
|
if not graphical_editor_run_file_logging_enabled():
|
|
return None
|
|
if not automation2_interface or not run_id:
|
|
return None
|
|
try:
|
|
run = automation2_interface.getRun(run_id) or {}
|
|
except Exception as ex:
|
|
logger.debug("GeRunFileLog: getRun failed run=%s: %s", run_id, ex)
|
|
return None
|
|
rel = (run.get("context") or {}).get(CONTEXT_KEY)
|
|
if not rel or not isinstance(rel, str):
|
|
return None
|
|
base_norm = os.path.realpath(resolve_app_log_dir())
|
|
allowed_root = os.path.realpath(os.path.join(base_norm, RUN_FILE_LOG_RELATIVE_ROOT))
|
|
cand = os.path.realpath(os.path.join(base_norm, *rel.replace("\\", "/").split("/")))
|
|
if cand != allowed_root and not cand.startswith(allowed_root + os.sep):
|
|
logger.warning(
|
|
"GeRunFileLog: path outside log root denied for run=%s rel=%s",
|
|
run_id,
|
|
rel,
|
|
)
|
|
return None
|
|
absolute = cand
|
|
return cls(run_id, absolute)
|
|
|
|
@classmethod
|
|
def find_existing_absolute_dir(cls, run_id: str) -> Optional[str]:
|
|
"""If a folder named ``*{timestamp}__{run_id}`` exists under the log root, return its absolute path."""
|
|
root = os.path.realpath(os.path.join(resolve_app_log_dir(), RUN_FILE_LOG_RELATIVE_ROOT))
|
|
if not os.path.isdir(root):
|
|
return None
|
|
suffix = f"__{run_id}"
|
|
try:
|
|
names = sorted((n for n in os.listdir(root) if n.endswith(suffix)), reverse=True)
|
|
except OSError:
|
|
return None
|
|
if not names:
|
|
return None
|
|
cand = os.path.realpath(os.path.join(root, names[0]))
|
|
allowed_root = root
|
|
if cand != allowed_root and not cand.startswith(allowed_root + os.sep):
|
|
return None
|
|
return cand if os.path.isdir(cand) else None
|
|
|
|
@classmethod
|
|
def ensure_attached(cls, automation2_interface: Any, run_id: str) -> RunFileLogger | None:
|
|
"""Open logger from DB, or reattach an on-disk folder for *run_id*, or create a new one."""
|
|
opened = cls.open_from_run_record(automation2_interface, run_id)
|
|
if opened is not None:
|
|
return opened
|
|
if not graphical_editor_run_file_logging_enabled():
|
|
return None
|
|
if not automation2_interface or not run_id:
|
|
return None
|
|
try:
|
|
run = automation2_interface.getRun(run_id) or {}
|
|
except Exception as ex:
|
|
logger.debug("GeRunFileLog: ensure getRun failed run=%s: %s", run_id, ex)
|
|
return None
|
|
prev_ctx = dict(run.get("context") or {})
|
|
|
|
existing_abs = cls.find_existing_absolute_dir(run_id)
|
|
if existing_abs:
|
|
base_norm = os.path.realpath(resolve_app_log_dir())
|
|
rel = os.path.relpath(existing_abs, base_norm).replace(os.sep, "/")
|
|
merged = {**prev_ctx, CONTEXT_KEY: rel}
|
|
try:
|
|
automation2_interface.updateRun(run_id, context=merged)
|
|
except Exception as ex:
|
|
logger.warning("GeRunFileLog: reattach persist failed run=%s: %s", run_id, ex)
|
|
return None
|
|
logger.info("GeRunFileLog: reattached existing folder for run=%s -> %s", run_id, existing_abs)
|
|
return cls(run_id, existing_abs)
|
|
|
|
subdir = cls.fresh_run_subdirectory_name(run_id)
|
|
rel = cls.relative_run_path(subdir)
|
|
base = resolve_app_log_dir()
|
|
absolute = os.path.join(base, RUN_FILE_LOG_RELATIVE_ROOT, subdir)
|
|
merged = {**prev_ctx, CONTEXT_KEY: rel}
|
|
try:
|
|
automation2_interface.updateRun(run_id, context=merged)
|
|
except Exception as ex:
|
|
logger.warning("GeRunFileLog: ensure new folder persist failed run=%s: %s", run_id, ex)
|
|
return None
|
|
logger.info("GeRunFileLog: created late attach folder %s (run=%s)", absolute, run_id)
|
|
return cls(run_id, absolute)
|
|
|
|
async def append_node_execution_line(self, record: Dict[str, Any]) -> None:
|
|
line = json.dumps(record, ensure_ascii=False, default=str)
|
|
async with self._lock:
|
|
try:
|
|
with open(self._exec_path, "a", encoding="utf-8") as f:
|
|
f.write(line + "\n")
|
|
except Exception as ex:
|
|
logger.warning("GeRunFileLog: append execution failed run=%s: %s", self._run_id, ex)
|
|
|
|
async def append_context_snapshot_line(self, record: Dict[str, Any]) -> None:
|
|
line = json.dumps(record, ensure_ascii=False, default=str)
|
|
async with self._lock:
|
|
try:
|
|
with open(self._ctx_path, "a", encoding="utf-8") as f:
|
|
f.write(line + "\n")
|
|
except Exception as ex:
|
|
logger.warning("GeRunFileLog: append context snapshot failed run=%s: %s", self._run_id, ex)
|