From 832c76619aeeaa1a136ec4ed270a0972dc787cca Mon Sep 17 00:00:00 2001 From: Hermes Date: Thu, 8 Oct 2026 10:30:59 +0800 Subject: [PATCH] state + skill: handoff doc, and move the measured failure modes into references/ STATE.md carries what the next session needs: the two commands that keep the tiers running, where the logs/stage/locks/ledger live, the eight bugs this round produced (each with the measurement that proved it), and the open items. The skill's body now keeps only the load-bearing rules; every measured case moved to references/pitfalls.md, so the always-loaded part stays readable. --- SKILL.md | 37 ++++++++---------------- STATE.md | 65 ++++++++++++++++++++++++++++++++++++++++++ references/pitfalls.md | 29 +++++++++++++++++++ scripts/library_run.py | 64 +++++++++++++++++++++++++---------------- 4 files changed, 146 insertions(+), 49 deletions(-) create mode 100644 STATE.md create mode 100644 references/pitfalls.md diff --git a/SKILL.md b/SKILL.md index 93247cf..81cc8c8 100644 --- a/SKILL.md +++ b/SKILL.md @@ -263,33 +263,20 @@ re-encoded to `-b:a 256k`: that added ~128 kbps for no audible gain, ~+10% file - **Killing a background session may not kill the process.** The session is a wrapper around the command; killing the session left the real python alive holding its lock, so the next start was refused by a lock that was telling the TRUTH while the log looked like a stale-lock bug. Check the real PID before concluding (`powershell -NoProfile -Command "Get-CimInstance Win32_Process -Filter 'ProcessId=' | Select ProcessId,ParentProcessId,CreationDate,CommandLine"`) and kill that PID. Corollary, now implemented in `Lock`: the lock file is touched by a heartbeat every minute and staleness is decided by age (5 min) as well as pid, and a takeover that cannot remove a file still held by the OS overwrites it in place instead of crashing. +- **A watchdog that reads a PIPE can kill healthy work; send child stderr to a FILE.** ffmpeg with `-stats` writes a line every 0.5 s; a 64 KB pipe fills within minutes, ffmpeg blocks in `write()` on stderr, its OUTPUT stops growing - and a stall watchdog then kills a perfectly good encode. Measured: ~270 kills in one night, 24 files converted, encoder sitting at 0% with the process alive. Pipes are for bounded output only; a multi-minute encode goes to a log file, read back afterwards for the error text. +- **Watchdogs earn their keep: a driver update wedges GPU work silently.** The user updated the NVIDIA driver while a `hevc_nvenc` encode ran: the process stayed alive, output stopped growing, the encoder read 0%, and NOTHING reported an error - the tier sat frozen for 1.5 hours. Tell the user to pause GPU tiers before touching the driver, and keep an output-growth watchdog (14 min window) so it self-heals either way. +- **Metadata on a Dokan share is a CACHE, so verify installed files by content.** A rename (`os.replace`) did not land for one file while every ffprobe probe insisted it had: the run logged `ok 1085 MB -> 478 MB` and the live file was still the original H.264, with no error anywhere. After installing, read the file back and compare its SHA-256 with the encode; that check cannot be served from a cache. (Same share: `getsize()` lies, so never resume an upload from a share-reported size.) +- **Give concurrent runs their own temp files.** Tiers run side by side by design (copy = I/O, x265 = CPU, nvenc = GPU ASIC) and share the stage directory; fixed temp names let two gates overwrite each other's decodes and report a fake `100% of frames below 0.85 - systematic defect`. Tag every temp with the pid AND the file. +- **Separate the single-file path from the tree walk.** `--path FILE --dest TARGET --keep-source` runs one file anywhere on disk through the same tier rule, gates and hash-verified install. Watch out: `os.path.relpath` raises ValueError across drives (file on D:, library on Z:) - fall back to the absolute path, and the dest overrides where the install lands (all post-install checks must then probe the DEST, not the source). + ## Pitfalls -- **A RaiDrive/Dokan write can return with NO error while the file is a fraction of what it should be.** Measured: a 403 MB upload left 12.5 MB on the share, and RaiDrive's own "the operation didn't complete within specific time limit" toast arrived *after* the write had already returned success. Never trust a write to a Dokan-backed share: hash the local file, hash the share copy back, compare size AND SHA-256, and only then rename. On a mismatch, retry the upload (it usually works on the second attempt) rather than failing the item. Uploads should use small chunks (4 MB) with a periodic `flush`+`fsync`; a partial `*.new.mp4`/`*.part.mp4` must be deleted, never resumed from `os.path.getsize()` on the share (RaiDrive reports stale sizes, so a resume offset taken from it corrupts the file). -- **Those same toasts are an overload signal, not a permission problem.** Three jobs reading/writing one share provoked both the truncated write above and `[Errno 9] Bad file descriptor` on a 1 GB staged read; writing into the library folder itself was perfectly fine (verified by creating and deleting a file there). Cap the concurrency at two jobs (one CPU tier + one GPU tier), give each tier its own lock file, and make the lock take over a stale one (pid gone). -- **Compare pictures by TIMESTAMP, never by frame index after an input seek.** An input `-ss` snaps to a keyframe, and it snaps to a *different* keyframe for the source and for the encode - measured: two 1500-frame decodes whose start times differed by ~10 s, so every frame met the wrong one and a perfectly good encode scored min SSIM 0.25. Cut the window with the `trim` filter on absolute PTS (`-copyts -ss -i in -vf "trim=start=X:end=Y,setpts=PTS-STARTPTS,..."`). Validate the method by comparing a file against ITSELF: it must read lo=1.0/mean=1.0, otherwise the harness is broken and every verdict it produces is noise. -- **If the frame counts in the sampled window differ by more than ~1%, the picture gate is NOT APPLICABLE - do not fail the file.** A source with holes in its timeline (measured: 1459 frames where 1500 belong, a 1.7 s hole) is *supposed* to gain duplicated frames from `-fps_mode cfr`; after the hole every frame pairs with the wrong one and SSIM collapses. Report the condition and let the structural/decode/size gates carry the verdict. -- **File paths with a space before the extension are NOT the problem they look like** - `1130 维特根斯坦十讲 .mp4` opened and streamed fine. Suspect the share, not the name. -- **Never kill encoders by process name.** `Get-Process ffmpeg | Stop-Process -Force` also killed an unrelated pilot encode that was running legitimately (rc=-1 mid-encode). Kill the specific background PID, or the specific `ffmpeg` PID you started. - -- **Never write the encode output directly to a network share.** A streaming `.part` write over - SMB/SFTP/Dokan leaves a corrupt stub when the connection blips. Encode to local disk, verify, - then copy the complete file across. The tool writes `dst + ".part.mp4"` and renames only after - verification — keep it on a local path if the destination is remote. -- **`os.path.getsize()` lies on RaiDrive/Dokan** — it returns cached metadata from the *previous* - file handle. Verify a network copy by sequential chunked read, never by size. -- **A `.mkv` extension on a converted file is cosmetic.** TubeSync's rename pass rewrites - finished `.mp4` files back to `.mkv` while `downloaded_container` still reads `mp4`, and - `Content-Type` follows the container. Do not "fix" it and do not report it as a playback bug. -- **Do not re-download to fix a timing defect.** The mkv that yt-dlp writes is itself flat, so a - re-download reproduces the defect exactly. -- **A `-c copy` remux cannot repair timing.** ffmpeg will not rewrite `stts`/`ctts` under stream - copy, and retiming only the SPS (`-bsf:v h264_metadata=tick_rate=…`) changes nothing either. - Repairing a copy-tier file means re-encoding its video — quote the size cost (1.28x at crf 23, - 1.74x at crf 20) before applying it to a whole library. -- **Unicode paths**: on Windows, drive ffmpeg from Python `subprocess` with an argv list. MSYS - bash cannot hand a Chinese filename to native `ffmpeg.exe` even when `ls` shows it. -- **`-hwaccel cuda` alone may still software-decode VP9**; `-c:v vp9_cuvid` forces NVDEC. +- **Five-step pipeline, no exceptions**: decode → encode → `verify()` → `verify_content()` / SSIM gate → hash-verified install. A file is replaced ONLY when every step passed; a failure leaves the live file untouched. +- **Never trust this share's metadata**: read files back and compare SHA-256 (a rename can silently not land); never resume a write from a share-reported size. +- **Never build a verification harness on a stream copy or a seek**: compare whole files, decode both sides sequentially, and prove the harness on a file against itself (must be lo=1.0). +- **Judge a defect's SHAPE, not one frame**: mean < 0.98 or > 1% of frames below 0.85 fails; a handful of scattered low frames at a healthy mean is a fade, and SSIM on near-flat frames means nothing. +- **Kill by PID only**, one lock per tier, one NVENC job at a time, and pause GPU tiers before a driver update (an update wedges GPU work silently — the output-growth watchdog is the net). +- **Full measured detail, every failure mode and its detector: `references/pitfalls.md`.** ## The owner's standing requirements — read this first diff --git a/STATE.md b/STATE.md new file mode 100644 index 0000000..25e47a5 --- /dev/null +++ b/STATE.md @@ -0,0 +1,65 @@ +# STATE — 樊登读书会媒体库转码（2026-10-07/08） + +给下一个会话的交接。**权威运行器：`scripts/library_run.py`**（不要再恢复旧的 `hevc_lib.py`）。 + +## 现在在跑什么 + +```bash +# 两个档并行（各自独立的锁：run-x265.lock / run-nvenc.lock），GPU 与 CPU 互不争抢 +cd /d/dev/universal-video-transcode +python -u scripts/library_run.py --tier x265 --origin-root "Z:\Class\#snapshot\GMT+08-2026.09.25-09.50.20\樊登读书\樊登读书会（每周更新）" --reverse >> /d/tmp/xcode/run_x265.log 2>&1 +python -u scripts/library_run.py --tier nvenc --origin-root "Z:\Class\#snapshot\GMT+08-2026.09.25-09.50.20\樊登读书\樊登读书会（每周更新）" --reverse >> /d/tmp/xcode/run_nvenc.log 2>&1 +``` + +- **copy 档已整轮完成**：`=== done: ok=193 skipped=389 failed=0`（视频逐位不变 + 音频转 AAC）。无需再跑。 +- 预期：x265 ~3.5 天、nvenc ~3 天跑完全库（582 文件 / ~324 GB）。 +- 断点续跑天然幂等：已转好的文件（HEVC 且 ≤ 原档大小）自动跳过；失败项文件未动，下一轮自动重做。 + +## 目录与日志 + +| 用途 | 路径 | +|---|---| +| 运行日志 | `/d/tmp/xcode/run_x265.log`、`run_nvenc.log`、`run_copy.log` | +| 单文件日志 | `/d/tmp/xcode/run_single.log` | +| 暂存目录（编码/闸门 raw） | `C:\AI\transcode-run\stage`（C: 盘，要留 ≥8 GB） | +| 台账（每项一行 JSON） | `C:\AI\transcode-run\ledger.jsonl` | +| 锁（每档一个 + 心跳） | `C:\AI\transcode-run\run-.lock` | + +## 本轮修掉的 bug（按时间顺序，全部已提交推送） + +1. **闸门判据太粗糙** → 改"缺陷形状"判：`mean < 0.98` 或 `>1% 帧 <0.85` 才判错，并**剔除近平坦帧**（SSIM 在黑场/淡入淡出上无意义；实测：好编码 0/1500、误判文件 0.33%、真缺陷 2.9%）。 +2. **闸门用输入 seek 解码** → 改**两侧顺序解码**（open GOP 源从中间 seek 会解出错误画面：同一文件与自身比对 min 0.25）。 +3. **闸门 raw 文件固定名** → 三个档并行时互踩（实测报出"100% 帧不符"的假缺陷）→ 改 **PID + tag** 命名。 +4. **安装只用 ffprobe 元数据复核** → RaiDrive 返回**缓存属性**，rename 没落地也说成功（实测"ok 1085→478 MB"而线上仍是原档）→ 改**安装后回读哈希**。 +5. **源拷贝只校验字节数** → 加 **SHA-256 比对共享盘副本**（长度对内容错是真风险）。 +6. **probe 单次失败即判文件失败** → 加**重试 3 次**。 +7. **看门狗用 stderr 管道**（本轮最贵的 bug）→ ffmpeg `-stats` 每 0.5 s 一行，64 KB 管道几分钟塞满 → ffmpeg 阻塞在 write() → 输出不增长 → 看门狗**误杀好编码**（整夜 ~270 杀、只转成 24 个、GPU 0%）。修：**stderr 写文件**，阈值 5→15 分钟。自检脚本 `D:\dev\hoelee-tubesync-management\cache\watchdog_selfcheck.py`。 +8. 看门狗**保留**（它要防的是真实场景：用户更新 NVIDIA 驱动会把在跑的 NVENC 冻死 1.5 小时且不报错）。 + +## 未完成 / 待办 + +- [ ] 两档跑完 → **全库落地审计**：`D:\dev\hoelee-tubesync-management\cache\install_audit.py`（核对线上文件真实大小 + 编码器；曾一次抓到"报告成功没落地"）+ `copy_land_check.py`（copy 档用音轨 aac/mp3 判定）。 +- [ ] 失败项：无需清单，新一轮自动重做（失败时文件原样）。 +- [ ] `2022年/0723 《走出强迫症》/走出强迫症.mp4` 用新下载（`D:\Download\0723走出强迫症.mp4`，618,696,954 B）已转好装好（450,502,893 B，HEVC+AAC，SSIM min 0.997，时长 3399.81 s）✓。**快照里那份仍是坏的**（618,697,011 B，moov 缺失）→ 待定：是否用干净副本替换快照里的坏档，以免将来"从原档重转"踩坑。 +- [ ] 目标文件夹里曾出现一个 0 字节的 `0723走出强迫症.mp4`（现已不在）—— 若是用户自建请告知命名约定。 +- [ ] 全库唯一真损坏：`走出强迫症.mp4` 的原档（上面已处理）；其余 573 个可读文件截断审计 0 可疑。 + +## 用法速查 + +```bash +# 单文件（任意位置）转好并装回库，走同一套分档/闸门/回读 +python scripts/library_run.py --path "D:/Download/x.mp4" --dest "Z:/.../x.mp4" --keep-source + +# 只审计不落地（本地编码+闸门，输出丢弃） +python scripts/library_run.py --tier x265 --limit 3 --keep-local + +# 分档预览 +python scripts/library_run.py --dry-run --limit 20 +``` + +## 红线（用户明确要求过） + +- **绝不删除/覆盖快照原档**（`#snapshot` 是唯一的干净档案）。 +- 失败时**不动 live 文件**；只有"结构 + 全解码 + 图片闸门 + 上传回读 + 安装回读"全过才替换。 +- 杀进程**只按 PID**（绝不用进程名批量杀）；一档一个锁；同一档不要跑两个实例。 +- 动 GPU（更新驱动/跑 ComfyUI/加载大模型）前先暂停 nvenc 档。 diff --git a/references/pitfalls.md b/references/pitfalls.md new file mode 100644 index 0000000..b789bd4 --- /dev/null +++ b/references/pitfalls.md @@ -0,0 +1,29 @@ +# 实测证据与坑（universal-video-transcode） + +每条都是在一个真实媒体库上量出来的，正文只留必须每次记住的铁律。 + +- **A RaiDrive/Dokan write can return with NO error while the file is a fraction of what it should be.** Measured: a 403 MB upload left 12.5 MB on the share, and RaiDrive's own "the operation didn't complete within specific time limit" toast arrived *after* the write had already returned success. Never trust a write to a Dokan-backed share: hash the local file, hash the share copy back, compare size AND SHA-256, and only then rename. On a mismatch, retry the upload (it usually works on the second attempt) rather than failing the item. Uploads should use small chunks (4 MB) with a periodic `flush`+`fsync`; a partial `*.new.mp4`/`*.part.mp4` must be deleted, never resumed from `os.path.getsize()` on the share (RaiDrive reports stale sizes, so a resume offset taken from it corrupts the file). +- **Those same toasts are an overload signal, not a permission problem.** Three jobs reading/writing one share provoked both the truncated write above and `[Errno 9] Bad file descriptor` on a 1 GB staged read; writing into the library folder itself was perfectly fine (verified by creating and deleting a file there). Cap the concurrency at two jobs (one CPU tier + one GPU tier), give each tier its own lock file, and make the lock take over a stale one (pid gone). +- **Compare pictures by TIMESTAMP, never by frame index after an input seek.** An input `-ss` snaps to a keyframe, and it snaps to a *different* keyframe for the source and for the encode - measured: two 1500-frame decodes whose start times differed by ~10 s, so every frame met the wrong one and a perfectly good encode scored min SSIM 0.25. Cut the window with the `trim` filter on absolute PTS (`-copyts -ss -i in -vf "trim=start=X:end=Y,setpts=PTS-STARTPTS,..."`). Validate the method by comparing a file against ITSELF: it must read lo=1.0/mean=1.0, otherwise the harness is broken and every verdict it produces is noise. +- **If the frame counts in the sampled window differ by more than ~1%, the picture gate is NOT APPLICABLE - do not fail the file.** A source with holes in its timeline (measured: 1459 frames where 1500 belong, a 1.7 s hole) is *supposed* to gain duplicated frames from `-fps_mode cfr`; after the hole every frame pairs with the wrong one and SSIM collapses. Report the condition and let the structural/decode/size gates carry the verdict. +- **File paths with a space before the extension are NOT the problem they look like** - `1130 维特根斯坦十讲 .mp4` opened and streamed fine. Suspect the share, not the name. +- **Never kill encoders by process name.** `Get-Process ffmpeg | Stop-Process -Force` also killed an unrelated pilot encode that was running legitimately (rc=-1 mid-encode). Kill the specific background PID, or the specific `ffmpeg` PID you started. + +- **Never write the encode output directly to a network share.** A streaming `.part` write over + SMB/SFTP/Dokan leaves a corrupt stub when the connection blips. Encode to local disk, verify, + then copy the complete file across. The tool writes `dst + ".part.mp4"` and renames only after + verification — keep it on a local path if the destination is remote. +- **`os.path.getsize()` lies on RaiDrive/Dokan** — it returns cached metadata from the *previous* + file handle. Verify a network copy by sequential chunked read, never by size. +- **A `.mkv` extension on a converted file is cosmetic.** TubeSync's rename pass rewrites + finished `.mp4` files back to `.mkv` while `downloaded_container` still reads `mp4`, and + `Content-Type` follows the container. Do not "fix" it and do not report it as a playback bug. +- **Do not re-download to fix a timing defect.** The mkv that yt-dlp writes is itself flat, so a + re-download reproduces the defect exactly. +- **A `-c copy` remux cannot repair timing.** ffmpeg will not rewrite `stts`/`ctts` under stream + copy, and retiming only the SPS (`-bsf:v h264_metadata=tick_rate=…`) changes nothing either. + Repairing a copy-tier file means re-encoding its video — quote the size cost (1.28x at crf 23, + 1.74x at crf 20) before applying it to a whole library. +- **Unicode paths**: on Windows, drive ffmpeg from Python `subprocess` with an argv list. MSYS + bash cannot hand a Chinese filename to native `ffmpeg.exe` even when `ls` shows it. +- **`-hwaccel cuda` alone may still software-decode VP9**; `-c:v vp9_cuvid` forces NVDEC. diff --git a/scripts/library_run.py b/scripts/library_run.py index e9048a3..42d5a30 100644 --- a/scripts/library_run.py +++ b/scripts/library_run.py @@ -129,7 +129,7 @@ def run(cmd, timeout=86400, **kw): errors="replace", timeout=timeout, **kw) -STALL_S = 300 # an encode with no output growth for this long is wedged, not slow +STALL_S = 900 # an encode with no output growth for this long is wedged, not slow def run_watched(cmd, watch, stall_s=STALL_S, timeout=86400): @@ -139,30 +139,46 @@ def run_watched(cmd, watch, stall_s=STALL_S, timeout=86400): updated the NVIDIA driver while it was running, which wedges in-flight GPU work without any error. A multi-day unattended run must recover from that by itself: no output growth for `stall_s` -> kill the command and report a failure the normal retry path can pick up. + + NB the child's stderr goes to a FILE, never a pipe. ffmpeg with `-stats` writes a line every + 0.5 s, which fills a 64 KB pipe within minutes; a blocked ffmpeg stops writing its output, so + the watchdog then kills a perfectly healthy encode (measured: ~270 kills in one night, almost no + work done, while the encoder sat idle in write() on stderr). """ - p = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, text=True, - encoding="utf-8", errors="replace") - last, last_t, t0 = -1, time.time(), time.time() - while p.poll() is None: - time.sleep(30) - if time.time() - t0 > timeout: - p.kill() - p.communicate() - return subprocess.CompletedProcess(cmd, -1, "", "timeout after %d s" % timeout) - try: - sz = os.path.getsize(watch) if os.path.exists(watch) else 0 - except OSError: - sz = last - if sz != last: - last, last_t = sz, time.time() - elif time.time() - last_t > stall_s: - p.kill() - out, err = p.communicate() - log(" !! STALL: no output growth for %d s - killed the wedged encode" % stall_s) - return subprocess.CompletedProcess(cmd, -9, out, - (err or "") + "\nkilled: wedged (no growth for %ds)" % stall_s) - out, err = p.communicate() - return subprocess.CompletedProcess(cmd, p.returncode, out, err) + errf = watch + ".err" + err = "" + with open(errf, "wb") as ferr: + p = subprocess.Popen(cmd, stdout=subprocess.DEVNULL, stderr=ferr) + last, last_t, t0 = -1, time.time(), time.time() + while p.poll() is None: + time.sleep(30) + if time.time() - t0 > timeout: + p.kill() + p.wait() + err = "timeout after %d s" % timeout + break + try: + sz = os.path.getsize(watch) if os.path.exists(watch) else 0 + except OSError: + sz = last + if sz != last: + last, last_t = sz, time.time() + elif time.time() - last_t > stall_s: + p.kill() + p.wait() + log(" !! STALL: no output growth for %d s - killed the wedged encode" % stall_s) + err = "killed: wedged (no growth for %ds)" % stall_s + break + try: + with open(errf, "rb") as f: + data = f.read() + tail = data[-4000:].decode("utf-8", "replace") + err = (tail + "\n" + err).strip() + os.remove(errf) + except OSError: + pass + rc = p.returncode if p.returncode is not None else -9 + return subprocess.CompletedProcess(cmd, rc, "", err) # ---------------------------------------------------------------- integrity