feat(latest): record one poll pass per exit with skip reason and outcome counts

Every way a Lane pass can end now writes exactly one durable row: a skip
value naming the exit (paused, refusing, sidecar-down, no-fetcher,
due-query, asleep, eligible-count, nothing-eligible, or empty for the
loop), five outcome counts from the classification the Series read already
makes, and carry-forward of the previous pass's figures exactly when the
pass's own gap is zero. Refusal is durable through the poll_lanes row, so
a restart does not re-probe a Site inside its backoff. Retention is 14
days. The mid-loop browser-unreachable return writes an empty skip by
design: a tenth value is not invented here. (#141)
This commit is contained in:
2026-08-21 18:48:30 +07:00
parent e0b9063d9e
commit 503fb49d0a
4 changed files with 686 additions and 43 deletions
+459 -1
View File
@@ -427,9 +427,12 @@ func TestRunLogsLaneDefaults(t *testing.T) {
log.SetOutput(&logs)
t.Cleanup(func() { log.SetOutput(previous) })
// The pass log writes through the store, so Run needs a real one — a
// poller without a Store is not a poller.
s, _ := newTestStore(t)
ctx, cancel := context.WithCancel(context.Background())
cancel()
(&Poller{Now: func() time.Time { return time.Now() }}).Run(ctx)
(&Poller{Store: s, Now: func() time.Time { return time.Now() }}).Run(ctx)
got := logs.String()
for _, want := range []string{"6 lanes", "rest=1h0m0s", "gap=10s"} {
@@ -1689,3 +1692,458 @@ func TestLaneStatus(t *testing.T) {
t.Fatalf("browser after loss = configured=%v reachable=%v, want true/false", st.BrowserConfigured, st.BrowserReachable)
}
}
// latestPassFor reads a Site's newest durable pass row, failing rather than
// returning a zero LanePass a caller would assert against by accident.
func latestPassFor(t *testing.T, s *store.Store, site string) store.LanePass {
t.Helper()
pass, ok, err := s.LatestLanePass(site)
if err != nil || !ok {
t.Fatalf("LatestLanePass(%s): ok=%v err=%v", site, ok, err)
}
return pass
}
// countPassRows counts a Site's durable pass rows, for asserting that a pass
// records exactly one.
func countPassRows(t *testing.T, dbURL, site string) int {
t.Helper()
db, err := sql.Open("pgx", dbURL)
if err != nil {
t.Fatalf("open %s: %v", dbURL, err)
}
defer db.Close()
var n int
if err := db.QueryRow(`SELECT count(*) FROM poll_passes WHERE site = $1`, site).Scan(&n); err != nil {
t.Fatalf("count passes for %s: %v", site, err)
}
return n
}
// One durable pass row per exit, with the skip value naming the exit. The
// mid-loop browser-unreachable return also writes one row — but with an empty
// skip, so the row is stall-shaped (due > 0, checked 0, skip ”), matching the
// deliberate absence of a tenth skip value.
func TestRunLanePassRecordsEveryExit(t *testing.T) {
now := time.UnixMilli(5_000_000)
t.Run("paused", func(t *testing.T) {
s, dbURL := newTestStore(t)
seedForCheck(t, s, "asura:x", "https://asurascans.com/series/x", 0)
if err := s.PauseLane("asura", now.Add(30*time.Minute).UnixMilli()); err != nil {
t.Fatalf("PauseLane: %v", err)
}
f := &fakeFetcher{body: asuraSeriesFixture, status: 200}
p := newTestPoller(t, s, f, now)
if pace := p.runLanePass(context.Background(), "asura", false); pace != 30*time.Minute {
t.Fatalf("paused pace = %s, want 30m (sleep until the expiry)", pace)
}
if f.callCount() != 0 {
t.Fatalf("fetches while paused = %d, want 0", f.callCount())
}
if got := readLatestCheckedAt(t, s, "asura:x"); got != 0 {
t.Fatalf("stamp while paused = %d, want 0 (Series stay due and unstamped)", got)
}
if pass := latestPassFor(t, s, "asura"); pass.Skip != skipPaused {
t.Fatalf("skip = %q, want %q", pass.Skip, skipPaused)
}
if got := countPassRows(t, dbURL, "asura"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
t.Run("refusing", func(t *testing.T) {
s, dbURL := newTestStore(t)
seedForCheck(t, s, "kagane:x", "https://kagane.to/series/x", 0)
if err := s.SetLaneRefusal("kagane", now.Add(10*time.Minute).UnixMilli()); err != nil {
t.Fatalf("SetLaneRefusal: %v", err)
}
browser := &fakeFetcher{status: 200}
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
p.BrowserFetch = browser
if pace := p.runLanePass(context.Background(), "kagane", false); pace != 10*time.Minute {
t.Fatalf("refusing pace = %s, want 10m", pace)
}
if browser.callCount() != 0 {
t.Fatalf("fetches while refusing = %d, want 0", browser.callCount())
}
if pass := latestPassFor(t, s, "kagane"); pass.Skip != skipRefusing {
t.Fatalf("skip = %q, want %q", pass.Skip, skipRefusing)
}
if got := countPassRows(t, dbURL, "kagane"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
t.Run("sidecar-down", func(t *testing.T) {
s, dbURL := newTestStore(t)
seedForCheck(t, s, "kagane:x", "https://kagane.to/series/x", 0)
browser := &fakeFetcher{body: kaganeAPIFixture, status: 200}
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
p.BrowserFetch = browser
p.setBrowserDown(now) // a sibling Lane lost Chrome within the backoff window
if pace := p.runLanePass(context.Background(), "kagane", false); pace != refuseBackoff {
t.Fatalf("sidecar-down pace = %s, want %s", pace, refuseBackoff)
}
if browser.callCount() != 0 {
t.Fatalf("fetches with the sidecar down = %d, want 0", browser.callCount())
}
if pass := latestPassFor(t, s, "kagane"); pass.Skip != skipSidecarDown {
t.Fatalf("skip = %q, want %q", pass.Skip, skipSidecarDown)
}
if got := countPassRows(t, dbURL, "kagane"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
t.Run("no-fetcher", func(t *testing.T) {
s, dbURL := newTestStore(t)
seedForCheck(t, s, "comix:c", "https://comix.to/title/c", 0)
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
if pace := p.runLanePass(context.Background(), "comix", false); pace != defaultGap {
t.Fatalf("no-fetcher pace = %s, want %s", pace, defaultGap)
}
pass := latestPassFor(t, s, "comix")
if pass.Skip != skipNoFetcher || pass.GapMS != defaultGap.Milliseconds() {
t.Fatalf("no-fetcher pass = %+v, want skip %q with its own gap %s", pass, skipNoFetcher, defaultGap)
}
if got := countPassRows(t, dbURL, "comix"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
t.Run("due-query", func(t *testing.T) {
s, dbURL := newTestStore(t)
seedForCheck(t, s, "asura:x", "https://asurascans.com/series/x", 0)
// The due query is the pass's first store read after the gates; making
// it fail without touching poll_passes takes its tables away.
db, err := sql.Open("pgx", dbURL)
if err != nil {
t.Fatalf("open %s: %v", dbURL, err)
}
if _, err := db.Exec(`DROP TABLE bookmarks`); err != nil {
t.Fatalf("drop bookmarks: %v", err)
}
db.Close()
p := newTestPoller(t, s, &fakeFetcher{body: asuraSeriesFixture, status: 200}, now)
if pace := p.runLanePass(context.Background(), "asura", false); pace != defaultGap {
t.Fatalf("due-query pace = %s, want %s", pace, defaultGap)
}
if pass := latestPassFor(t, s, "asura"); pass.Skip != skipDueQuery {
t.Fatalf("skip = %q, want %q", pass.Skip, skipDueQuery)
}
if got := countPassRows(t, dbURL, "asura"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
t.Run("asleep", func(t *testing.T) {
s, dbURL := newTestStore(t)
for i := 0; i < 3; i++ {
key := fmt.Sprintf("kagane:w%d", i)
seedForCheck(t, s, key, "https://kagane.to/series/"+key[7:], now.Add(-62*time.Minute).UnixMilli())
}
browser := &fakeFetcher{body: kaganeAPIFixture, status: 200}
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
p.BrowserFetch = browser
if pace := p.runLanePass(context.Background(), "kagane", false); pace != defaultGap {
t.Fatalf("asleep pace = %s, want %s", pace, defaultGap)
}
if browser.callCount() != 0 {
t.Fatalf("fetches while Chrome is asleep = %d, want 0", browser.callCount())
}
pass := latestPassFor(t, s, "kagane")
if pass.Skip != skipAsleep || pass.Due != 3 || pass.GapMS != defaultGap.Milliseconds() {
t.Fatalf("asleep pass = %+v, want skip %q with 3 due and the default gap", pass, skipAsleep)
}
if got := countPassRows(t, dbURL, "kagane"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
t.Run("eligible-count", func(t *testing.T) {
s, dbURL := newTestStore(t)
// The eligible query shares the due query's tables, so no real store
// failure reaches it after a successful due read; the seam is how the
// path is driven at all (see Poller.eligibleCount).
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
p.eligibleCount = func(string) (int, error) { return 0, errors.New("count failed") }
if pace := p.runLanePass(context.Background(), "asura", false); pace != defaultGap {
t.Fatalf("eligible-count pace = %s, want %s", pace, defaultGap)
}
if pass := latestPassFor(t, s, "asura"); pass.Skip != skipEligibleCount {
t.Fatalf("skip = %q, want %q", pass.Skip, skipEligibleCount)
}
if got := countPassRows(t, dbURL, "asura"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
t.Run("nothing-eligible", func(t *testing.T) {
s, dbURL := newTestStore(t)
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
if pace := p.runLanePass(context.Background(), "asura", false); pace != sites["asura"].Rest {
t.Fatalf("nothing-eligible pace = %s, want a full rest %s", pace, sites["asura"].Rest)
}
if pass := latestPassFor(t, s, "asura"); pass.Skip != skipNothingEligible {
t.Fatalf("skip = %q, want %q", pass.Skip, skipNothingEligible)
}
if got := countPassRows(t, dbURL, "asura"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
t.Run("reached the loop", func(t *testing.T) {
s, dbURL := newTestStore(t)
const url = "https://asurascans.com/comics/chronicles-of-the-demon-faction-f886a8af"
seedForCheck(t, s, "asura:chronicles-of-the-demon-faction-f886a8af", url, 0)
p := newTestPoller(t, s, &fakeFetcher{body: asuraSeriesFixture, status: 200}, now)
if pace := p.runLanePass(context.Background(), "asura", false); pace != defaultGap {
t.Fatalf("loop pace = %s, want %s", pace, defaultGap)
}
pass := latestPassFor(t, s, "asura")
if pass.Skip != "" || pass.Due != 1 || pass.Checked != 1 {
t.Fatalf("loop pass = %+v, want an empty skip with 1 due and 1 checked", pass)
}
if got := countPassRows(t, dbURL, "asura"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
t.Run("browser-unreachable mid-loop", func(t *testing.T) {
s, dbURL := newTestStore(t)
seedForCheck(t, s, "comix:c", "https://comix.to/title/c", 0)
interrupted := fmt.Errorf("%w: %w", errBrowserInterrupted, errors.New("restart"))
browser := &fakeFetcher{status: 200, err: interrupted}
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
p.BrowserFetch = browser
if pace := p.runLanePass(context.Background(), "comix", false); pace != defaultGap {
t.Fatalf("mid-loop pace = %s, want %s", pace, defaultGap)
}
// One row was still written, and it is stall-shaped by construction:
// empty skip with due > 0 and checked 0 because the return precedes
// the checked counter. The assertion below pins that shape precisely.
pass := latestPassFor(t, s, "comix")
if pass.Skip != "" || pass.Unreachable != 1 || pass.Checked != 0 || pass.Due != 1 {
t.Fatalf("mid-loop pass = %+v, want empty skip, unreachable 1, checked 0, due 1", pass)
}
if got := countPassRows(t, dbURL, "comix"); got != 1 {
t.Fatalf("pass rows = %d, want exactly 1", got)
}
})
}
// Carry-forward moves verbatim from the in-memory snapshot (issue #141): a
// pass that never computed its own gap carries the previous pass's due, gap,
// clamped and checked forward; a pass with a gap of its own records its own
// figures, zeroes included, beside the skip reason that explains them.
func TestRunLanePassCarryForwardOnlyWhenGapZero(t *testing.T) {
now := time.UnixMilli(5_000_000)
t.Run("no gap of its own carries the previous pass's figures", func(t *testing.T) {
s, _ := newTestStore(t)
seedForCheck(t, s, "kagane:x", "https://kagane.to/series/x", 0)
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
p.BrowserFetch = &fakeFetcher{body: kaganeAPIFixture, status: 200}
p.runLanePass(context.Background(), "kagane", false)
first := latestPassFor(t, s, "kagane")
if first.Due != 1 || first.Checked != 1 || first.GapMS == 0 {
t.Fatalf("first pass = %+v, want a measured pass", first)
}
if err := s.SetLaneRefusal("kagane", now.Add(10*time.Minute).UnixMilli()); err != nil {
t.Fatalf("SetLaneRefusal: %v", err)
}
// The pass row is keyed (site, ran_at), so the second pass needs its
// own timestamp: a minute later is still inside the refusal.
p.Now = func() time.Time { return now.Add(time.Minute) }
p.runLanePass(context.Background(), "kagane", false)
second := latestPassFor(t, s, "kagane")
if second.Skip != skipRefusing {
t.Fatalf("second pass skip = %q, want %q", second.Skip, skipRefusing)
}
if second.Due != first.Due || second.Checked != first.Checked ||
second.GapMS != first.GapMS || second.Clamped != first.Clamped {
t.Fatalf("carried pass = %+v, want the first pass's figures %+v", second, first)
}
})
t.Run("a gap of its own records its own figures", func(t *testing.T) {
s, _ := newTestStore(t)
seedForCheck(t, s, "comix:c", "https://comix.to/title/c", 0)
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
p.BrowserFetch = &fakeFetcher{body: comixSeriesFixture, status: 200}
p.runLanePass(context.Background(), "comix", false)
first := latestPassFor(t, s, "comix")
if first.Due != 1 || first.GapMS == 0 {
t.Fatalf("first pass = %+v, want a measured pass", first)
}
// The no-fetcher exit sets its own gap, so no carry-forward: the due
// count it never gathered records as zero beside its skip reason. A
// minute later gives the second pass its own (site, ran_at) key.
p.BrowserFetch = nil
p.Now = func() time.Time { return now.Add(time.Minute) }
p.runLanePass(context.Background(), "comix", false)
second := latestPassFor(t, s, "comix")
if second.Skip != skipNoFetcher {
t.Fatalf("second pass skip = %q, want %q", second.Skip, skipNoFetcher)
}
if second.GapMS != defaultGap.Milliseconds() {
t.Fatalf("second pass gap = %d, want its own %d (not carried)", second.GapMS, defaultGap.Milliseconds())
}
if second.Due != 0 || second.Checked != 0 {
t.Fatalf("second pass = %+v, want due 0 checked 0 (its own, not the previous pass's)", second)
}
})
}
// The pass row's five outcome counts are the classification the Series read
// already makes — never a second taxonomy (issue #141). Success is derived,
// never stored: checked minus the four named counts, unreachable excluded
// because its exit returns before the checked counter increments.
func TestRunLanePassCountsOutcomes(t *testing.T) {
s, _ := newTestStore(t)
now := time.UnixMilli(5_000_000)
const (
successKey = "asura:chronicles-of-the-demon-faction-f886a8af"
successURL = "https://asurascans.com/comics/chronicles-of-the-demon-faction-f886a8af"
)
seeds := map[string]string{
"asura:refused": "https://asurascans.com/series/refused",
"asura:no-chapter": "https://asurascans.com/comics/no-chapter",
"asura:unfetchable": "https://evil.example/x",
"asura:transport": "https://asurascans.com/series/transport",
successKey: successURL,
}
for key, url := range seeds {
seedForCheck(t, s, key, url, 0)
}
f := &fakeFetcher{perURL: map[string]fakeResponse{
seeds["asura:refused"]: {status: 403},
seeds["asura:no-chapter"]: {body: "<html></html>", status: 200},
seeds["asura:transport"]: {err: errors.New("dial tcp: refused")},
successURL: {body: asuraSeriesFixture, status: 200},
}}
newTestPoller(t, s, f, now).runLanePass(context.Background(), "asura", false)
pass := latestPassFor(t, s, "asura")
if pass.Skip != "" || pass.Due != 5 || pass.Checked != 5 {
t.Fatalf("pass = %+v, want a full pass over 5 due Series", pass)
}
if pass.Refused != 1 || pass.Unreachable != 0 || pass.NoChapter != 1 ||
pass.Unfetchable != 1 || pass.Errors != 1 {
t.Fatalf("outcome counts = refused %d unreachable %d no_chapter %d unfetchable %d errors %d, want 1 0 1 1 1",
pass.Refused, pass.Unreachable, pass.NoChapter, pass.Unfetchable, pass.Errors)
}
if success := pass.Checked - (pass.Refused + pass.NoChapter + pass.Unfetchable + pass.Errors); success != 1 {
t.Fatalf("derived success = %d, want 1", success)
}
// The one genuine read went through: the success Series carries the
// fixture's newest chapter, and none of the four failures do.
b, ok, err := s.Get(s.OwnerID(), successKey)
if err != nil || !ok {
t.Fatalf("Get: %v ok=%v", err, ok)
}
if b.LatestChapterNum == nil || *b.LatestChapterNum != 181 {
t.Fatalf("success Series latest = %v, want 181 (the fixture's newest)", b.LatestChapterNum)
}
for _, key := range []string{"asura:refused", "asura:no-chapter", "asura:unfetchable", "asura:transport"} {
b, _, err := s.Get(s.OwnerID(), key)
if err != nil {
t.Fatalf("Get %s: %v", key, err)
}
if b.LatestChapterNum != nil {
t.Fatalf("%s latest = %v, want nil (no chapter survived a failed read)", key, *b.LatestChapterNum)
}
}
}
// A refusal is the Site's mood and outlives our process: the durable stamp a
// pass writes is honoured by a freshly constructed poller, which must not
// re-probe the Site inside its backoff (issue #141).
func TestDurableRefusalSurvivesFreshPoller(t *testing.T) {
s, _ := newTestStore(t)
now := time.UnixMilli(5_000_000)
// Four due Series: the Lane refuses twice, stamps those two, and leaves
// the remaining two untried and due — the queue the fresh poller must
// find intact once the durable backoff lifts.
for i := 0; i < 4; i++ {
key := fmt.Sprintf("kagane:s%d", i)
seedForCheck(t, s, key, "https://kagane.to/series/"+key[7:], 0)
}
p := newTestPoller(t, s, &fakeFetcher{status: 200}, now)
p.BrowserFetch = &fakeFetcher{status: 403}
p.runLanePass(context.Background(), "kagane", false)
if got := p.BrowserFetch.(*fakeFetcher).callCount(); got != 2 {
t.Fatalf("fetches on the refusing pass = %d, want 2 (refused twice)", got)
}
// A restart: a brand-new poller, no in-memory refusal, same store. The
// durable stamp gates the pass.
fresh := newTestPoller(t, s, &fakeFetcher{status: 200}, now.Add(14*time.Minute))
fresh.BrowserFetch = &fakeFetcher{status: 403}
fresh.runLanePass(context.Background(), "kagane", false)
if got := fresh.BrowserFetch.(*fakeFetcher).callCount(); got != 0 {
t.Fatalf("fetches by a fresh poller inside the backoff = %d, want 0", got)
}
if pass := latestPassFor(t, s, "kagane"); pass.Skip != skipRefusing {
t.Fatalf("fresh poller's pass skip = %q, want %q", pass.Skip, skipRefusing)
}
// Past the backoff the fresh poller probes again — the two Series the
// original pass never reached, still due with their stamps untouched.
fresh.Now = func() time.Time { return now.Add(16 * time.Minute) }
fresh.runLanePass(context.Background(), "kagane", false)
if got := fresh.BrowserFetch.(*fakeFetcher).callCount(); got != 2 {
t.Fatalf("fetches after the backoff = %d, want 2", got)
}
for i := 2; i < 4; i++ {
if got := readLatestCheckedAt(t, s, fmt.Sprintf("kagane:s%d", i)); got == 0 {
t.Fatalf("kagane:s%d still untried after the backoff", i)
}
}
}
// RecordLanePass prunes in the same call that inserts, so the retention
// cutoff the recorder passes is observable in what survives: a row just inside
// 14 days behind the poller's clock is kept, one just outside is pruned
// (issue #139, #141).
func TestPassRetentionCutoffIsFourteenDays(t *testing.T) {
s, dbURL := newTestStore(t)
// A real-world clock: the seeded rows sit 14 days back, so they must be
// positive timestamps or the seed's own prune (ran_at < 0) removes them.
now := time.UnixMilli(1_800_000_000_000)
kept := now.Add(-14*24*time.Hour + time.Minute).UnixMilli()
pruned := now.Add(-14*24*time.Hour - time.Minute).UnixMilli()
for _, ranAt := range []int64{kept, pruned} {
if err := s.RecordLanePass(store.LanePass{Site: "asura", RanAt: ranAt}, 0); err != nil {
t.Fatalf("seed pass at %d: %v", ranAt, err)
}
}
seedForCheck(t, s, "asura:x", "https://asurascans.com/series/x", 0)
newTestPoller(t, s, &fakeFetcher{body: asuraSeriesFixture, status: 200}, now).
runLanePass(context.Background(), "asura", false)
db, err := sql.Open("pgx", dbURL)
if err != nil {
t.Fatalf("open %s: %v", dbURL, err)
}
defer db.Close()
var n int
if err := db.QueryRow(`SELECT count(*) FROM poll_passes WHERE site = $1 AND ran_at = $2`, "asura", pruned).Scan(&n); err != nil {
t.Fatalf("count pruned row: %v", err)
}
if n != 0 {
t.Fatalf("row at %d survived, want it pruned (older than 14 days)", pruned)
}
if err := db.QueryRow(`SELECT count(*) FROM poll_passes WHERE site = $1`, "asura").Scan(&n); err != nil {
t.Fatalf("count passes: %v", err)
}
if n != 2 {
t.Fatalf("passes = %d, want 2 (this pass plus the kept row)", n)
}
}