diff --git a/TODO.md b/TODO.md index 8caaa8e..ee76305 100644 --- a/TODO.md +++ b/TODO.md @@ -35,6 +35,11 @@ tested. # Completed Steps +- 2026-11-02: a WHOIS lookup skipped because its RIR is paused makes the fetcher + wait longer before the next lookup, as a failed lookup does, up to one minute. + The status page does not count a skip as a failure. A skip used to leave the + wait as it was. Each lookup asks IANA first, so while most stale ASes were at + a paused RIR, the fetcher could ask IANA every second (closes #222) - 2026-11-02: RouteWatch pauses an RIR's or NIC.br's WHOIS server for an hour after the server refuses a query. A refused or reset connection is a refusal. So is an answer with an `%ERROR:201:` or `%ERROR:202:` line. Lookups at the diff --git a/internal/routewatch/asnfetcher.go b/internal/routewatch/asnfetcher.go index 27e5887..744506c 100644 --- a/internal/routewatch/asnfetcher.go +++ b/internal/routewatch/asnfetcher.go @@ -187,25 +187,33 @@ func (f *ASNFetcher) recordSuccess() { f.statsMu.Unlock() } -// recordFailure increases the interval on failed fetch using exponential backoff. -func (f *ASNFetcher) recordFailure() { +// lengthenInterval makes the interval 1.5 times as long, up to maxInterval. +// A failed lookup and a skipped one both lengthen it. +func (f *ASNFetcher) lengthenInterval() { f.intervalMu.Lock() - f.consecutiveFails++ + defer f.intervalMu.Unlock() - // Exponential backoff: multiply by 1.5, capped at max newInterval := min( f.currentInterval*backoffNumerator/backoffDenominator, maxInterval) if newInterval != f.currentInterval { - f.logger.Debug("Increased fetch interval due to failure", + f.logger.Debug("Increased fetch interval", "old_interval", f.currentInterval, "new_interval", newInterval, "consecutive_failures", f.consecutiveFails, ) f.currentInterval = newInterval } +} + +// recordFailure counts a failed fetch and lengthens the interval. +func (f *ASNFetcher) recordFailure() { + f.intervalMu.Lock() + f.consecutiveFails++ f.intervalMu.Unlock() + f.lengthenInterval() + // Record error time for stats, dropping those older than statsWindow f.statsMu.Lock() now := f.now() @@ -291,9 +299,11 @@ func (f *ASNFetcher) fetchNextStale(ctx context.Context) { // The WHOIS client pauses an RIR's or NIC.br's server for whois.PauseTime // after the server refuses a query. Lookups at the other servers go on. IANA // is never paused, so a refusal by IANA is an ordinary failure. A lookup -// whose RIR is paused fails with whois.ErrPaused. Such a lookup leaves the -// AS stale, and counts as neither a success nor a failure. The lookups that -// QueueImmediate asks for also run through fetchAndUpdate. +// whose RIR is paused fails with whois.ErrPaused, and is skipped. A skipped +// lookup leaves the AS stale and is not counted as a failure. It lengthens +// the interval as a failure does: each lookup asks IANA before it finds the +// RIR paused, and a short interval would ask IANA every second. The lookups +// that QueueImmediate asks for also run through fetchAndUpdate. func (f *ASNFetcher) fetchAndUpdate(ctx context.Context, asn int) bool { ctx, cancel := context.WithTimeout(ctx, time.Minute) defer cancel() @@ -317,6 +327,7 @@ func (f *ASNFetcher) fetchAndUpdate(ctx context.Context, asn int) bool { if errors.Is(err, whois.ErrPaused) { f.logger.Info("Skipped WHOIS lookup, the RIR's server is paused", "asn", asn, "error", err) + f.lengthenInterval() return false } diff --git a/internal/routewatch/asnfetcher_internal_test.go b/internal/routewatch/asnfetcher_internal_test.go index 6f2590a..2c5443c 100644 --- a/internal/routewatch/asnfetcher_internal_test.go +++ b/internal/routewatch/asnfetcher_internal_test.go @@ -196,6 +196,47 @@ func TestFetchAndUpdateWaitsOutAPause(t *testing.T) { } } +// TestFetchAndUpdateBacksOffDuringAPause looks up an AS at RIPE while RIPE +// refuses the query. The test sets the WHOIS client's clock. It looks the AS +// up again each time the interval has passed, so each later lookup is +// skipped. Each skip must make the interval 1.5 times as long, up to one +// minute, as a failure does. The skips must not count as failures. +func TestFetchAndUpdateBacksOffDuringAPause(t *testing.T) { + t.Parallel() + + f, _ := newFetcherWithWHOISAnswers(t, map[string]string{ + ianaWHOISServer: ianaRefersToRIPE, + ripeWHOISServer: ripeAccessDenied, + }) + + now := time.Date(2026, 11, 2, 0, 0, 0, 0, time.UTC) + f.whoisClient.Now = func() time.Time { return now } + + f.fetchAndUpdate(t.Context(), testASNA) + + for i, want := range []time.Duration{ + 33750 * time.Millisecond, + 50625 * time.Millisecond, + time.Minute, + time.Minute, + } { + now = now.Add(f.getInterval()) + + f.fetchAndUpdate(t.Context(), testASNA) + + if got := f.getInterval(); got != want { + t.Errorf("interval after %d skipped lookups = %v, want %v", + i+1, got, want) + } + } + + got := f.GetStats() + if got.ConsecutiveFails != 1 || got.ErrorsLastHour != 1 { + t.Errorf("%d failures in a row and %d errors, want 1 and 1", + got.ConsecutiveFails, got.ErrorsLastHour) + } +} + // TestFetchAndUpdateKeepsAskingIANA looks up an AS while IANA's server // refuses the connection. The test sets the WHOIS client's clock. The next // lookup comes a second before whois.PauseTime has passed. IANA is never