Files
jellybit/internal/worker/recovery_test.go
T
avandClaude Opus 4.8 8261d5b55d Retry/stall: сброс базиса таймаута + простой от last_activity (MAJOR-1, MAJOR-2)
Два связанных бага семантики таймаутов зависания и ручного retry.

MAJOR-1: Retry живого торрента не сбрасывал базис отсчёта таймаута — задача
мгновенно снова падала в stuck на ближайшем тике. Вводим колонку
download.retried_at (миграция 0010): ручной retry фиксирует момент и
приподнимает пол обоих таймаутов (max(базис, retried_at)). Хранится в БД, а
не в памяти, чтобы сброс пережил тик поллинга и рестарт.

MAJOR-2: stuck_after мерил ВОЗРАСТ торрента (от added_on), а не ПРОСТОЙ —
долго качавшийся торрент, на миг зашедший в stalledDL, ложно уходил в stuck
со «stalled for 5h». Теперь stuck_after мерит простой от qBit last_activity
(новое поле qbt.Torrent из того же ответа /torrents/info); magnet_timeout
по-прежнему мерит возраст (семантически верно). checkTimeouts разбит на
torrentAge/stallDuration/addedBasis/retriedFloor.

NIT-10: фолбэк базиса возраста added_on→created_at сохранён и покрыт.
NIT-12: retry перестаёт перецепляться к сломанному живому торренту
(error/missingFiles) — повторно отдаёт источник (перецепка к нему
бессмысленна: reconcile тут же вернул бы в failed).

Спека: дельта state-reconciliation (MODIFIED «Восстановление зависшей
загрузки» и «Ручной повтор»), правка docs/specs/workflow.md (устранено
противоречие «возраст vs простой»), ER-схема database.md.

Тесты: TestRetryResetsTimeoutBasis (следующий тик после retry — прячется в
TestRetryReattachesNoReadd), TestStallMeasuredFromLastActivity,
TestSetRetriedAtOverwrites.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-08 17:18:28 +03:00

