From acaf8830ec94cf2cbff6d4d111b9fcb35f016f23 Mon Sep 17 00:00:00 2001 From: jochen Date: Thu, 22 Oct 2026 20:56:46 +0200 Subject: [PATCH] Try a forge clone again when its name lookup fails (issue 1773) A build or check failed now and then on 'Could not resolve host: novox.internal' between clones that resolved the same name, and its whole delivery failed with it. A clone whose lookup failed reached nothing, so it is cloned again with a growing pause for up to 60 s, each retry said in the build's log as the resolver not answering; past the bound it fails saying so. Any other git failure fails at once, as before. Covers a module's own clone, an artifact's context and a check's repositories. --- internal/builder/builder.go | 5 +- internal/builder/check.go | 3 +- internal/builder/clone_lookup.go | 114 ++++++++++++++++++ internal/builder/clone_lookup_test.go | 162 ++++++++++++++++++++++++++ 4 files changed, 281 insertions(+), 3 deletions(-) create mode 100644 internal/builder/clone_lookup.go create mode 100644 internal/builder/clone_lookup_test.go diff --git a/internal/builder/builder.go b/internal/builder/builder.go index eb5b09e3..bbaf4fc3 100644 --- a/internal/builder/builder.go +++ b/internal/builder/builder.go @@ -241,7 +241,8 @@ func build(ctx context.Context, run Runner, publish Publisher, // A fresh clone every time rather than a fetch into a tree that is already there. A build // that reuses a working tree can succeed because of something a previous build left behind, // and that is a build nobody can reproduce. - if _, err := run(ctx, workspace, "git", cloneWith(credentials, "clone", "--quiet", repository, tree)...); err != nil { + if err := cloneFromForge(ctx, run, workspace, repository, tree, + cloneWith(credentials, "clone", "--quiet", repository, tree), say); err != nil { say("clone", "FAILED: %v", err) return Result{}, fmt.Errorf("cannot clone %s: %w", repository, err) } @@ -793,7 +794,7 @@ func contextFrom(ctx context.Context, run Runner, workspace, artifact, credentia os.RemoveAll(dir) } }() - if _, err := run(ctx, workspace, "git", cloneWith(credentials, "clone", "--quiet", url, dir)...); err != nil { + if err := cloneFromForge(ctx, run, workspace, url, dir, cloneWith(credentials, "clone", "--quiet", url, dir), say); err != nil { return "", fmt.Errorf("cannot clone %s: %w", url, err) } if err := recordedWithoutUserinfo(ctx, run, dir, url); err != nil { diff --git a/internal/builder/check.go b/internal/builder/check.go index 57d86925..b9add5d2 100644 --- a/internal/builder/check.go +++ b/internal/builder/check.go @@ -428,7 +428,8 @@ func Check(ctx context.Context, run Runner, spec CheckSpec, workspace, registry // clone clones a repository and checks out ref; readAt keeps which, by directory. readAt := map[string]string{} clone := func(repository, ref, dir string) error { - if _, err := run(ctx, root, "git", cloneWith(credentials, "clone", "--quiet", repository, dir)...); err != nil { + if err := cloneFromForge(ctx, run, root, redact.redact(repository), filepath.Join(root, dir), + cloneWith(credentials, "clone", "--quiet", repository, dir), say); err != nil { return fmt.Errorf("cannot clone %s: %s", redact.redact(repository), redact.redact(err.Error())) } if err := recordedWithoutUserinfo(ctx, run, filepath.Join(root, dir), repository); err != nil { diff --git a/internal/builder/clone_lookup.go b/internal/builder/clone_lookup.go new file mode 100644 index 00000000..82189c55 --- /dev/null +++ b/internal/builder/clone_lookup.go @@ -0,0 +1,114 @@ +package builder + +import ( + "context" + "fmt" + "os" + "strings" + "time" +) + +// A clone from the forge waits out a resolver that did not answer, for a bounded time (novox/hq issue 1773). +// +// **Why.** A build or a check failed now and then on "Could not resolve host: novox.internal" while cloning, between +// clones that resolved the same name a second before and after, and the whole delivery failed with it. The lookup +// failing is the resolver's passing fault, not the repository's: nothing reached the forge, so cloning again cannot +// do anything twice. This is issue 457's shape (a build waits out a registry held still) applied to the name lookup. +// +// **Only the lookup.** Any other failure of git — authentication, a repository or a ref that is not there, a 404 — +// fails at once, as it always did: trying it again would only make a real failure slower. +// +// **Bounded, and loud.** Each retry is said in the build's log as the resolver's failure, and past lookupWait the +// build fails saying the resolver did not answer for that long. + +var ( + // lookupWait is how long a clone waits for a resolver that does not answer. + lookupWait = 60 * time.Second + // lookupFirstPause is the first pause between tries; each pause doubles, up to lookupMostPause. + lookupFirstPause = time.Second +) + +// lookupMostPause is the longest pause between two tries. +const lookupMostPause = 10 * time.Second + +// lookupFailures are what git (through curl) and Go's resolver say when a name did not resolve, in lower case. +var lookupFailures = []string{ + "could not resolve host", + "temporary failure in name resolution", +} + +// failedLookup is whether an error is a name lookup that failed: git's "Could not resolve host", the system's +// "Temporary failure in name resolution", or a lookup that timed out. +func failedLookup(err error) bool { + if err == nil { + return false + } + said := strings.ToLower(err.Error()) + for _, f := range lookupFailures { + if strings.Contains(said, f) { + return true + } + } + return strings.Contains(said, "lookup ") && strings.Contains(said, "i/o timeout") +} + +// cloneFromForge runs `git clone` of url into dest (git's arguments in args, run from dir), and while it fails on the +// name lookup, clones again with a growing pause until lookupWait has passed. What a failed try left at dest is +// removed before the next. Any other failure is returned at once. +func cloneFromForge(ctx context.Context, run Runner, dir, url, dest string, args []string, + say func(step, format string, args ...any)) error { + _, err := run(ctx, dir, "git", args...) + if !failedLookup(err) { + return err + } + started := time.Now() + pause := lookupFirstPause + for { + elapsed := time.Since(started) + left := lookupWait - elapsed + if left <= 0 { + say("clone", "the resolver did not answer for %s, cloning %s, for %s; the clone fails", + urlHost(url), url, elapsed.Round(time.Second)) + return fmt.Errorf("the resolver did not answer a lookup of %s for %s, cloning %s: %w", + urlHost(url), elapsed.Round(time.Millisecond), url, err) + } + wait := min(pause, left) + say("clone", "the resolver did not answer for %s, cloning %s; trying again in %s, for up to %s "+ + "(novox/hq issue 1773)", urlHost(url), url, wait, lookupWait) + select { + case <-ctx.Done(): + return fmt.Errorf("stopped while waiting for the resolver to answer for %s: %w (last: %v)", + urlHost(url), ctx.Err(), err) + case <-time.After(wait): + } + pause = min(pause*2, lookupMostPause) + if err := os.RemoveAll(dest); err != nil { + return err + } + if _, err = run(ctx, dir, "git", args...); !failedLookup(err) { + if err == nil { + say("clone", "the resolver answered for %s after %s; the clone worked", urlHost(url), + time.Since(started).Round(time.Millisecond)) + } + return err + } + } +} + +// urlHost is the host (and port) a URL names, or the URL itself when it names none. +func urlHost(url string) string { + rest := url + if _, after, ok := strings.Cut(url, "://"); ok { + rest = after + } + if i := strings.IndexAny(rest, "/?#"); i >= 0 { + rest = rest[:i] + } + if i := strings.LastIndex(rest, "@"); i >= 0 { + rest = rest[i+1:] + } + if rest == "" { + return url + } + return rest +} diff --git a/internal/builder/clone_lookup_test.go b/internal/builder/clone_lookup_test.go new file mode 100644 index 00000000..a7d8332d --- /dev/null +++ b/internal/builder/clone_lookup_test.go @@ -0,0 +1,162 @@ +package builder + +import ( + "context" + "fmt" + "strings" + "sync" + "testing" + "time" +) + +// Issue 1773: a build or a check failed now and then on "Could not resolve host: novox.internal" while cloning from +// the forge, between clones that resolved the same name, and its whole delivery failed with it. A clone that fails on +// the name lookup is tried again within a bound, says each retry in the build's log as the resolver's failure, and +// only past the bound fails, saying the resolver did not answer. Any other failure of git fails at once, as before. + +const lookupFailure = "exit status 128\nfatal: unable to access 'http://novox.internal:20000/novox/x.git/': " + + "Could not resolve host: novox.internal" + +// failingClones is a runner whose first n forge clones fail with failure, then clone as r does; n < 0 fails every one. +type failingClones struct { + r *recorded + n int + failure string + clones int +} + +func (f *failingClones) run(ctx context.Context, dir, name string, args ...string) (string, error) { + if name == "git" && isACloneOf(args) { + f.clones++ + if f.n < 0 || f.clones <= f.n { + return "", fmt.Errorf("git %s: %s", strings.Join(args, " "), f.failure) + } + } + return f.r.run(ctx, dir, name, args...) +} + +func isACloneOf(args []string) bool { + for _, a := range args { + if a == "clone" { + return true + } + } + return false +} + +// buildLog collects what a build says in its own log. +func buildLog() (Log, func() []string) { + var mu sync.Mutex + var lines []string + return func(step, message string) { + mu.Lock() + defer mu.Unlock() + lines = append(lines, step+": "+message) + }, func() []string { + mu.Lock() + defer mu.Unlock() + return append([]string(nil), lines...) + } +} + +const nothingToBuild = `{"module":"x","version":"1"}` + +// 1773/AC1: a clone failing twice on the lookup, then working, is tried again, each retry said, and the build goes on. +func TestACloneThatFailsOnTheLookupIsTriedAgainAndTheBuildGoesOn(t *testing.T) { + quickLookups(t) + r, workspace := aRepository(t, nothingToBuild, nil) + f := &failingClones{r: r, n: 2, failure: lookupFailure} + log, said := buildLog() + _, err := Build(context.Background(), f.run, r, "http://novox.internal:20000/novox/x.git", "", "", workspace, nil, + Npmrc{}, GitCredential{}, log) + if err != nil { + t.Fatalf("a clone the resolver failed twice, then answered, ended the build: %v", err) + } + if f.clones != 3 { + t.Errorf("the clone ran %d times, want 3 (two lookups failed, the third worked)", f.clones) + } + retries := 0 + for _, line := range said() { + if strings.Contains(line, "the resolver did not answer") && strings.Contains(line, "novox.internal") { + retries++ + } + } + if retries != 2 { + t.Errorf("the build's log said %d retries as the resolver's failure, want 2:\n%s", retries, + strings.Join(said(), "\n")) + } +} + +// 1773/AC2: a lookup that keeps failing past the bound fails the build, saying the resolver did not answer. +func TestACloneWhoseLookupNeverAnswersFailsSayingTheResolverDidNotAnswer(t *testing.T) { + quickLookups(t) + r, workspace := aRepository(t, nothingToBuild, nil) + f := &failingClones{r: r, n: -1, failure: lookupFailure} + _, err := Build(context.Background(), f.run, r, "http://novox.internal:20000/novox/x.git", "", "", workspace, nil, + Npmrc{}, GitCredential{}, nil) + if err == nil { + t.Fatal("a clone whose lookup never answered built") + } + if !strings.Contains(err.Error(), "the resolver did not answer") || + !strings.Contains(err.Error(), "http://novox.internal:20000/novox/x.git") { + t.Errorf("the failure does not say the resolver did not answer for the forge's URL: %v", err) + } + if f.clones < 2 { + t.Errorf("the clone ran %d times; a failed lookup is tried again within the bound", f.clones) + } +} + +// 1773/AC3: any other failure of git (authentication, a missing repository) is not tried again and fails at once. +func TestACloneFailingForAnotherReasonIsNotTriedAgain(t *testing.T) { + quickLookups(t) + for _, failure := range []string{ + "exit status 128\nfatal: Authentication failed for 'http://novox.internal:20000/novox/x.git/'", + "exit status 128\nremote: Not found.\nfatal: repository 'http://novox.internal:20000/novox/x.git/' not found", + "exit status 128\nfatal: unable to access 'http://novox.internal:20000/novox/x.git/': The requested URL returned error: 404", + } { + r, workspace := aRepository(t, nothingToBuild, nil) + f := &failingClones{r: r, n: -1, failure: failure} + _, err := Build(context.Background(), f.run, r, "http://novox.internal:20000/novox/x.git", "", "", workspace, nil, + Npmrc{}, GitCredential{}, nil) + if err == nil || !strings.Contains(err.Error(), "cannot clone") { + t.Errorf("a clone failing with %q said %v", failure, err) + } + if f.clones != 1 { + t.Errorf("a clone failing with %q ran %d times; it is not a lookup and is not tried again", failure, f.clones) + } + } +} + +// quickLookups shortens the bound and the pauses, so a test waits for milliseconds. +func quickLookups(t *testing.T) { + t.Helper() + wasBound, wasFirst := lookupWait, lookupFirstPause + lookupWait, lookupFirstPause = 200*time.Millisecond, 10*time.Millisecond + t.Cleanup(func() { lookupWait, lookupFirstPause = wasBound, wasFirst }) +} + +// 1773/AC1, 1773/AC3: a check's clones are the same: a failed lookup is tried again, and the failure after it (here +// an authentication refused) ends the check at once, not tried again. +func TestACheckCloneTriesAFailedLookupAgain(t *testing.T) { + quickLookups(t) + clones := 0 + run := func(_ context.Context, _ string, name string, args ...string) (string, error) { + if name == "git" && isACloneOf(args) { + clones++ + if clones <= 2 { + return "", fmt.Errorf("git clone: %s", lookupFailure) + } + return "", fmt.Errorf("git clone: exit status 128\nfatal: Authentication failed") + } + return "", nil + } + _, err := Check(context.Background(), run, CheckSpec{ID: "build-1", Owner: "novox", Repo: "x", Number: 1, + Repository: "http://novox.internal:20000/novox/x.git", Ref: "abc"}, t.TempDir(), "registry.invalid", + GitCredential{}, nil) + if err == nil || !strings.Contains(err.Error(), "cannot clone") || !strings.Contains(err.Error(), "Authentication failed") { + t.Fatalf("the check said %v", err) + } + if clones != 3 { + t.Errorf("the check's clone ran %d times, want 3: two failed lookups, then the refusal, not tried again", clones) + } +}