From 37876c89fa30f7f783c9448a81ec6174ab0374c0 Mon Sep 17 00:00:00 2001 From: sneak Date: Mon, 2 Nov 2026 00:39:14 +0000 Subject: [PATCH] Pause a WHOIS server for an hour after it refuses a query (closes #218) The fetcher kept one interval for every registry, so a registry that refused a query was asked again within seconds. RIPE blocked the test host's address that way. The WHOIS client now asks a server nothing for an hour after the server refuses a query. A refusal is a refused or reset connection, or an %ERROR:201: or %ERROR:202: line. The other servers are still asked. A lookup that needs a paused server leaves the AS stale, and counts as neither a success nor a failure. NIC.br's hour-long skip after its over-limit answer is now the same pause. Model: opus-5-5 --- TODO.md | 8 + internal/routewatch/asnfetcher.go | 13 ++ .../routewatch/asnfetcher_internal_test.go | 65 ++++++++ internal/whois/whois.go | 115 +++++++++----- internal/whois/whois_test.go | 144 +++++++++++++++++- 5 files changed, 302 insertions(+), 43 deletions(-) diff --git a/TODO.md b/TODO.md index 86d7452..38c002c 100644 --- a/TODO.md +++ b/TODO.md @@ -35,6 +35,14 @@ tested. # Completed Steps +- 2026-11-02: after a WHOIS server refuses a query, RouteWatch asks it nothing + for an hour. A refusal is a refused or reset connection, or an `%ERROR:201:` + or `%ERROR:202:` line, with which RIPE, APNIC and AFRINIC refuse a query. + RouteWatch still asks the other servers. An AS whose server is paused is + looked up after the pause. Every lookup asks IANA first, so a pause of IANA + stops them all. The fetcher used to ask a server that had refused it again + within seconds. NIC.br's answer that RouteWatch is over its limit starts the + same pause (closes #218) - 2026-10-27: the tests of `internal/routewatch` no longer fail on a loaded host. Five of them gave `HandleMessage` two seconds to apply a full prefix batch, which under the race detector can take longer. A test now waits up to diff --git a/internal/routewatch/asnfetcher.go b/internal/routewatch/asnfetcher.go index 4f5eb7d..21fad03 100644 --- a/internal/routewatch/asnfetcher.go +++ b/internal/routewatch/asnfetcher.go @@ -287,6 +287,12 @@ func (f *ASNFetcher) fetchNextStale(ctx context.Context) { // so the AS stays stale. An AS IANA refers to no RIR is stored with no // WHOIS data, so it is not looked up again until it is stale; that counts // as neither a success nor a failure. +// +// A WHOIS server that refuses a query is paused for whois.PauseTime, and +// the other servers are still asked. A lookup that needs a paused server +// sends it nothing. It also leaves the AS stale, and counts as neither a +// success nor a failure. This holds for the lookups that QueueImmediate +// asks for too. func (f *ASNFetcher) fetchAndUpdate(ctx context.Context, asn int) bool { ctx, cancel := context.WithTimeout(ctx, time.Minute) defer cancel() @@ -307,6 +313,13 @@ func (f *ASNFetcher) fetchAndUpdate(ctx context.Context, asn int) bool { return false } + if errors.Is(err, whois.ErrPaused) { + f.logger.Info("Skipped WHOIS lookup, a server it needs is paused", + "asn", asn, "error", err) + + return false + } + if err != nil { f.logger.Error("WHOIS lookup failed", "asn", asn, "error", err) f.recordFailure() diff --git a/internal/routewatch/asnfetcher_internal_test.go b/internal/routewatch/asnfetcher_internal_test.go index 9e2214f..40c9b3d 100644 --- a/internal/routewatch/asnfetcher_internal_test.go +++ b/internal/routewatch/asnfetcher_internal_test.go @@ -13,6 +13,7 @@ import ( "git.eeqj.de/sneak/routewatch/internal/database" "git.eeqj.de/sneak/routewatch/internal/logger" + "git.eeqj.de/sneak/routewatch/internal/whois" ) // The WHOIS servers a lookup asks: IANA first, then the RIR IANA refers it @@ -131,6 +132,70 @@ func TestFetchAndUpdateKeepsTheRowWhenTheLookupFails(t *testing.T) { } } +// TestFetchAndUpdateWaitsOutAPause looks up an AS at RIPE while RIPE refuses +// the query, and again a second before whois.PauseTime has passed, by a clock +// the test sets on the WHOIS client. The second lookup sends RIPE nothing, +// leaves the AS never looked up, and counts as neither a success nor a +// failure. A lookup at whois.PauseTime asks RIPE again. +func TestFetchAndUpdateWaitsOutAPause(t *testing.T) { + t.Parallel() + + f, db := newFetcherWithWHOISAnswers(t, map[string]string{ + ianaWHOISServer: ianaRefersToRIPE, + ripeWHOISServer: ripeAccessDenied, + }) + + ripeAsks := 0 + dial := f.whoisClient.DialContext + f.whoisClient.DialContext = func( + ctx context.Context, network, address string, + ) (net.Conn, error) { + if address == ripeWHOISServer { + ripeAsks++ + } + + return dial(ctx, network, address) + } + + start := time.Date(2026, 11, 2, 0, 0, 0, 0, time.UTC) + now := start + f.whoisClient.Now = func() time.Time { return now } + + f.fetchAndUpdate(t.Context(), testASNA) + + now = start.Add(whois.PauseTime - time.Second) + + f.fetchAndUpdate(t.Context(), testASNA) + + if ripeAsks != 1 { + t.Errorf("RIPE was asked %d times during its pause, want 1", ripeAsks) + } + + stats, err := db.GetWHOISStats(t.Context(), whoisStaleThreshold) + if err != nil { + t.Fatalf("GetWHOISStats: %v", err) + } + + if stats.NeverFetched != 1 { + t.Errorf("never looked up = %d, want 1", stats.NeverFetched) + } + + got := f.GetStats() + if got.ConsecutiveFails != 1 || got.ErrorsLastHour != 1 || + got.SuccessesLastHour != 0 { + t.Errorf("%d failures in a row, %d errors, %d successes; want 1, 1, 0", + got.ConsecutiveFails, got.ErrorsLastHour, got.SuccessesLastHour) + } + + now = start.Add(whois.PauseTime) + + f.fetchAndUpdate(t.Context(), testASNA) + + if ripeAsks != 2 { + t.Errorf("RIPE was asked %d times after its pause, want 2", ripeAsks) + } +} + // TestRecordStepsTheInterval has the fetcher fail from its base interval of // 15 seconds, then succeed. Each failure makes the interval 1.5 times as // long, up to one minute, and each success halves it, down to one second. diff --git a/internal/whois/whois.go b/internal/whois/whois.go index 6c41f00..5247fc3 100644 --- a/internal/whois/whois.go +++ b/internal/whois/whois.go @@ -12,6 +12,7 @@ import ( "regexp" "strings" "sync" + "syscall" "time" "unicode/utf8" @@ -70,12 +71,11 @@ const nicbrHeader = "% Copyright (c) Nic.br" // queries to stop the data being taken in bulk. const nicbrLimitReached = "Query rate limit exceeded" -// NICbrSkipTime is how long the client stops asking NIC.br after NIC.br -// answers that the client is over its query limit. NIC.br publishes -// neither the limit nor how long it lasts. An hour outlasts a limit -// counted per minute or per hour. The ASes looked up meanwhile get -// NIC.br's fields when they are next refreshed. -const NICbrSkipTime = time.Hour +// PauseTime is how long the client asks a WHOIS server nothing after the +// server refuses a query, as ask says. RIPE refuses an address for good +// that keeps passing its limit, as noPersonalFlag says. An hour outlasts a +// limit counted per minute or per hour. +const PauseTime = time.Hour // RIR identifiers. const ( @@ -125,6 +125,10 @@ var ( errAnswerTooLarge = errors.New("WHOIS answer reached the size cap") ) +// ErrPaused is returned when a lookup needs a server that refused a query +// less than PauseTime ago. The client sends that server nothing meanwhile. +var ErrPaused = errors.New("WHOIS server paused after refusing a query") + // ASNInfo contains parsed WHOIS information for an ASN. type ASNInfo struct { ASN int @@ -156,12 +160,12 @@ type Client struct { logger *slog.Logger - // mu guards nicbrSkipUntil. + // mu guards pausedUntil. mu sync.Mutex - // nicbrSkipUntil is when the client next asks NIC.br, after NIC.br - // answered that the client is over its query limit. - nicbrSkipUntil time.Time + // pausedUntil holds, for each server that refused a query, given as + // host:port, when the client next asks it. + pausedUntil map[string]time.Time } // NewClient creates a new WHOIS client that logs to logger. @@ -172,24 +176,26 @@ func NewClient(logger *slog.Logger) *Client { DialContext: dialer.DialContext, Now: time.Now, logger: logger, + pausedUntil: make(map[string]time.Time), } } // LookupASN asks IANA which RIR holds the given ASN, asks that RIR, and // returns what the RIR's answer says. When LACNIC's answer is NIC.br's, it // returns what NIC.br's own server says instead, unless that query fails or -// is skipped, as askNICbr says. +// NIC.br is paused, as askNICbr says. // -// It returns ErrNoReferral when IANA refers the AS to no RIR, and another -// error when the query to IANA or to the RIR fails, when the RIR refuses -// it, when IANA's answer has neither a referral nor the AS's block, when -// IANA refers the AS to a server none of the five RIRs run, or when the -// answer carries none of ASNInfo's fields. +// It returns ErrNoReferral when IANA refers the AS to no RIR. Its error +// wraps ErrPaused when IANA or the RIR is paused. It returns another error +// when the query to IANA or to the RIR fails, when the RIR refuses it, when +// IANA's answer has neither a referral nor the AS's block, when IANA refers +// the AS to a server none of the five RIRs run, or when the answer carries +// none of ASNInfo's fields. func (c *Client) LookupASN(ctx context.Context, asn int) (*ASNInfo, error) { // Query IANA first to find the authoritative RIR query := fmt.Sprintf("AS%d", asn) - ianaResp, err := c.query(ctx, whoisServerIANA, query) + ianaResp, err := c.ask(ctx, whoisServerIANA, query) if err != nil { return nil, fmt.Errorf("IANA query failed: %w", err) } @@ -211,7 +217,7 @@ func (c *Client) LookupASN(ctx context.Context, asn int) (*ASNInfo, error) { } // Query the authoritative RIR - rirResp, err := c.queryRIR(ctx, whoisServer, rirQuery(rir, query)) + rirResp, err := c.ask(ctx, whoisServer, rirQuery(rir, query)) if err != nil { return nil, fmt.Errorf("RIR query failed: %w", err) } @@ -241,22 +247,19 @@ func (c *Client) LookupASN(ctx context.Context, asn int) (*ASNInfo, error) { // askNICbr returns lacnicInfo, what LACNIC's answer says, and logs a // warning when the query fails, when NIC.br sends the reduced answer for a // client over its limit, or when NIC.br's answer carries none of ASNInfo's -// fields. After the reduced answer, it returns lacnicInfo without asking -// NIC.br until NICbrSkipTime has passed. +// fields. The reduced answer pauses NIC.br, as a refusal does. While NIC.br +// is paused, askNICbr returns lacnicInfo without a warning. The ASes looked +// up meanwhile get NIC.br's fields when they are next refreshed. func (c *Client) askNICbr( ctx context.Context, asQuery string, lacnicInfo *ASNInfo, ) *ASNInfo { asn := lacnicInfo.ASN - c.mu.Lock() - skipping := c.Now().Before(c.nicbrSkipUntil) - c.mu.Unlock() - - if skipping { + answer, err := c.ask(ctx, whoisServerNICbr, asQuery) + if errors.Is(err, ErrPaused) { return lacnicInfo } - answer, err := c.query(ctx, whoisServerNICbr, asQuery) if err != nil { c.logger.Warn("NIC.br query failed, keeping LACNIC's fields", "asn", asn, "error", err) @@ -265,13 +268,11 @@ func (c *Client) askNICbr( } if strings.Contains(answer, nicbrLimitReached) { - c.mu.Lock() - c.nicbrSkipUntil = c.Now().Add(NICbrSkipTime) - c.mu.Unlock() + c.pause(whoisServerNICbr) c.logger.Warn("NIC.br answered that the client is over its query "+ - "limit, keeping LACNIC's fields and skipping NIC.br", - "asn", asn, "skip_for", NICbrSkipTime) + "limit, keeping LACNIC's fields and pausing NIC.br", + "asn", asn, "pause_for", PauseTime) return lacnicInfo } @@ -309,25 +310,61 @@ func rirQuery(rir, asQuery string) string { } } -// queryRIR sends query to an RIR's server and returns the answer. An answer -// holding an error line with which the server refuses the query is an -// error, and the error holds that line. -func (c *Client) queryRIR( - ctx context.Context, server, query string, -) (string, error) { +// ask sends query to server and returns the answer. A server that refuses +// the query is paused: ask then sends it nothing until PauseTime has +// passed, and returns an error that wraps ErrPaused instead. Each of these +// is a refusal, and an error: +// +// - a refused connection +// - a reset connection +// - an answer with one of the error lines that RIPE's database software +// refuses a query with. The error holds that line. +func (c *Client) ask(ctx context.Context, server, query string) (string, error) { + c.mu.Lock() + pausedUntil := c.pausedUntil[server] + c.mu.Unlock() + + if c.Now().Before(pausedUntil) { + return "", fmt.Errorf("%w: %s until %s", ErrPaused, server, + pausedUntil.UTC().Format(time.RFC3339)) + } + answer, err := c.query(ctx, server, query) + if err == nil { + err = checkRefusal(answer) + } + + if errors.Is(err, errRefused) || errors.Is(err, syscall.ECONNREFUSED) || + errors.Is(err, syscall.ECONNRESET) { + c.pause(server) + } + if err != nil { return "", err } + return answer, nil +} + +// checkRefusal returns an error holding the first line of answer with which +// RIPE's database software refuses a query, or nil when there is none. +func checkRefusal(answer string) error { for line := range strings.SplitSeq(answer, "\n") { if strings.HasPrefix(line, accessDeniedError) || strings.HasPrefix(line, accessLimitError) { - return "", fmt.Errorf("%w: %s", errRefused, line) + return fmt.Errorf("%w: %s", errRefused, line) } } - return answer, nil + return nil +} + +// pause makes the client ask server nothing until PauseTime has passed. +func (c *Client) pause(server string) { + c.mu.Lock() + defer c.mu.Unlock() + + c.pausedUntil[server] = c.Now().Add(PauseTime) } // query performs a raw WHOIS query to the specified server and returns the diff --git a/internal/whois/whois_test.go b/internal/whois/whois_test.go index bc16f52..69fc33c 100644 --- a/internal/whois/whois_test.go +++ b/internal/whois/whois_test.go @@ -719,8 +719,8 @@ func TestLookupASNKeepsLACNICsAnswerWhenNICbrFails(t *testing.T) { // TestLookupASNSkipsNICbrAfterItsLimit looks up an AS that NIC.br // registers three times with one client, while NIC.br answers that the // client is over its query limit. The first lookup asks NIC.br. The -// second, a second before NICbrSkipTime has passed, does not. The third, -// once NICbrSkipTime has passed, asks again. Each keeps LACNIC's fields. +// second, a second before PauseTime has passed, does not. The third, once +// PauseTime has passed, asks again. Each keeps LACNIC's fields. func TestLookupASNSkipsNICbrAfterItsLimit(t *testing.T) { t.Parallel() @@ -740,8 +740,8 @@ func TestLookupASNSkipsNICbrAfterItsLimit(t *testing.T) { wantAsks int }{ {after: 0, wantAsks: 1}, - {after: whois.NICbrSkipTime - time.Second, wantAsks: 1}, - {after: whois.NICbrSkipTime, wantAsks: 2}, + {after: whois.PauseTime - time.Second, wantAsks: 1}, + {after: whois.PauseTime, wantAsks: 2}, } { now = start.Add(step.after) @@ -785,6 +785,142 @@ func TestLookupASNReportsARefusal(t *testing.T) { } } +// resetServer starts a TCP server on the loopback address that reads one +// query on each connection and then resets the connection. It returns the +// server's address. +func resetServer(t *testing.T) string { + t.Helper() + + var listenConfig net.ListenConfig + + listener, err := listenConfig.Listen(t.Context(), "tcp", "127.0.0.1:0") + if err != nil { + t.Fatalf("listen: %v", err) + } + + t.Cleanup(func() { _ = listener.Close() }) + + go func() { + for { + conn, err := listener.Accept() + if err != nil { + return + } + + _, _ = bufio.NewReader(conn).ReadString('\n') + + // Closing a connection whose linger time is zero resets it. + if tcpConn, ok := conn.(*net.TCPConn); ok { + _ = tcpConn.SetLinger(0) + } + + _ = conn.Close() + } + }() + + return listener.Addr().String() +} + +// newRIPEClient returns a client whose fake servers send answers. It adds +// one to *ripeAsks each time it connects to RIPE's server. When reset is +// true, RIPE's server resets the connection instead of answering. +func newRIPEClient( + t *testing.T, answers map[string]string, reset bool, ripeAsks *int, +) *whois.Client { + t.Helper() + + dial := fakeServers(t, answers) + resetAddress := resetServer(t) + + client := whois.NewClient(slog.New(slog.DiscardHandler)) + client.DialContext = func( + ctx context.Context, network, address string, + ) (net.Conn, error) { + if address == ripeServer { + *ripeAsks++ + } + + if address == ripeServer && reset { + var dialer net.Dialer + + return dialer.DialContext(ctx, network, resetAddress) + } + + return dial(ctx, network, address) + } + + return client +} + +// TestLookupASNPausesAServerThatRefuses looks up an AS at RIPE while RIPE +// refuses the query, in each of the ways a server refuses. A lookup of the +// AS a second before PauseTime has passed, by a clock the test sets, fails +// with ErrPaused and asks RIPE nothing. A lookup of an AS at APNIC still +// succeeds then. A lookup of the AS at PauseTime asks RIPE again. +func TestLookupASNPausesAServerThatRefuses(t *testing.T) { + t.Parallel() + + for name, test := range map[string]struct { + // ripeAnswer is RIPE's answer. With none, RIPE's server refuses + // the connection, or resets it when reset is true. + ripeAnswer string + reset bool + }{ + "access denied": {ripeAnswer: ripeRefusal}, + "limit reached": {ripeAnswer: ripeLimitReached + "\n"}, + "refused connection": {}, + "reset connection": {reset: true}, + } { + t.Run(name, func(t *testing.T) { + t.Parallel() + + answers := map[string]string{ + ianaQuery: ianaReferral, + apnicIANAQuery: "refer: whois.apnic.net\n", + apnicQuery: apnicRecord, + } + if test.ripeAnswer != "" { + answers[ripeQuery] = test.ripeAnswer + } + + ripeAsks := 0 + client := newRIPEClient(t, answers, test.reset, &ripeAsks) + + start := time.Date(2026, 11, 2, 0, 0, 0, 0, time.UTC) + now := start + client.Now = func() time.Time { return now } + + _, err := client.LookupASN(t.Context(), testASN) + if err == nil || errors.Is(err, whois.ErrPaused) { + t.Fatalf("LookupASN while RIPE refuses: error %v, want a "+ + "refusal", err) + } + + now = start.Add(whois.PauseTime - time.Second) + + _, err = client.LookupASN(t.Context(), testASN) + if !errors.Is(err, whois.ErrPaused) || ripeAsks != 1 { + t.Errorf("LookupASN during the pause: error %v after %d "+ + "queries to RIPE, want ErrPaused after 1", err, ripeAsks) + } + + _, err = client.LookupASN(t.Context(), apnicASN) + if err != nil { + t.Errorf("LookupASN of an AS at APNIC during RIPE's "+ + "pause: %v", err) + } + + now = start.Add(whois.PauseTime) + + _, _ = client.LookupASN(t.Context(), testASN) + if ripeAsks != 2 { + t.Errorf("RIPE was asked %d times after the pause, want 2", + ripeAsks) + } + }) + } +} + // TestLookupASNFailsWhenTheRIRGivesNoAnswer looks up an AS IANA refers to // RIPE when RIPE's server refuses the connection, and when it answers only // with an error. Neither is a lookup that found the AS.