Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
28 changes: 17 additions & 11 deletions cmd/artifact/build/create/cmd.go
Original file line number Diff line number Diff line change
Expand Up @@ -144,22 +144,28 @@ func waitForAllBuilds(
fmt.Fprintf(cmd.ErrOrStderr(), "Waiting for build %s...\n", buildID)

build, werr := waitStreaming(cmd, artifactID, buildID, poll)
if werr != nil && firstWaitErr == nil {
firstWaitErr = werr
}

if build == nil {
summaries = append(summaries, workload.BuildSummary{BuildID: buildID, Status: workload.BuildStatusCLIUnknown})
if build != nil {
summary, serr := workload.BuildSummaryFor(build, workload.DefaultBuildLogTail)

continue
}
// Reuses summary.LogTail (just fetched above) to decide whether
// the logs hint is worth showing -- no extra call.
if workload.IsBuildErrorStatus(build.Status) {
werr = workload.BuildFailureMessage(artifactID, build.ID, build.Status, len(summary.LogTail) > 0)
}

summary, serr := workload.BuildSummaryFor(build, workload.DefaultBuildLogTail)
if serr != nil && firstWaitErr == nil {
firstWaitErr = serr
if serr != nil && firstWaitErr == nil {
firstWaitErr = serr
}

summaries = append(summaries, summary)
} else {
summaries = append(summaries, workload.BuildSummary{BuildID: buildID, Status: workload.BuildStatusCLIUnknown})
}

summaries = append(summaries, summary)
if werr != nil && firstWaitErr == nil {
firstWaitErr = werr
}
}

return summaries, firstWaitErr
Expand Down
16 changes: 7 additions & 9 deletions cmd/artifact/build/get/cmd.go
Original file line number Diff line number Diff line change
Expand Up @@ -128,17 +128,15 @@ func runGet(
return err
}

if waitErr != nil {
return waitErr
// Covers both "already terminal-error on the first GET" and "failed
// during the wait". Reuses summary.LogTail (already fetched above) to
// decide whether the logs hint is worth showing -- no extra call.
if workload.IsBuildErrorStatus(build.Status) {
return workload.BuildFailureMessage(artifactID, build.ID, build.Status, len(summary.LogTail) > 0)
}

// The build may have been already terminal-error on the first GET, in
// which case WaitForBuild was skipped and waitErr stays nil. Surface
// that explicitly so the process exits non-zero; hint at the logs
// command so the user has a one-step recovery to inspect what went
// wrong.
if workload.IsBuildErrorStatus(build.Status) {
return fmt.Errorf("build %s ended with status %s; run 'dr artifact build logs %s' to inspect", build.ID, build.Status, build.ID)
if waitErr != nil {
return waitErr
}

return nil
Expand Down
29 changes: 28 additions & 1 deletion internal/workload/build.go
Original file line number Diff line number Diff line change
Expand Up @@ -387,7 +387,13 @@ func WaitForBuild(

if IsTerminalBuildStatus(build.Status) {
if IsBuildErrorStatus(build.Status) {
return build, fmt.Errorf("build %s ended with status %s; run 'dr artifact build logs %s' to inspect", buildID, build.Status, buildID)
// No 'dr artifact build logs' suggestion here: this shared
// primitive doesn't know whether logs exist, and callers
// that already fetch them (via BuildSummaryFor) shouldn't be
// forced into a second fetch just so this function can
// build a hint. Callers construct the final message
// themselves via BuildFailureMessage.
return build, fmt.Errorf("build %s ended with status %s", buildID, build.Status)
}

return build, nil
Expand All @@ -401,6 +407,27 @@ func WaitForBuild(
}
}

// BuildLogsAvailable reports whether at least one log entry exists for the
// build. Used to decide whether it's worth pointing the user at
// 'dr artifact build logs' -- suggesting a command that 404s or prints
// nothing is worse than not suggesting anything.
func BuildLogsAvailable(artifactID, buildID string) bool {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[P2] BuildLogsAvailable drains every log page to answer a boolean

BuildLogsAvailable calls GetArtifactBuildLogs, which hardcodes maxEntries = 0 (build.go:337). In drainLogPages, maxEntries <= 0 means "drain every page" — it follows every next link to the end with no early exit. For a failed build with a verbose Docker log stream, that's potentially dozens of HTTP round-trips just to evaluate len(entries) > 0.

The trigger is this PR's only "extra precheck fetch" call site: buildImage in internal/workload/up/build.go calls hasLogsFn on every failed dr workload up, right after BuildLogTail already fetched (much of) the same data during the wait.

The fix is cheap because the seam already exists: call fetchArtifactBuildLogs(artifactID, buildID, 1, "", "", "") directly — limit=1 short-circuits after the first page — or give GetArtifactBuildLogs a limit parameter. (Related to but distinct from the ingestion-lag concern raised in the other thread: even with correct timing, this check is far more expensive than it needs to be.)

Suggested change
func BuildLogsAvailable(artifactID, buildID string) bool {
func BuildLogsAvailable(artifactID, buildID string) bool {
// limit=1: we only need to know whether at least one entry exists;
// maxEntries=0 would drain every page of a verbose build's log stream.
otel, err := fetchArtifactBuildLogs(artifactID, buildID, 1, "", "", "build logs")
return err == nil && len(otel) > 0
}

entries, err := GetArtifactBuildLogs(artifactID, buildID)

return err == nil && len(entries) > 0
}

// BuildFailureMessage formats the error for a build that ended in
// FAILED/CANCELLED, pointing at 'dr artifact build logs' only when
// logsAvailable is true.
func BuildFailureMessage(artifactID, buildID, status string, logsAvailable bool) error {
if !logsAvailable {
return fmt.Errorf("build %s ended with status %s; no logs were captured for this build", buildID, status)

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fetch errors claimed as missing logs

Medium Severity

BuildFailureMessage states that no logs were captured whenever logsAvailable is false, but callers treat a failed logs fetch the same as a successful empty result. BuildLogsAvailable returns false on any error, and create/get infer availability from LogTail after BuildSummaryFor swallows fetch failures. A 5xx, 403, or transient outage then tells the user logs never existed, so they will not retry dr artifact build logs even though the stream may have just printed lines or the command would succeed moments later.

Additional Locations (2)
Fix in Cursor Fix in Web

Reviewed by Cursor Bugbot for commit 5c756c6. Configure here.

}

return fmt.Errorf("build %s ended with status %s; see 'dr artifact build logs %s %s'", buildID, status, artifactID, buildID)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[low] question: does this hint hold up for a build that only logged at DEBUG? dr artifact build logs defaults to --level info and filters, but both availability checks count unfiltered entries, so that build gets the hint and then prints "No logs found."

}

// BuildSummaryFor composes the terminal-state summary RenderBuildSummary
// renders. Duration comes from the Build timestamps; ImageURI is fetched
// from the parent artifact's primary container only on COMPLETED (the
Expand Down
90 changes: 90 additions & 0 deletions internal/workload/build_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -544,6 +544,96 @@ func TestGetArtifactBuildLogs_ReadsTheOTELStream(t *testing.T) {
assert.NotEmpty(t, entries[0].Raw, "OTEL record preserved for JSON passthrough")
}

// An empty OTEL page (no records for this build's external_build_id) is a
// legitimate empty result, not an error.
func TestGetArtifactBuildLogs_EmptyPageIsEmpty(t *testing.T) {
installSkipAuth(t)

srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
_, _ = w.Write([]byte(logsPage("")))
}))

defer srv.Close()

installEndpoint(t, srv.URL)

entries, err := GetArtifactBuildLogs("art-1", "b-1")
require.NoError(t, err)
assert.Empty(t, entries)
}

func TestBuildLogsAvailable(t *testing.T) {
t.Run("true when entries exist", func(t *testing.T) {
installSkipAuth(t)

srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
_, _ = w.Write([]byte(logsPage("", logEntryDoc("INFO", "hi"))))
}))

defer srv.Close()

installEndpoint(t, srv.URL)

assert.True(t, BuildLogsAvailable("art-1", "b-1"))
})

