chore: sync ffmpeg video session and logging fallback

Co-authored-by: Cursor <cursoragent@cursor.com>

scripts/jiangchang_skill_core/rpa/video_session.py

@@ -1,7 +1,4 @@
-"""RPA 运行录屏会话：ffmpeg 桌面录制 → 字幕 + 背景音乐 → 最终 MP4。
-
-Playwright 仅用于浏览器自动化，不负责录屏。
-"""
+"""RPA 运行录屏会话：ffmpeg 桌面录制 → 字幕 + 背景音乐 → 最终 MP4。"""
 
 from __future__ import annotations
 
@@ -15,7 +12,7 @@ import time
 from dataclasses import dataclass
 from datetime import datetime
 from pathlib import Path
-from typing import Any, Dict, List, Optional
+from typing import Any, Dict, IO, List, Optional
 
 from .. import config
 
@@ -222,8 +219,6 @@ class RpaVideoSession:
         self.warnings: List[str] = []
         self.output_video_path: Optional[str] = None
         self.capture_path: Optional[str] = None
-        # 已废弃：勿用于 Playwright；始终为 None。
-        self.record_video_dir: Optional[str] = None
         self.artifacts: Dict[str, Any] = {}
 
         ts = datetime.now().strftime("%Y%m%d_%H%M%S")
@@ -236,6 +231,7 @@ class RpaVideoSession:
         )
         self._subtitles_dir = os.path.join(self._artifact_root, "subtitles")
         self._logs_dir = os.path.join(self._artifact_root, "logs")
+        self._ffmpeg_record_log_path = os.path.join(self._logs_dir, "ffmpeg-record.log")
         self._capture_path = os.path.join(self._artifact_root, "capture.mp4")
         self._srt_path = os.path.join(self._subtitles_dir, f"{self._video_stem}.srt")
         self._planned_output = os.path.join(self._videos_dir, f"{self._video_stem}.mp4")
@@ -243,6 +239,7 @@ class RpaVideoSession:
         self._steps: List[_StepEntry] = []
         self._t0: Optional[float] = None
         self._ffmpeg_proc: Optional[subprocess.Popen] = None
+        self._ffmpeg_record_log_file: Optional[IO[str]] = None
 
         if self.enabled:
             os.makedirs(self._videos_dir, exist_ok=True)
@@ -250,6 +247,21 @@ class RpaVideoSession:
             os.makedirs(self._logs_dir, exist_ok=True)
             os.makedirs(self._artifact_root, exist_ok=True)
 
+    def _record_log_hint(self) -> str:
+        if self.enabled and self._ffmpeg_record_log_path:
+            return f"; record_log={self._ffmpeg_record_log_path}"
+        return ""
+
+    def _append_warning(self, code: str, detail: str = "") -> None:
+        msg = code if not detail else f"{code}: {detail}"
+        if code in (
+            "ffmpeg_record_start_failed",
+            "ffmpeg_capture_missing",
+            "ffmpeg_compose_failed",
+        ):
+            msg += self._record_log_hint()
+        self.warnings.append(msg)
+
     def step(self, text: str, *, duration: float = 4.0) -> None:
         self.add_step(text, duration=duration)
 
@@ -262,6 +274,16 @@ class RpaVideoSession:
         elapsed = time.monotonic() - self._t0
         self._steps.append(_StepEntry(start=elapsed, text=text.strip(), duration=duration))
 
+    def _close_ffmpeg_record_log(self) -> None:
+        fh = self._ffmpeg_record_log_file
+        self._ffmpeg_record_log_file = None
+        if fh is None:
+            return
+        try:
+            fh.close()
+        except Exception:
+            pass
+
     def _start_ffmpeg_capture(self) -> None:
         if not self.enabled:
             return
@@ -271,26 +293,39 @@ class RpaVideoSession:
 
         cmd = _build_desktop_record_cmd(self._capture_path)
         if cmd is None:
