Files
acfunlive-remake/diagnostics_test.go
tamakyi 3eb4aa3102 让 ffmpeg 的报错能进日志,并堵住三处会直接毁掉整块渲染的坑
背景:线上第 153/648 块失败,三个编码器依次报同一个 "exit status 0xffffffea"
(EINVAL)。可用的线索只有这一句 —— 因为 ffmpeg 自己的输出走的是 os.Stderr,
服务模式下没人看,等于丢掉了。所以这轮先解决"看不到原因",再顺手补几处防御。

一、把 ffmpeg 的报错留在日志里
   runFFmpegWith 给 stderr 挂一个只保留最后 40 行的 writer(进度行用 \r 刷新,
   一并按行处理),失败时把这段附在错误上再由上层 lPrintErrf 写进日志。
   顺带过滤掉每次启动都打印的版本/编译配置那几行(configuration 一行就一千多字符,
   留着会把真正的报错挤出去)。实测效果:报错里直接能看到
   "moov atom not found" / "Error opening input: Invalid data found"。

二、跟编码器无关的失败不再挨个回退
   滤镜图建不起来、输入文件打不开这类问题,换个编码器结果一模一样。
   原来会把同一件事重跑三遍(hevc_qsv → h264_qsv → libx264),既浪费时间
   又在日志里刷三行看不出区别的错误。现在命中这些关键词就直接报出完整错误。

三、头像 split 的份数必须和真正用到的份数一致
   统计头像用量时按整块弹幕算,生成 overlay 时才做可见性裁剪:
   同一 uid 在本块有多条、其中一条整条落在块外的话,split 会多出一个没人接收的输出 pad,
   ffmpeg 直接 EINVAL 退出(报错完全看不出跟弹幕有关)。抽出 danmuVisibleInChunk
   让统计、生成 overlay、写块字幕三处用同一个判断。

四、缓存命中要校验文件完整,下载改成原子写
   原来只看"文件在不在",被写一半的 PNG 会被当成可用缓存塞给 ffmpeg 当输入。
   现在要求 PNG 以 IEND 收尾(16 字节以下直接判无效),下载先写 .part 再改名,
   旧位置搬过来的文件同样要过这道校验。

五、头像直径至少为 1
   有人把 danmuFontSize 填成 1、2 时 avatarSize 会算出 0,而 scale=0:0
   会让 ffmpeg 直接 EINVAL、整块渲染失败。

验证:
- gofmt / go vet / go build 通过;go test 全绿(16.8s);go test -race 全绿(22.8s);
  staticcheck -checks=all 零告警
- 新增 diagnostics_test.go(10 个)与 split_pad_test.go(1 个)用例;
  反向验证扩到 21 项全过
- 隔离实例:e2e.py 37 项、smoke_extra.py 33 项、smoke_late_danmu.py(越界弹幕场景)全过;
  另用一个损坏的 mp4 实测,任务失败时日志里能看到 ffmpeg 的原话,
  且没有出现编码器回退
2026-09-26 12:15:14 +08:00