t.Run("false on 404", func(t *testing.T) {
installSkipAuth(t)

srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusNotFound)
}))

defer srv.Close()

installEndpoint(t, srv.URL)

assert.False(t, BuildLogsAvailable("art-1", "b-1"))
})

t.Run("false on empty page", func(t *testing.T) {
installSkipAuth(t)

srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
_, _ = w.Write([]byte(logsPage("")))
}))

defer srv.Close()

installEndpoint(t, srv.URL)

assert.False(t, BuildLogsAvailable("art-1", "b-1"))
})

t.Run("false on server error", func(t *testing.T) {
installSkipAuth(t)

srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusInternalServerError)
}))

defer srv.Close()

installEndpoint(t, srv.URL)

assert.False(t, BuildLogsAvailable("art-1", "b-1"))
})
}

func TestBuildFailureMessage(t *testing.T) {
t.Run("with logs available", func(t *testing.T) {
err := BuildFailureMessage("art-1", "b-1", BuildStatusFailed, true)
require.Error(t, err)
assert.EqualError(t, err, "build b-1 ended with status FAILED; see 'dr artifact build logs art-1 b-1'")
})

t.Run("without logs available", func(t *testing.T) {
err := BuildFailureMessage("art-1", "b-1", BuildStatusCancelled, false)
require.Error(t, err)
assert.EqualError(t, err, "build b-1 ended with status CANCELLED; no logs were captured for this build")
})
}