242 lines
11 KiB
Go
Raw 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 worker
import (
"context"
"testing"
"time"
"git.vakhrushev.me/av/jellybit/internal/qbt"
"git.vakhrushev.me/av/jellybit/internal/store"
)
// addedRecent — added_on торрента «минуту назад» относительно зафиксированного
// в newTestWorker now (2026-06-14 10:00:00 UTC).
var addedRecent = time.Date(2026, 6, 14, 9, 59, 0, 0, time.UTC).Unix()
func oneFailed(state store.State, code, infohash, createdAt string) *fakeStore {
return &fakeStore{downloads: map[string]*store.Download{
"1": {
ID: "1",
State: state,
SourceType: store.SourceMagnet,
SourceRef: "magnet:?xt=urn:btih:" + infohash,
Infohashes: hashesOf("1", infohash),
ErrorCode: store.NullString(code),
CreatedAt: createdAt,
},
}}
}
func TestRecovery(t *testing.T) {
const ih = "541adcff3b6dd5dba7088ea83317d9d6fac331d6"
tests := []struct {
name string
state store.State
code string
qbitState string
want store.State
}{
{"метаданные пришли → downloading", store.StateFailed, errCodeMagnetTimeout, "downloading", store.StateDownloading},
{"торрент готов → completed", store.StateFailed, errCodeMagnetTimeout, "uploading", store.StateCompleted},
{"всё ещё metaDL → остаётся failed", store.StateFailed, errCodeMagnetTimeout, "metaDL", store.StateFailed},
{"stalled ожил → downloading", store.StateStuck, errCodeStalled, "downloading", store.StateDownloading},
{"stalled всё ещё stalledDL → остаётся stuck", store.StateStuck, errCodeStalled, "stalledDL", store.StateStuck},
{"qbit_error не восстанавливается", store.StateFailed, errCodeQbitError, "downloading", store.StateFailed},
{"ошибка торрента не восстанавливает", store.StateFailed, errCodeMagnetTimeout, "error", store.StateFailed},
}
for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
st := oneFailed(tc.state, tc.code, ih, timeOld)
qb := &fakeQbt{torrents: []qbt.Torrent{{Hash: ih, State: tc.qbitState, AddedOn: addedRecent}}}
w := newTestWorker(st, qb)
if err := w.Poll(context.Background()); err != nil {
t.Fatalf("Poll: %v", err)
}
if got := st.downloads["1"].State; got != tc.want {
t.Errorf("state = %q, want %q", got, tc.want)
}
})
}
}
// Источник пропал (торрента нет в qBittorrent) — задача остаётся failed,
// воскрешать нечего (вернёт ручной retry).
func TestRecoveryNoSourceStaysFailed(t *testing.T) {
const ih = "541adcff3b6dd5dba7088ea83317d9d6fac331d6"
st := oneFailed(store.StateFailed, errCodeMagnetTimeout, ih, timeOld)
w := newTestWorker(st, &fakeQbt{torrents: nil})
if err := w.Poll(context.Background()); err != nil {
t.Fatal(err)
}
if st.downloads["1"].State != store.StateFailed {
t.Errorf("без источника задача должна остаться failed, got %q", st.downloads["1"].State)
}
}
// Конфликт идемпотентности: тот же infohash уже взяла другая активная задача —
// упавшую не воскрешаем (иначе нарушим «одна активная задача на infohash»).
func TestRecoverySkipsOnIdempotencyConflict(t *testing.T) {
const ih = "541adcff3b6dd5dba7088ea83317d9d6fac331d6"
st := oneFailed(store.StateFailed, errCodeMagnetTimeout, ih, timeOld)
st.downloads["2"] = &store.Download{
ID: "2",
State: store.StateDownloading,
SourceType: store.SourceMagnet,
Infohashes: hashesOf("2", ih),
CreatedAt: timeRecent,
}
qb := &fakeQbt{torrents: []qbt.Torrent{{Hash: ih, State: "downloading", AddedOn: addedRecent}}}
w := newTestWorker(st, qb)
if err := w.Poll(context.Background()); err != nil {
t.Fatal(err)
}
if st.downloads["1"].State != store.StateFailed {
t.Errorf("при конфликте ключа задача #1 должна остаться failed, got %q", st.downloads["1"].State)
}
}
// Тот же конфликт ключа, но торрент уже готов (recovery хочет completed):
// completed тоже нетерминален и восстановил бы idempotency_key — проверка
// конфликта обязана покрывать и эту ветку.
func TestRecoverySkipsConflictOnCompleted(t *testing.T) {
const ih = "541adcff3b6dd5dba7088ea83317d9d6fac331d6"
st := oneFailed(store.StateFailed, errCodeMagnetTimeout, ih, timeOld)
st.downloads["2"] = &store.Download{
ID: "2",
State: store.StateDownloading,
SourceType: store.SourceMagnet,
Infohashes: hashesOf("2", ih),
CreatedAt: timeRecent,
}
qb := &fakeQbt{torrents: []qbt.Torrent{{Hash: ih, State: "uploading", AddedOn: addedRecent}}}
w := newTestWorker(st, qb)
if err := w.Poll(context.Background()); err != nil {
t.Fatal(err)
}
if st.downloads["1"].State != store.StateFailed {
t.Errorf("при конфликте ключа задача #1 не должна уходить в completed, got %q", st.downloads["1"].State)
}
}
// Повторное падение одной задачи в пределах окна дебаунса шлёт уведомление лишь
// раз (защита от спама при флаппинге stuck↔downloading).
func TestFailNotifyDebounce(t *testing.T) {
const ih = "541adcff3b6dd5dba7088ea83317d9d6fac331d6"
st := oneFailed(store.StateStuck, errCodeStalled, ih, timeOld)
w := newTestWorker(st, &fakeQbt{})
n := &recordingNotifier{ch: make(chan notifyEvent, 4)}
w.SetNotifier(n)
d := *st.downloads["1"]
w.transition(context.Background(), d, store.StateStuck, errCodeStalled, "")
if e := waitNotify(t, n); e.ev != EventFailed {
t.Fatalf("первый пинг: ev=%v, want failed", e.ev)
}
// Второе падение при том же w.now() — в пределах дебаунса, без пинга.
w.transition(context.Background(), d, store.StateStuck, errCodeStalled, "")
select {
case e := <-n.ch:
t.Fatalf("повторный пинг в пределах дебаунса не ожидался: %+v", e)
case <-time.After(200 * time.Millisecond):
}
}
// Retry при живом торренте перецепляется к нему (без повторного Add) и не падает
// снова на ближайшем тике: базис таймаута берётся от added_on, а не от старого
// created_at.
func TestRetryReattachesNoReadd(t *testing.T) {
const ih = "541adcff3b6dd5dba7088ea83317d9d6fac331d6"
st := oneFailed(store.StateFailed, errCodeMagnetTimeout, ih, timeOld)
// Торрент жив, всё ещё тянет метаданные, но добавлен только что (added_on).
qb := &fakeQbt{torrents: []qbt.Torrent{{Hash: ih, State: "metaDL", AddedOn: addedRecent}}}
w := newTestWorker(st, qb)
if err := w.Retry(context.Background(), "1"); err != nil {
t.Fatalf("Retry: %v", err)
}
if st.downloads["1"].State != store.StateDownloading {
t.Fatalf("после retry ожидался downloading, got %q", st.downloads["1"].State)
}
if len(qb.added) != 0 {
t.Errorf("живой торрент не должен добавляться повторно, got %d Add", len(qb.added))
}
// Ближайший тик: metaDL свежий (added_on минуту назад) — не падает по таймауту.
if err := w.Poll(context.Background()); err != nil {
t.Fatal(err)
}
if st.downloads["1"].State != store.StateDownloading {
t.Errorf("свежий metaDL не должен падать после retry, got %q", st.downloads["1"].State)
}
}
// addedLongAgo — added_on «5 часов назад» относительно now теста (10:00:00 UTC):
// торрент давно в qBittorrent (возраст сам по себе большой).
var addedLongAgo = time.Date(2026, 6, 14, 5, 0, 0, 0, time.UTC).Unix()
// lastActivityLongAgo — last_activity «2 часа назад»: данные давно не двигались.
var lastActivityLongAgo = time.Date(2026, 6, 14, 8, 0, 0, 0, time.UTC).Unix()
// MAJOR-1: retry живого, но давно добавленного и простаивающего stalledDL-торрента
// сбрасывает базис таймаута (retried_at), поэтому СЛЕДУЮЩИЙ тик не роняет задачу
// снова в stuck. Без сброса базиса stallDuration=nowlast_activity (2ч) > StuckAfter
// (1ч) → задача мгновенно вернулась бы в stuck (регрессия, которую прячет
// TestRetryReattachesNoReadd, ставящий added_on/last_activity «минуту назад»).
func TestRetryResetsTimeoutBasis(t *testing.T) {
const ih = "541adcff3b6dd5dba7088ea83317d9d6fac331d6"
st := oneFailed(store.StateStuck, errCodeStalled, ih, timeOld)
// Торрент жив, но давно добавлен (added_on 5ч) и давно простаивает
// (last_activity 2ч) — по старой мере «возраст» он мгновенно снова stuck.
qb := &fakeQbt{torrents: []qbt.Torrent{{
Hash: ih, State: "stalledDL",
AddedOn: addedLongAgo, LastActivity: lastActivityLongAgo,
}}}
w := newTestWorker(st, qb)
if err := w.Retry(context.Background(), "1"); err != nil {
t.Fatalf("Retry: %v", err)
}
if len(qb.added) != 0 {
t.Errorf("живой здоровый торрент не должен добавляться повторно, got %d Add", len(qb.added))
}
if !st.downloads["1"].RetriedAt.Valid {
t.Error("retry должен проставить retried_at (сброс базиса)")
}
// Ключевая проверка MAJOR-1: следующий тик поллинга.
if err := w.Poll(context.Background()); err != nil {
t.Fatal(err)
}
if got := st.downloads["1"].State; got != store.StateDownloading {
t.Errorf("после retry задача не должна снова падать в stuck на ближайшем тике, got %q", got)
}
}
// MAJOR-2: stuck_after мерит ДЛИТЕЛЬНОСТЬ ПРОСТОЯ (nowlast_activity), а не возраст
// торрента. Долго качавшийся торрент (added_on 5ч назад) с недавним движением
// данных (last_activity 30с назад), на миг зашедший в stalledDL, НЕ уходит в stuck.
func TestStallMeasuredFromLastActivity(t *testing.T) {
const ih = "541adcff3b6dd5dba7088ea83317d9d6fac331d6"
lastActivityRecent := time.Date(2026, 6, 14, 9, 59, 30, 0, time.UTC).Unix() // 30с назад
st := oneDownloading(ih, timeOld)
qb := &fakeQbt{torrents: []qbt.Torrent{{
Hash: ih, State: "stalledDL",
AddedOn: addedLongAgo, LastActivity: lastActivityRecent,
}}}
w := newTestWorker(st, qb)
if err := w.Poll(context.Background()); err != nil {
t.Fatal(err)
}
if got := st.downloads["1"].State; got != store.StateDownloading {
t.Errorf("свежая активность (30с) — не stuck несмотря на возраст 5ч, got %q", got)
}
// Контроль: тот же торрент, но данные давно не двигались (last_activity 2ч) —
// простой превысил StuckAfter (1ч) → stuck.
qb.torrents[0].LastActivity = lastActivityLongAgo
if err := w.Poll(context.Background()); err != nil {
t.Fatal(err)
}
if got := st.downloads["1"].State; got != store.StateStuck {
t.Errorf("простой 2ч > stuck_after 1ч должен дать stuck, got %q", got)
}
}