310 lines
9.5 KiB
Go
Raw Permalink Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
package main
import (
"bytes"
"errors"
"fmt"
"image"
"image/png"
"net/http"
"net/http/httptest"
"os"
"path/filepath"
"strings"
"sync/atomic"
"testing"
)
// ==================== ffmpeg 报错的可见性 ====================
// 尾部 writer 只留最近若干行(ffmpeg 的进度行会不停刷)
func TestTailWriterKeepsLastLines(t *testing.T) {
w := newTailWriter(3)
fmt.Fprint(w, "第1行\n第2行\n第3行\r第4行\n第5行\n")
got := w.String()
if !strings.Contains(got, "第5行") {
t.Fatalf("应当保留最后一行:%q", got)
}
if strings.Contains(got, "第1行") || strings.Contains(got, "第2行") {
t.Fatalf("超出保留行数的旧内容应当被丢掉:%q", got)
}
if lines := strings.Split(got, "\n"); len(lines) != 3 {
t.Fatalf("应当只留 3 行,实际 %d 行:%q", len(lines), got)
}
}
// 失败时要把 ffmpeg 自己的报错带上,不然只剩一句 exit status
func TestFFmpegResultCarriesStderr(t *testing.T) {
err := ffmpegResult(errors.New("exit status 0xffffffea"), "Error binding filtergraph inputs/outputs")
if err == nil {
t.Fatal("应当返回错误")
}
msg := err.Error()
if !strings.Contains(msg, "exit status 0xffffffea") || !strings.Contains(msg, "Error binding filtergraph") {
t.Fatalf("错误里应当同时有退出状态和 ffmpeg 的说明,实际:%s", msg)
}
// 成功时不带任何东西
if got := ffmpegResult(nil, "随便什么输出"); got != nil {
t.Fatalf("成功时应当返回 nil,实际 %v", got)
}
// 没有 stderr 时保持原样
plain := errors.New("exit status 1")
if got := ffmpegResult(plain, " "); got != plain {
t.Fatalf("没有 ffmpeg 输出时应当原样返回,实际 %v", got)
}
}
// 跟编码器无关的失败不该挨个回退重试
func TestEncoderMightHelp(t *testing.T) {
unrelated := []string{
"Error binding filtergraph inputs/outputs: Invalid argument",
"Error initializing filtergraph",
"Error opening input: No such file or directory",
}
for _, msg := range unrelated {
if encoderMightHelp(errors.New(msg)) {
t.Fatalf("这类失败跟编码器无关,不该回退重试:%s", msg)
}
}
related := []string{
"Error initializing output stream 0:0 -- Error while opening encoder",
"hevc_qsv: Function not implemented",
}
for _, msg := range related {
if !encoderMightHelp(errors.New(msg)) {
t.Fatalf("编码器自身的失败应当允许回退:%s", msg)
}
}
}
// ==================== 头像缓存完整性 ====================
func tinyPNG(t *testing.T) []byte {
t.Helper()
var buf bytes.Buffer
if err := png.Encode(&buf, image.NewRGBA(image.Rect(0, 0, 8, 8))); err != nil {
t.Fatal(err)
}
return buf.Bytes()
}
// 半截的 PNG 不能被当成可用缓存
func TestValidCachedAvatar(t *testing.T) {
dir := t.TempDir()
good := tinyPNG(t)
full := filepath.Join(dir, "full.png")
if err := os.WriteFile(full, good, 0644); err != nil {
t.Fatal(err)
}
if !validCachedAvatar(full) {
t.Fatal("完整的 PNG 应当算有效")
}
// 砍掉尾巴(模拟下载中断)
cut := filepath.Join(dir, "cut.png")
if err := os.WriteFile(cut, good[:len(good)-8], 0644); err != nil {
t.Fatal(err)
}
if validCachedAvatar(cut) {
t.Fatal("半截 PNG 不该算有效")
}
empty := filepath.Join(dir, "empty.png")
if err := os.WriteFile(empty, nil, 0644); err != nil {
t.Fatal(err)
}
if validCachedAvatar(empty) {
t.Fatal("空文件不该算有效")
}
if validCachedAvatar(filepath.Join(dir, "不存在.png")) {
t.Fatal("不存在的文件不该算有效")
}
}
// 命中的是半截缓存时要重新下载,下载完必须是完整 PNG
func TestEnsureAvatarRedownloadsBrokenCache(t *testing.T) {
withJobFlags(t, true, false, false)
dir := t.TempDir()
var hits int64
body := tinyPNG(t)
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
atomic.AddInt64(&hits, 1)
w.Header().Set("Content-Type", "image/png")
_, _ = w.Write(body)
}))
defer srv.Close()
url := srv.URL + "/a.png"
path := filepath.Join(dir, avatarCacheName(42, url))
// 先摆一个「写了一半」的缓存
if err := os.WriteFile(path, body[:len(body)-8], 0644); err != nil {
t.Fatal(err)
}
if validCachedAvatar(path) {
t.Fatal("前置条件不成立:半截文件应当被判为无效")
}
got := ensureAvatar(42, url, dir)
if got != path {
t.Fatalf("应当返回缓存路径 %q,实际 %q", path, got)
}
if atomic.LoadInt64(&hits) == 0 {
t.Fatal("半截缓存应当触发重新下载")
}
if !validCachedAvatar(path) {
t.Fatal("重新下载之后应当是完整的 PNG")
}
}
// 完好的缓存不该再走网络
func TestEnsureAvatarUsesGoodCache(t *testing.T) {
withJobFlags(t, true, false, false)
dir := t.TempDir()
var hits int64
body := tinyPNG(t)
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
atomic.AddInt64(&hits, 1)
_, _ = w.Write(body)
}))
defer srv.Close()
url := srv.URL + "/b.png"
path := filepath.Join(dir, avatarCacheName(43, url))
if err := os.WriteFile(path, body, 0644); err != nil {
t.Fatal(err)
}
if got := ensureAvatar(43, url, dir); got != path {
t.Fatalf("应当直接命中缓存,实际 %q", got)
}
if n := atomic.LoadInt64(&hits); n != 0 {
t.Fatalf("完好的缓存不该再请求网络,实际 %d 次", n)
}
}
// 下载过程中不会留下能被误用的半截文件
func TestDownloadAvatarWritesAtomically(t *testing.T) {
withJobFlags(t, true, false, false)
dir := t.TempDir()
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
_, _ = w.Write(tinyPNG(t))
}))
defer srv.Close()
url := srv.URL + "/c.png"
path := filepath.Join(dir, avatarCacheName(44, url))
if err := downloadAvatar(44, url, path); err != nil {
t.Fatalf("下载不该失败:%v", err)
}
if !validCachedAvatar(path) {
t.Fatal("下载完的缓存应当是完整 PNG")
}
// 临时文件不该留下
if entries, err := os.ReadDir(dir); err == nil {
for _, e := range entries {
if strings.HasSuffix(e.Name(), ".part") {
t.Fatalf("不该留下临时文件:%s", e.Name())
}
}
}
}
// 记录当前日志长度,返回一个能读到之后新增内容的函数
func logCursor() func() string {
logString.Lock()
start := logString.str.Len()
logString.Unlock()
return func() string {
logString.Lock()
defer logString.Unlock()
data := logString.str.String()
if start > len(data) {
return data // 中间被 Reset 过,那就给全部
}
return data[start:]
}
}
// 头像输入打不开属于「跟编码器无关」的失败:不该挨个编码器回退重试,
// 而且 ffmpeg 自己的报错必须留在日志里(否则只剩一句 exit status 0xffffffea)
func TestRenderChunkDoesNotFallBackOnUnrelatedFailure(t *testing.T) {
ffmpegFile := getFFmpeg()
if ffmpegFile == "" {
t.Skip("找不到 ffmpeg,跳过")
}
withJobFlags(t, true, false, false)
dir := t.TempDir()
video := filepath.Join(dir, "in.mp4")
makeTinyVideo(t, ffmpegFile, video, "red")
uid := int64(1)
chunk := danmuChunk{start: 0, end: 1, records: []danmuRecord{
{Time: 0.2, UID: uid, Name: "甲", Content: "正常一条", Lane: 0, Width: 100},
}}
ctx := &burnContext{
ffmpegFile: ffmpegFile,
videoFile: video,
outFile: filepath.Join(dir, "out.mp4"),
meta: danmuMeta{PlayResX: 160, PlayResY: 120, FontSize: 20},
// 头像文件根本不存在:ffmpeg 打开输入就会失败
avatars: map[int64]string{uid: filepath.Join(dir, "根本没有这个头像.png")},
dir: dir,
// 故意不指定 encoder:从候选列表第一个开始,才能看出有没有挨个回退
}
ad, gap := avatarSize(ctx.meta.FontSize), avatarGap(ctx.meta.FontSize)
if err := writeChunkAss(filepath.Join(dir, "chunk.ass"), ctx.meta, chunk, 0, ad, gap); err != nil {
t.Fatal(err)
}
read := logCursor()
err := ctx.renderChunk(chunk, "chunk.ass", filepath.Join(dir, "out.mp4"), false, nil)
if err == nil {
t.Fatal("头像打不开时应当渲染失败")
}
msg := err.Error()
if !strings.Contains(msg, "ffmpeg 最后的输出") {
t.Fatalf("错误里应当带上 ffmpeg 自己的输出:%s", msg)
}
if log := read(); strings.Contains(log, "回退到") {
t.Fatalf("输入打不开跟编码器无关,不该挨个回退重试:\n%s", log)
}
}
// 启动时那段版本/编译配置要过滤掉,别把真正的报错挤出日志
func TestTailWriterSkipsStartupNoise(t *testing.T) {
w := newTailWriter(10)
fmt.Fprint(w, "ffmpeg version n9.0.2-3\n"+
" built with gcc 16.2.0\n"+
" configuration: --prefix=/ffbuild --enable-gpl --enable-libass 等等很长的一行\n"+
" libavutil 61. 1.102 / 61. 1.102\n"+
" libswscale 10. 1.102 / 10. 1.102\n"+
"[in#0 @ 0x1] moov atom not found\n"+
"Error opening input files: Invalid data found when processing input\n")
got := w.String()
for _, noise := range []string{"ffmpeg version", "configuration:", "libavutil", "libswscale", "built with"} {
if strings.Contains(got, noise) {
t.Fatalf("启动信息应当被过滤掉(%s),实际:%q", noise, got)
}
}
if !strings.Contains(got, "moov atom not found") || !strings.Contains(got, "Invalid data found") {
t.Fatalf("真正的报错必须保留:%q", got)
}
}
// 头像直径再小也要 >= 1,否则 scale=0:0 会让 ffmpeg 直接 EINVAL
func TestAvatarSizeNeverZero(t *testing.T) {
for _, fs := range []int{0, 1, 2, 5, 42, 60} {
if got := avatarSize(fs); got < 1 {
t.Fatalf("字号 %d 算出的头像直径是 %d,应当至少为 1", fs, got)
}
}
if got := avatarSize(60); got != 48 {
t.Fatalf("正常字号的口径不该变:60 -> %d(应为 48)", got)
}
}