From 0b312218f90fdc208bfc98248c5ec855f58a9921 Mon Sep 17 00:00:00 2001 From: jochen Date: Fri, 23 Oct 2026 13:03:17 +0200 Subject: [PATCH] Wait out a failed lookup of the registry's name in a build, and say it was the resolver (issue 1748) --- internal/builder/registry_wait.go | 30 +++++++++--- internal/builder/registry_wait_test.go | 65 ++++++++++++++++++++++++++ 2 files changed, 88 insertions(+), 7 deletions(-) diff --git a/internal/builder/registry_wait.go b/internal/builder/registry_wait.go index f2b10bae..33d3762d 100644 --- a/internal/builder/registry_wait.go +++ b/internal/builder/registry_wait.go @@ -45,21 +45,37 @@ func refused(err error) bool { return err != nil && (errors.Is(err, syscall.ECONNREFUSED) || strings.Contains(err.Error(), "connection refused")) } -// waitForRegistry runs try, and while it fails because the registry at address refuses connections, -// tries again with a growing pause until registryWait has passed. what names the call, for the log. +// waitedFor is whether an error is one a build waits out: a refused connection, or a lookup of the registry's name +// that the resolver did not answer (novox/hq issue 1748; failedLookup, from issue 1773, says which). +func waitedFor(err error) bool { return refused(err) || failedLookup(err) } + +// waitForRegistry runs try, and while it fails because the registry at address refuses connections, or the +// resolver does not answer a lookup of its name, tries again with a growing pause until registryWait has passed. what names the call, for the log. func waitForRegistry(ctx context.Context, address, what string, try func() error) error { err := try() - if !refused(err) { + if !waitedFor(err) { return err } started := time.Now() pause := registryFirstPause - tell("registry", "%s: refused; the build waits for the registry at %s, for up to %s — it is held still while "+ - "the store's nightly collection runs, about a minute and a half (novox/hq issue 457)", - what, address, registryWait) + if failedLookup(err) { + tell("registry", "%s: the resolver did not answer a lookup of the registry's name (%v); the build waits, "+ + "for up to %s (novox/hq issue 1748)", what, err, registryWait) + } else { + tell("registry", "%s: refused; the build waits for the registry at %s, for up to %s — it is held still while "+ + "the store's nightly collection runs, about a minute and a half (novox/hq issue 457)", + what, address, registryWait) + } for { left := registryWait - time.Since(started) if left <= 0 { + if failedLookup(err) { + tell("registry", "%s: the resolver still did not answer a lookup of the registry at %s after %s; the build fails", + what, address, time.Since(started).Round(time.Second)) + return fmt.Errorf("the resolver did not answer a lookup of the registry at %s for %s, so it is the "+ + "resolver, not the registry, that is down: %w", + address, time.Since(started).Round(time.Millisecond), err) + } tell("registry", "%s: the registry at %s still refuses after %s; the build fails", what, address, time.Since(started).Round(time.Second)) return fmt.Errorf("the registry at %s refused every connection for %s, longer than its nightly "+ @@ -73,7 +89,7 @@ func waitForRegistry(ctx context.Context, address, what string, try func() error case <-time.After(wait): } pause = min(pause*2, registryMostPause) - if err = try(); !refused(err) { + if err = try(); !waitedFor(err) { // Said as it is: the registry answering is only the build going on when the call worked. if err == nil { tell("registry", "%s: the registry at %s answers again after %s; the build goes on", what, address, diff --git a/internal/builder/registry_wait_test.go b/internal/builder/registry_wait_test.go index c529f716..e65c0450 100644 --- a/internal/builder/registry_wait_test.go +++ b/internal/builder/registry_wait_test.go @@ -4,6 +4,7 @@ import ( "context" "crypto/sha256" "encoding/hex" + "errors" "net" "net/http" "strings" @@ -152,3 +153,67 @@ func TestAnImagePushWaitsForARegistryHeldStill(t *testing.T) { type errorString string func (e errorString) Error() string { return string(e) } + +// A resolver that does not answer for a moment (novox/hq issue 1748): a lookup of the registry's name that +// timed out failed the build at once, though the same name resolved a second later. + +const lookupTimeout = "Head \"http://novox.internal:5100/v2/x/blobs/sha256:1\": dial tcp: lookup novox.internal on 10.10.0.3:53: " + + "read udp 10.10.0.3:44790->10.10.0.3:53: i/o timeout" + +type lookupTimedOut struct{} + +func (lookupTimedOut) Error() string { return lookupTimeout } + +func TestABuildWaitsOutAResolverThatDoesNotAnswerAndGoesOn(t *testing.T) { // 1748/AC1 + waitingFor(t, 5*time.Second) + said := saying(t) + calls := 0 + err := waitForRegistry(context.Background(), "novox.internal:5100", "HEAD /v2/x", func() error { + calls++ + if calls < 3 { + return lookupTimedOut{} + } + return nil + }) + if err != nil { + t.Fatalf("a lookup timing out twice failed the build: %v", err) + } + if calls != 3 { + t.Errorf("tried %d times, want 3", calls) + } + log := strings.Join(said(), "\n") + if !strings.Contains(log, "resolver did not answer") || !strings.Contains(log, "answers again") { + t.Errorf("the build's log does not say the resolver was waited for, and that it came back:\n%s", log) + } +} + +func TestABuildFailsNamingTheResolverWhenItDoesNotAnswerPastTheBound(t *testing.T) { // 1748/AC2 + waitingFor(t, 100*time.Millisecond) + saying(t) + started := time.Now() + err := waitForRegistry(context.Background(), "novox.internal:5100", "HEAD /v2/x", func() error { return lookupTimedOut{} }) + if err == nil { + t.Fatal("a resolver that never answered let the build go on") + } + if !strings.Contains(err.Error(), "resolver did not answer") || !strings.Contains(err.Error(), "i/o timeout") { + t.Errorf("the failure does not name the resolver: %v", err) + } + if strings.Contains(err.Error(), "refused every connection") { + t.Errorf("the failure blames a refusal: %v", err) + } + if waited := time.Since(started); waited < 100*time.Millisecond { + t.Errorf("failed after %s, before the bound", waited) + } +} + +func TestAnErrorThatIsNeitherARefusalNorALookupFailsAtOnce(t *testing.T) { // 1748/AC3 + waitingFor(t, 5*time.Second) + calls := 0 + err := waitForRegistry(context.Background(), "novox.internal:5100", "HEAD /v2/x", func() error { + calls++ + return errors.New("401 unauthorized") + }) + if err == nil || calls != 1 { + t.Fatalf("err %v after %d calls, want a failure at once", err, calls) + } +} -- 2.54.0