func TestWaitForBuild_TerminalCompletedReturnsNil(t *testing.T) {
installSkipAuth(t)

Expand Down
14 changes: 14 additions & 0 deletions internal/workload/output.go
Original file line number Diff line number Diff line change
Expand Up @@ -254,11 +254,25 @@ func RenderBuildSummary(format outputformat.OutputFormat, summary BuildSummary)
return nil
}

// RenderBuildLogs prints a build's log entries: one formatted line each in
// text mode, or a JSON array (always [], never null, when empty). With no
// entries in text mode, "No logs found." goes to stderr so stdout stays log
// lines only and a `logs | grep`/pipe is not polluted by a status line.
func RenderBuildLogs(format outputformat.OutputFormat, entries []BuildLogEntry) error {
if format == outputformat.OutputFormatJSON {
if len(entries) == 0 {
entries = []BuildLogEntry{}
}

return printJSON(entries)
}

if len(entries) == 0 {
fmt.Fprintln(os.Stderr, "No logs found.")

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[P3] "No logs found." is wrong for logs filtered out by the default level

Verified end-to-end: cmd/artifact/build/logs/cmd.go calls GetArtifactBuildLogs (unfiltered), then FilterLogsByLevel(entries, "info") (the flag's default), then RenderBuildLogs. A DEBUG-only build therefore delivers an empty slice here, and this now prints No logs found. to stderr — factually wrong, the logs exist. Before this PR, empty text output printed nothing, so this message is newly introduced for the filtered-empty case, and it nudges the user away from the actual remedy (--level debug).

Render-side sibling of the unfiltered-availability comment on build.go: since filtering happens in the caller, RenderBuildLogs can't distinguish "no logs" from "all filtered out". Options: pass the pre-filter count into the render call, or have the cmd emit a level-aware message like No logs at this level (try --level debug).


return nil
}

for _, entry := range entries {
fmt.Println(formatLogLine(entry))
}
Expand Down
23 changes: 23 additions & 0 deletions internal/workload/output_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -530,6 +530,29 @@ func TestRenderBuildLogs_JSONPassthroughPreservesRaw(t *testing.T) {
assert.Equal(t, "raw", got[0]["message"])
}

func TestRenderBuildLogs_TextEmpty(t *testing.T) {
var stderr string

stdout := captureStdout(t, func() {
stderr = captureStderr(t, func() {
require.NoError(t, RenderBuildLogs(outputformat.OutputFormatText, nil))
})
})

// The hint goes to stderr so stdout stays log lines only (pipe/grep safe).
assert.Empty(t, stdout)
assert.Equal(t, "No logs found.\n", stderr)
}

func TestRenderBuildLogs_JSONAlwaysArray(t *testing.T) {
output := captureStdout(t, func() {
require.NoError(t, RenderBuildLogs(outputformat.OutputFormatJSON, nil))
})

// A regression that emits `null` instead of a JSON array must fail here.
assert.JSONEq(t, `[]`, output)
}

func TestFilterLogsByLevel(t *testing.T) {
entries := []BuildLogEntry{
{Levelname: "DEBUG", Message: "d"},
Expand Down
8 changes: 4 additions & 4 deletions internal/workload/up/build.go
Original file line number Diff line number Diff line change
Expand Up @@ -481,10 +481,10 @@ func buildImage(artifactID, attachTo string, opts Options, report *reporter) (st
}

if workload.IsBuildErrorStatus(built.Status) {
// Said here rather than left to the wait's own wording, because this
// is the only place that knows which artifact the build belongs to.
return built.ID, fmt.Errorf("build %s finished as %s; see 'dr artifact build logs %s %s'",
built.ID, built.Status, artifactID, built.ID)
// Precheck log availability before suggesting the logs command --
// this is the only call site with no already-fetched log info, so
// it's the one place that needs its own extra fetch.
return built.ID, workload.BuildFailureMessage(artifactID, built.ID, built.Status, hasLogsFn(artifactID, built.ID))

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[medium] Build log ingestion trails the builder by 20-40s per the buildLogLagAllowance comment, and this fires right after tail.Finish(), which is a single catch-up poll. A build that fails fast gets told no logs were captured, then the lines land a second later. Could the tail track whether it ever emitted a line instead?

}

// A build still running when the wait expires keeps its id too: it is
Expand Down
2 changes: 2 additions & 0 deletions internal/workload/up/roll_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -1372,6 +1372,8 @@ func TestRun_FailedBuildOnARollLeavesTheOldVersionServing(t *testing.T) {
return &workload.Build{ID: id, Status: workload.BuildStatusFailed},
fmt.Errorf("build %s ended with status %s", id, workload.BuildStatusFailed)
}
// Logs exist for this build, so the failure message should point at them.
f.hasLogs = func(string, string) bool { return true }

install(t, f)

Expand Down
1 change: 1 addition & 0 deletions internal/workload/up/run.go
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,7 @@ var (
lockArtifactFn = workload.LockArtifact
triggerBuildFn = workload.TriggerArtifactBuild
waitBuildFn = workload.WaitForBuild
hasLogsFn = workload.BuildLogsAvailable
listBuildsFn = workload.ListArtifactBuilds
getCredentialFn = workload.GetCredential
findCredentialFn = workload.FindCredentialNamed
Expand Down
8 changes: 8 additions & 0 deletions internal/workload/up/run_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -193,6 +193,7 @@ type fakes struct {
build func(string) (*workload.BuildTriggerResponse, error)
waitBuild func(string, string, time.Duration, time.Duration, func(*workload.Build)) (*workload.Build, error)
builds func(string, int) ([]workload.Build, error)
hasLogs func(string, string) bool

// checkEndpoint is the one GET a deploy ends with.
checkEndpoint func(string) (int, error)
Expand Down Expand Up @@ -287,6 +288,11 @@ func install(t *testing.T, f fakes) {
swap(t, &waitBuildFn, f.waitBuild)
swap(t, &listBuildsFn, f.builds)

// Defaults to "no logs" so a test that does not care does not make a
// real network call by accident.
force(t, &hasLogsFn, func(string, string) bool { return false })
swap(t, &hasLogsFn, f.hasLogs)

// Nothing stands in the way of a rollout unless a test says so, because
// the quiet answer is the one every other roll test wants.
force(t, &guardReplacementFn, func(string) error { return nil })
Expand Down Expand Up @@ -1492,6 +1498,8 @@ func TestRun_FailedBuildStopsAndNamesTheLogs(t *testing.T) {
return &workload.Build{ID: id, Status: workload.BuildStatusFailed},
fmt.Errorf("build %s ended with status %s", id, workload.BuildStatusFailed)
}
// Logs exist for this build, so the failure message should point at them.
f.hasLogs = func(string, string) bool { return true }

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[low] Both tests that reach this path force hasLogs true, so nothing asserts the "no logs were captured" wording through buildImage. Hardcoding true at build.go:487 would still pass the suite.


install(t, f)

Expand Down
Loading