-            self.warnings.append(
-                "ffmpeg_record_start_failed: desktop capture only supported on Windows"
+            self._append_warning(
+                "ffmpeg_record_start_failed",
+                "desktop capture only supported on Windows",
             )
             return
 
+        stderr_target: Any = subprocess.DEVNULL
+        try:
+            os.makedirs(self._logs_dir, exist_ok=True)
+            self._ffmpeg_record_log_file = open(
+                self._ffmpeg_record_log_path, "a", encoding="utf-8"
+            )
+            stderr_target = self._ffmpeg_record_log_file
+        except Exception as exc:
+            self.warnings.append(f"ffmpeg_record_log_open_failed: {exc}")
+
         try:
             self._ffmpeg_proc = subprocess.Popen(
                 cmd,
                 stdin=subprocess.PIPE,
                 stdout=subprocess.DEVNULL,
-                stderr=subprocess.DEVNULL,
+                stderr=stderr_target,
             )
             self.capture_path = self._capture_path
         except Exception as exc:
-            self.warnings.append(f"ffmpeg_record_start_failed: {exc}")
+            self._append_warning("ffmpeg_record_start_failed", str(exc))
             self._ffmpeg_proc = None
+            self._close_ffmpeg_record_log()
 
     def _stop_ffmpeg_capture(self) -> None:
         proc = self._ffmpeg_proc
         if proc is None:
+            self._close_ffmpeg_record_log()
             return
         if proc.poll() is None:
             try:
@@ -314,8 +349,8 @@ class RpaVideoSession:
                 except Exception:
                     pass
         self._ffmpeg_proc = None
-        await_sleep = 0.3
-        time.sleep(await_sleep)
+        self._close_ffmpeg_record_log()
+        time.sleep(0.3)
 
     async def __aenter__(self) -> "RpaVideoSession":
         if self.enabled:
@@ -342,7 +377,7 @@ class RpaVideoSession:
         try:
             capture = Path(self._capture_path)
             if not capture.is_file() or capture.stat().st_size <= 0:
-                self.warnings.append("ffmpeg_capture_missing")
+                self._append_warning("ffmpeg_capture_missing")
                 self.artifacts = self.summary()
                 return
 
@@ -396,7 +431,7 @@ class RpaVideoSession:
                     ]
                 )
             if not ok:
-                self.warnings.append(f"ffmpeg_compose_failed: {err}")
+                self._append_warning("ffmpeg_compose_failed", err)
                 self.artifacts = self.summary()
                 return
 
@@ -407,10 +442,16 @@ class RpaVideoSession:
         self.artifacts = self.summary()
 
     def summary(self) -> Dict[str, Any]:
+        record_log = (
+            os.path.abspath(self._ffmpeg_record_log_path)
+            if self.enabled and self._ffmpeg_record_log_path
+            else None
+        )
         return {
             "enabled": self.enabled,
             "path": self.output_video_path,
             "capture_path": self.capture_path,
+            "record_log_path": record_log,
             "warnings": list(self.warnings),
         }
 

scripts/jiangchang_skill_core/unified_logging.py

@@ -1,5 +1,5 @@
 """
-统一文件日志：{DATA_ROOT}/{USER_ID}/logs/jiangchang.log
+统一文件日志：{JIANGCHANG_DATA_ROOT}/{JIANGCHANG_USER_ID}/logs/jiangchang.log
 按日轮转；行内带 trace_id 与 skill_slug，便于跨技能排查。
 """
 
@@ -20,21 +20,29 @@ _logger_name: str = ""
 
 def get_unified_logs_dir() -> str:
     path = os.path.join(get_data_root(), get_user_id(), "logs")
+    try:
         os.makedirs(path, exist_ok=True)
+    except OSError:
+        pass
     return path
 
 
 def get_skill_log_file_path() -> str:
+    """与 setup 写入的主日志文件一致（供终端提示等）。"""
     override = (os.getenv("JIANGCHANG_LOG_FILE") or "").strip()
     if override:
         parent = os.path.dirname(os.path.abspath(override))
         if parent:
+            try:
                 os.makedirs(parent, exist_ok=True)
+            except OSError:
+                pass
         return os.path.abspath(override)
     return os.path.join(get_unified_logs_dir(), "jiangchang.log")
 
 
 def ensure_trace_for_process() -> str:
+    """本进程调用链 ID：沿用 JIANGCHANG_TRACE_ID，否则生成并写入环境（子进程可继承）。"""
     existing = (os.getenv("JIANGCHANG_TRACE_ID") or "").strip()
     if existing:
         return existing
@@ -44,8 +52,11 @@ def ensure_trace_for_process() -> str:
 
 
 def subprocess_env_with_trace(environ: Optional[dict] = None) -> dict:
+    """subprocess.run(..., env=...) 时使用，保证带上当前 trace。"""
     ensure_trace_for_process()
