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.
This commit is contained in:
2026-10-08 10:30:59 +08:00
parent 5c911f5450
commit 832c76619a
4 changed files with 146 additions and 49 deletions
+12 -25
View File
@@ -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=<N>' | 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 <before window> -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
+65
View File
@@ -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-<tier>.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 档。
+29
View File
@@ -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 <before window> -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.
+40 -24
View File
@@ -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