В начале ночного сеанса в логах появилось сообщение от пользователя: "ошибка конвертации на бою". Проверяю контейнер epich_watch:
docker --context epich logs epich_watch --tail 60 2>&1
В выводе сразу двое подозреваемых. Первый очевиден:
ffmpeg error: signal: killed
torrent: file not found after download room f7f8-...: ...ep5.mkv
ffmpeg убит по OOM или таймауту, это случается. Интереснее вторая строка: файл ep5.mkv не найден после завершения загрузки. Но пользователь уточнил, что ep4 ffmpeg убили раньше, а ep5 он загружал уже новой попыткой, и именно ep5 не нашёлся. Это уже не OOM, а что-то другое.
Как устроен watch.epich.ru
Сервис позволяет двум людям смотреть видео синхронно. Один загружает файл (или magnet-ссылку), сервер конвертирует его в HLS, и оба смотрят через hls.js. Пауза одного тут же останавливает видео у второго через WebSocket.
Стек: Go 1.24, gorilla/websocket, anacrolix/torrent v1.61.0, ffmpeg с флагами -hls_flags append_list+temp_file, hls.js 1.5.15 на фронтенде. Состояние комнаты: только в памяти процесса, никаких баз данных для runtime-данных.
Баг 1: файл ещё не файл
anacrolix/torrent пишет данные в ep5.mkv.part и переименовывает в ep5.mkv только после верификации всех кусочков. Верификация начинается, когда BytesCompleted() >= Length(). Но это не одновременные события.
Это хорошо видно при du -sh файлов в пресловутой проблемной комнате: ep4 занимал 4.3 ГБ, ep5: 3.8 ГБ, но из-за sparse-предварительного выделения на диске они занимали лишь 1.3 ГБ суммарно (файлы .part (sparse), данные записываются не подряд).
Как поправили
Retry-цикл между download-loop и os.Stat: ждём появления конечного файла до 10 секунд с шагом 100 мс. Это изначально было inline-циклом, а в следующем коммите вынесено в хелпер waitForFile:
func waitForFile(path string, maxAttempts int, interval time.Duration) bool {
for i := 0; i < maxAttempts; i++ {
if _, err := os.Stat(path); err == nil {
return true
}
time.Sleep(interval)
}
return false
}
// В startTorrentDownload после download-loop:
if !waitForFile(srcPath, 100, 100*time.Millisecond) {
log.Printf("torrent: file did not appear after 10s room %s: path=%s", room.ID, srcPath)
}
// os.Stat(srcPath) ниже уже после retry
Почему 10 секунд? Верификация кусочков занимает от доли секунды до нескольких, в зависимости от диска и размера файла. Для ep5 объёмом 3.8 ГБ это единицы секунд на SSD. Десять секунд: запас с большим перекрытием.
Баг 2: клиент не знает, какое видео активно
После исправления первого бага выяснилось кое-что ещё: торрент загружался и конвертировался нормально, но браузер по-прежнему загружал ep4. Пользователь описал это так: "я загружаю пятую серию, а после конвертации вижу четвёртую".
Это отдельный баг, и он оказался интереснее первого.
Анатомия промаха
На сервере setActiveVideoID(ep5ID) вызывается внутри горутины после завершения скачивания. Переменная activeVideoID обновляется правильно. Потом запускается transport: startTranscodeFrom делает broadcastAll с типом video_status:transcoding. Но этот broadcast не содержал active_video_id.
На фронтенде переменная currentActiveVideoID обновлялась только при получении сообщения video_activated, отдельного события, которое отправляется при явном переключении видео из UI. При torrent-загрузке это событие не отправлялось.
Получался разрыв: сервер знает актуальный ID, браузер: нет. Когда hls_started или ready приходило к клиенту, loadServerVideo() строила URL из устаревшего ep4ID. ep4 мог быть уже полностью готов (он конвертировался раньше и был убит по OOM), поэтому видео грузилось без ошибки, только не то.
Исправление
Решение в двух строках кода. На сервере: добавить active_video_id в broadcast при смене статуса:
// transcode.go — startTranscodeFrom
room.broadcastAll(mustMarshal(map[string]any{
"t": "video_status",
"status": string(VideoTranscoding),
"active_video_id": videoID, // <-- добавлено
}))
// main.go — handleUpload
room.broadcastAll(mustMarshal(map[string]any{
"t": "video_status",
"status": string(VideoUploading),
"active_video_id": videoID, // <-- добавлено
}))
На фронтенде: читать active_video_id до вызова onVideoStatus, потому что именно onVideoStatus вызывает loadServerVideo():
case "video_status":
// active_video_id может прийти вместе со статусом —
// обновляем до onVideoStatus, чтобы loadServerVideo использовал верный ID
if (msg.active_video_id) currentActiveVideoID = msg.active_video_id;
onVideoStatus(msg.status);
break;
Тесты и рефакторинг ради тестируемости
После каждого фикса добавлялись unit-тесты. Для waitForFile написались три сценария: файл уже есть, файл появляется через 50 мс, файл так и не появился. Тест с появлением файла создаёт временный файл в горутине через time.AfterFunc:
func TestWaitForFile_FileAppearsLater(t *testing.T) {
dir := t.TempDir()
path := filepath.Join(dir, "target.mkv")
time.AfterFunc(50*time.Millisecond, func() {
os.WriteFile(path, []byte("x"), 0o600)
})
if !waitForFile(path, 20, 20*time.Millisecond) {
t.Error("expected file to appear within 400ms")
}
}
С тестом на active_video_id в broadcast получилась история. Первая попытка: создать комнату, запустить startTranscodeFrom, проверить что broadcast содержит нужное поле. Тест падал, потому что os.MkdirAll("/app/data/hls/...") возвращал ошибку, в тестовом окружении нет /app. Но перед MkdirAll broadcast ещё не был отправлен, проверять было нечего.
Правильное решение: поменять порядок: сначала broadcast, потом MkdirAll. Это и лучше для UX (партнёр видит "конвертирую" раньше), и тест начинает работать без моков файловой системы. При ошибке MkdirAll теперь явно переводим комнату в VideoError и сообщаем об этом обоим клиентам:
func startTranscodeFrom(room *Room, inputPath string, ...) {
go func() {
// Сначала атомарно меняем статус и сообщаем клиентам
if !room.trySetVideoStatus(fromStatus, VideoTranscoding) {
return
}
room.broadcastAll(mustMarshal(map[string]any{
"t": "video_status",
"status": string(VideoTranscoding),
"active_video_id": videoID,
}))
// Потом файловые операции
hlsDir := hlsDirPath(room.ID, videoID)
if err := os.MkdirAll(hlsDir, 0o700); err != nil {
if room.trySetVideoStatus(VideoTranscoding, VideoError) {
room.broadcastAll(mustMarshal(map[string]any{...}))
}
return
}
// ... ffmpeg ...
}()
}
Теперь тест создаёт комнату с двумя mock-клиентами, запускает функцию и читает из канала:
func TestStartTranscodeFrom_BroadcastsActiveVideoID(t *testing.T) {
h := &Hub{rooms: make(map[string]*Room)}
r := h.GetOrCreate("test-broadcast")
r.setActiveVideoID("ep4videoid0000")
c1 := &Client{room: r, send: make(chan []byte, 16)}
c2 := &Client{room: r, send: make(chan []byte, 16)}
r.join(c1)
r.join(c2)
startTranscodeFrom(r, "/nonexistent/input.mkv", VideoDownloading,
"ep5videoid0000", "ep5.mkv", 1000)
select {
case raw := <-c1.send:
var msg map[string]any
json.Unmarshal(raw, &msg)
if msg["active_video_id"] != "ep5videoid0000" {
t.Errorf("active_video_id = %v, want ep5videoid0000", msg["active_video_id"])
}
case <-time.After(200 * time.Millisecond):
t.Fatal("no broadcast received")
}
}
1.3 ГБ на сервере
Пока разбирался с багами, заглянул в хранилище торрентов на проде:
docker --context epich exec epich_watch du -sh /app/data/watch-torrents/*
Нашлась директория комнаты от 14 марта (572f-484f-7081-d7c9) : именно та, где произошёл первоначальный сбой. В ней два sparse-файла: ep4.mkv.part (4.3 ГБ виртуально, ~0.8 ГБ реально) и ep5.mkv.part (3.8 ГБ виртуально, ~0.5 ГБ реально). Сервер перезапускался после того сбоя, komнатa была брошена, но файлы остались.
Постоянная уборка "потерянных" хранилищ при старте сервиса: задача для бэклога. Комната без участников с несуществующим torrent-handle может уводить данные в "сирот".
Хронология коммитов
Что унёс из этого сеанса
anacrolix/torrent и переименование файлов
Библиотека использует .part-суффикс и делает rename только после верификации SHA1 всех кусочков. Это задокументировано в исходниках, но легко пропустить. BytesCompleted() >= Length() не означает "файл на диске": это означает "все байты получены и записаны в storage". Верификация занимает ещё некоторое время.
Хелпер waitForFile с разумным таймаутом: дешёвое и работающее решение. Альтернатива: подписаться на channel t.Complete(), но он есть только для целых torrent-объектов, не для отдельных файлов.
WS broadcast: контракт состояния
Когда сервер меняет state и отправляет broadcast об этом изменении, клиент должен получить весь необходимый для реакции контекст внутри одного сообщения. Разделение "меняем state" и "сообщаем ID" на два разных места создаёт окно гонки.
Простое правило: если broadcast описывает событие "X сменило своё активное видео на Y", то и X, и Y должны быть в теле сообщения. Клиент не обязан помнить, что было "активным" до.
Порядок операций определяет тестируемость
Код "broadcast → MkdirAll" проще тестируется, чем "MkdirAll → broadcast". Не потому что так удобнее писать тест, а потому что первый вариант имеет более чёткий инвариант: клиент всегда получает уведомление о смене статуса, даже если файловая операция потом упадёт. Это и правильнее семантически.