-    tid = (os.getenv("JIANGCHANG_TRACE_ID") or "").strip() or ensure_trace_for_process()
+    tid = (os.getenv("JIANGCHANG_TRACE_ID") or "").strip()
+    if not tid:
+        tid = ensure_trace_for_process()
     base = os.environ if environ is None else environ
     return {**base, "JIANGCHANG_TRACE_ID": tid}
 
@@ -57,7 +68,9 @@ class _SkillContextFilter(logging.Filter):
         return True
 
 
-_FORMAT = "%(asctime)s | %(levelname)-8s | %(trace_id)s | %(skill_slug)s | %(name)s | %(message)s"
+_FORMAT = (
+    "%(asctime)s | %(levelname)-8s | %(trace_id)s | %(skill_slug)s | %(name)s | %(message)s"
+)
 _DATEFMT = "%Y-%m-%dT%H:%M:%S"
 
 
@@ -74,7 +87,17 @@ def _backup_count() -> int:
         return 30
 
 
+def _attach_fallback_handler(log: logging.Logger, fmt: logging.Formatter) -> None:
+    """文件日志不可用时仅挂内存 handler，不向 stderr 打印 logging 异常。"""
+    log.addHandler(logging.NullHandler())
+
+
 def setup_skill_logging(skill_slug: str, logger_name: str) -> None:
+    """
+    幂等：为指定 logger 挂载统一文件日志与可选 stderr。
+    须在进程早期调用（如 CLI main 在业务日志之前）。
+    文件日志目录无权限或不可写时降级为 no-op，不影响 CLI 返回码。
+    """
     global _skill_slug, _logger_name
     ensure_trace_for_process()
     _skill_slug = skill_slug
@@ -84,6 +107,10 @@ def setup_skill_logging(skill_slug: str, logger_name: str) -> None:
     if log.handlers:
         return
     log.setLevel(_log_level_from_env())
+    fmt = logging.Formatter(_FORMAT, datefmt=_DATEFMT)
+    filt = _SkillContextFilter()
+
+    try:
         path = get_skill_log_file_path()
         fh = TimedRotatingFileHandler(
             path,
@@ -93,16 +120,28 @@ def setup_skill_logging(skill_slug: str, logger_name: str) -> None:
             encoding="utf-8",
             delay=True,
         )
-    fmt = logging.Formatter(_FORMAT, datefmt=_DATEFMT)
         fh.setFormatter(fmt)
-    fh.addFilter(_SkillContextFilter())
+        fh.addFilter(filt)
         log.addHandler(fh)
-    if (os.getenv("JIANGCHANG_LOG_TO_STDERR") or "").strip().lower() in ("1", "true", "yes", "on"):
+    except (OSError, PermissionError, ValueError):
+        _attach_fallback_handler(log, fmt)
+    except Exception:
+        _attach_fallback_handler(log, fmt)
+
+    if (os.getenv("JIANGCHANG_LOG_TO_STDERR") or "").strip().lower() in (
+        "1",
+        "true",
+        "yes",
+        "on",
+    ):
+        try:
             sh = logging.StreamHandler(sys.stderr)
             sh.setLevel(logging.WARNING)
             sh.setFormatter(fmt)
-        sh.addFilter(_SkillContextFilter())
+            sh.addFilter(filt)
             log.addHandler(sh)
+        except Exception:
+            pass
     log.propagate = False
 
 
@@ -119,19 +158,27 @@ def attach_unified_file_handler(
     logger_name: str,
     level: int = logging.DEBUG,
 ) -> logging.Logger:
+    """
+    独立子进程内追加同一日志文件（如 login 检测子进程），格式与主进程一致。
+    """
     global _skill_slug
     ensure_trace_for_process()
     _skill_slug = skill_slug
     lg = logging.getLogger(logger_name)
     lg.handlers.clear()
     lg.setLevel(level)
+    fmt = logging.Formatter(_FORMAT, datefmt=_DATEFMT)
+    try:
         parent = os.path.dirname(os.path.abspath(log_path))
         if parent:
             os.makedirs(parent, exist_ok=True)
         fh = logging.FileHandler(log_path, encoding="utf-8")
-    fmt = logging.Formatter(_FORMAT, datefmt=_DATEFMT)
         fh.setFormatter(fmt)
         fh.addFilter(_SkillContextFilter())
         lg.addHandler(fh)
+    except (OSError, PermissionError, ValueError):
+        lg.addHandler(logging.NullHandler())
+    except Exception:
+        lg.addHandler(logging.NullHandler())
     lg.propagate = False
     return lg