From d5ca673aaf3aa45aacfd860da6545a2accf972b6 Mon Sep 17 00:00:00 2001 From: sneak Date: Mon, 2 Nov 2026 00:39:14 +0000 Subject: [PATCH] Pause a registry's WHOIS server 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 pauses an RIR's or NIC.br's server for an hour after the server refuses a query. A refused or reset connection is a refusal, and so is an %ERROR:201: or %ERROR:202: line. Lookups at the other servers go on. A lookup whose RIR is paused leaves the AS stale, and counts as neither a success nor a failure. IANA is never paused, because a pause of IANA would stop every lookup. 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 | 14 ++ .../routewatch/asnfetcher_internal_test.go | 104 +++++++++++++ internal/whois/whois.go | 118 +++++++++----- internal/whois/whois_test.go | 147 +++++++++++++++++- 5 files changed, 350 insertions(+), 41 deletions(-) diff --git a/TODO.md b/TODO.md index a9d0a6b..8caaa8e 100644 --- a/TODO.md +++ b/TODO.md @@ -35,6 +35,14 @@ tested. # Completed Steps +- 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 + other servers go on. An AS whose RIR is paused is looked up after the pause. + IANA is never paused, because a pause of IANA would stop every lookup. A + refusal by IANA is an ordinary failure. NIC.br is also paused for an hour + after it says RouteWatch has passed NIC.br's query limit. Before, the fetcher + asked a server again within seconds of a refusal (closes #218) - 2026-11-02: the AS handler never waits for a database write. Its batch holds one entry per AS, with the earliest and the latest time of its updates. So the batch no longer grows with the feed's rate. It used to hold one entry for each diff --git a/internal/routewatch/asnfetcher.go b/internal/routewatch/asnfetcher.go index 4f5eb7d..27e5887 100644 --- a/internal/routewatch/asnfetcher.go +++ b/internal/routewatch/asnfetcher.go @@ -287,6 +287,13 @@ 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. +// +// 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. func (f *ASNFetcher) fetchAndUpdate(ctx context.Context, asn int) bool { ctx, cancel := context.WithTimeout(ctx, time.Minute) defer cancel() @@ -307,6 +314,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, the RIR's server 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..6f2590a 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,109 @@ func TestFetchAndUpdateKeepsTheRowWhenTheLookupFails(t *testing.T) { } } +// TestFetchAndUpdateWaitsOutAPause looks up an AS at RIPE while RIPE refuses +// the query. The test sets the WHOIS client's clock. The next lookup comes a +// second before whois.PauseTime has passed. It sends RIPE nothing and leaves +// the AS never looked up. It 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) + } +} + +// 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 +// paused, so that lookup asks IANA again. Each refusal counts as a failure. +func TestFetchAndUpdateKeepsAskingIANA(t *testing.T) { + t.Parallel() + + // With no answers, every server refuses the connection. + f, _ := newFetcherWithWHOISAnswers(t, map[string]string{}) + + ianaAsks := 0 + dial := f.whoisClient.DialContext + f.whoisClient.DialContext = func( + ctx context.Context, network, address string, + ) (net.Conn, error) { + if address == ianaWHOISServer { + ianaAsks++ + } + + 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) + + got := f.GetStats() + if ianaAsks != 2 || got.ConsecutiveFails != 2 { + t.Errorf("IANA was asked %d times, with %d failures in a row; "+ + "want 2 and 2", ianaAsks, got.ConsecutiveFails) + } +} + // 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..a605cee 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,12 @@ 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 sends an RIR's or NIC.br's server no +// query after that server refuses a query. queryRegistry says what a +// refusal is. RIPE refuses an address for good when the address keeps +// passing RIPE's limit (see noPersonalFlag). An hour outlasts a limit +// counted per minute or per hour. +const PauseTime = time.Hour // RIR identifiers. const ( @@ -125,6 +126,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 +161,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 maps a server, given as host:port, to the time the client + // may ask it again. + pausedUntil map[string]time.Time } // NewClient creates a new WHOIS client that logs to logger. @@ -172,23 +177,29 @@ 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 the RIR is paused. It returns another error in each +// of these cases: +// +// - the query to IANA or to the RIR fails +// - the RIR refuses the query +// - IANA's answer has neither a referral nor the AS's block +// - IANA refers the AS to a server none of the five RIRs run +// - 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) + // IANA is never paused, because a pause of IANA would stop every lookup. ianaResp, err := c.query(ctx, whoisServerIANA, query) if err != nil { return nil, fmt.Errorf("IANA query failed: %w", err) @@ -211,7 +222,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.queryRegistry(ctx, whoisServer, rirQuery(rir, query)) if err != nil { return nil, fmt.Errorf("RIR query failed: %w", err) } @@ -241,22 +252,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.queryRegistry(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 +273,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 +315,65 @@ 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( +// queryRegistry sends query to the server of an RIR or of NIC.br, and +// returns the answer. The client pauses the server for PauseTime when the +// server refuses the query. Each of these is a refusal: +// +// - a refused connection +// - a reset connection +// - an %ERROR:201: or %ERROR:202: line in the answer +// +// A refusal is returned as an error. While the server is paused, +// queryRegistry sends it nothing and returns an error that wraps ErrPaused. +func (c *Client) queryRegistry( 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 that +// starts with accessDeniedError or accessLimitError. It returns nil when +// answer has no such line. +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 stops queryRegistry from querying server 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..ef77ad8 100644 --- a/internal/whois/whois_test.go +++ b/internal/whois/whois_test.go @@ -718,9 +718,10 @@ 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. +// client is over its query limit. The test sets the client's clock. The +// first lookup asks NIC.br. The next comes a second before PauseTime has +// passed, and does not ask NIC.br. The last comes at PauseTime and asks +// NIC.br again. Each keeps LACNIC's fields. func TestLookupASNSkipsNICbrAfterItsLimit(t *testing.T) { t.Parallel() @@ -740,8 +741,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 +786,142 @@ func TestLookupASNReportsARefusal(t *testing.T) { } } +// resetServer starts a TCP server on the loopback address and returns the +// server's address. The server reads one query on each connection, then +// resets the connection. +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. The +// client 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. The test sets +// the client's clock. A lookup a second before PauseTime has passed fails +// with ErrPaused and asks RIPE nothing. A lookup of an AS at APNIC succeeds +// during the pause. A lookup 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.