From bd70379158b0065c665b28326b94ce6aacb90929 Mon Sep 17 00:00:00 2001 From: Zack Brady Date: Tue, 11 Aug 2026 19:58:58 -0400 Subject: [PATCH] fixed logging output when adding images (#732) --- cmd/hauler/cli/store/add.go | 10 +++++----- cmd/hauler/cli/store/sync_test.go | 11 ++++++----- 2 files changed, 11 insertions(+), 10 deletions(-) diff --git a/cmd/hauler/cli/store/add.go b/cmd/hauler/cli/store/add.go index 39adb20..73415fb 100644 --- a/cmd/hauler/cli/store/add.go +++ b/cmd/hauler/cli/store/add.go @@ -389,7 +389,7 @@ func storeLocalImage(ctx context.Context, s *store.Layout, i v1.Image, _ *flags. start := time.Now() ignoreErrors := flags.ShouldIgnoreErrors(ro) - l.Debugf("adding image [%s] from local Docker daemon to the store", i.Name) + l.Debugf("resolving image [%s] from local Docker daemon (rewrite=%q)", i.Name, rewrite) r, err := name.ParseReference(i.Name) if err != nil { @@ -480,7 +480,10 @@ func storeImage(ctx context.Context, s *store.Layout, i v1.Image, platform strin return err } - log.BaseFromContext(ctx).Debugf("adding image [%s] to the store", i.Name) + insecureSkipTLSVerify := derefInsecure(i.InsecureSkipTLSVerify) + caFile := i.CaFile + + log.BaseFromContext(ctx).Debugf("resolving image [%s] (verified=%t, platform=%q, excludeExtras=%t, insecureSkipTLSVerify=%t, caFile=%q, rewrite=%q, digest=%q)", i.Name, verified, platform, excludeExtras, insecureSkipTLSVerify, caFile, rewrite, pinnedDigest) r, err := name.ParseReference(i.Name) if err != nil { @@ -493,9 +496,6 @@ func storeImage(ctx context.Context, s *store.Layout, i v1.Image, platform strin } } - insecureSkipTLSVerify := derefInsecure(i.InsecureSkipTLSVerify) - caFile := i.CaFile - // fetch image along with any associated signatures and attestations. // A fresh store.ImageStats is built inside the closure on every attempt, // not once outside it, so a failed attempt's partial layer/byte counts diff --git a/cmd/hauler/cli/store/sync_test.go b/cmd/hauler/cli/store/sync_test.go index b1f0b90..0de13d6 100644 --- a/cmd/hauler/cli/store/sync_test.go +++ b/cmd/hauler/cli/store/sync_test.go @@ -2033,7 +2033,7 @@ func TestSyncImages_ErrorPropagation(t *testing.T) { // goroutine has fully returned (including cancelling gctx on failure), so // jobs run strictly in slice order and the good jobs are guaranteed to // observe the already-cancelled context before doing anything. -func TestRunImageJobs_CancelledJobsDoNotLogAddingImage(t *testing.T) { +func TestRunImageJobs_CancelledJobsDoNotLogResolvingImage(t *testing.T) { host, remoteOpts := newTestRegistry(t) const nGood = 3 @@ -2047,8 +2047,9 @@ func TestRunImageJobs_CancelledJobsDoNotLogAddingImage(t *testing.T) { s := newTestStore(t) var buf bytes.Buffer - // "adding image [...]" now logs at Debug (cmd/hauler/cli/store/add.go), - // so this test needs Debug-level output visible. Per-logger .Level() is + // "resolving image [...]" (storeImage's per-job startup line in + // cmd/hauler/cli/store/add.go) logs at Debug, so this test needs + // Debug-level output visible. Per-logger .Level() is // not sufficient on its own: zerolog's Logger.should() gates on // max(logger.level, zerolog.GlobalLevel()) -- and GlobalLevel is // process-global state that other tests in this package mutate (e.g. @@ -2073,9 +2074,9 @@ func TestRunImageJobs_CancelledJobsDoNotLogAddingImage(t *testing.T) { t.Fatal("runImageJobs: expected error, got nil") } - got := strings.Count(buf.String(), "adding image [") + got := strings.Count(buf.String(), "resolving image [") if got != 1 { - t.Errorf("\"adding image [\" logged %d times, want exactly 1 (only the failed job should have attempted logging; the %d good jobs queued after it must never start)\nfull log:\n%s", got, nGood, buf.String()) + t.Errorf("\"resolving image [\" logged %d times, want exactly 1 (only the failed job should have attempted logging; the %d good jobs queued after it must never start)\nfull log:\n%s", got, nGood, buf.String()) } }