From e6f2d4765e90b091250dc3680135a9c30d510661 Mon Sep 17 00:00:00 2001 From: Shaun Thompson <30006198+thompson-shaun@users.noreply.github.com> Date: Mon, 30 Mar 2026 12:11:14 -0400 Subject: [PATCH] history logs: print error summary at end of output When a build fails, `history logs` now prints an error summary after all progress output, matching the error detail already shown by `history inspect`. This includes the error message, source location (e.g. the failing Dockerfile line), logs from the failed vertex, and a stack trace hint. Particularly useful for cache key computation failures where no vertex logs appear during the main log replay. Extracts loadBuildErrorOutput and printErrorDetails as shared helpers so both commands use the same formatting logic. Co-Authored-By: Claude Sonnet 4.6 Signed-off-by: Shaun Thompson <30006198+thompson-shaun@users.noreply.github.com> --- commands/history/inspect.go | 127 +++++++++++++++++------------- commands/history/logs.go | 26 ++++++- commands/history/logs_test.go | 140 ++++++++++++++++++++++++++++++++++ 3 files changed, 241 insertions(+), 52 deletions(-) create mode 100644 commands/history/logs_test.go diff --git a/commands/history/inspect.go b/commands/history/inspect.go index a045d1ec724c..58b7a12087c3 100644 --- a/commands/history/inspect.go +++ b/commands/history/inspect.go @@ -297,46 +297,16 @@ workers0: } if rec.Error != nil || rec.ExternalError != nil { - out.Error = &errorOutput{} if rec.Error != nil { if codes.Code(rec.Error.Code) == codes.Canceled { out.Status = statusCanceled } else { out.Status = statusError } - out.Error.Code = int(codes.Code(rec.Error.Code)) - out.Error.Message = rec.Error.Message } - if rec.ExternalError != nil { - dt, err := content.ReadBlob(ctx, store, ociDesc(rec.ExternalError)) - if err != nil { - return errors.Wrapf(err, "failed to read external error %s", rec.ExternalError.Digest) - } - var st spb.Status - if err := proto.Unmarshal(dt, &st); err != nil { - return errors.Wrapf(err, "failed to unmarshal external error %s", rec.ExternalError.Digest) - } - retErr := grpcerrors.FromGRPC(status.ErrorProto(&st)) - var errsources bytes.Buffer - for _, s := range errdefs.Sources(retErr) { - s.Print(&errsources) - errsources.WriteString("\n") - } - out.Error.Sources = errsources.Bytes() - var ve *errdefs.VertexError - if errors.As(retErr, &ve) { - dgst, err := digest.Parse(ve.Digest) - if err != nil { - return errors.Wrapf(err, "failed to parse vertex digest %s", ve.Digest) - } - name, logs, err := loadVertexLogs(ctx, c, rec.Ref, dgst, 16) - if err != nil { - return errors.Wrapf(err, "failed to load vertex logs %s", dgst) - } - out.Error.Name = name - out.Error.Logs = logs - } - out.Error.Stack = fmt.Appendf(nil, "%+v", stack.Formatter(retErr)) + var loadErr error + if out.Error, loadErr = loadBuildErrorOutput(ctx, c, rec); loadErr != nil { + return loadErr } } @@ -616,24 +586,7 @@ workers0: } if out.Error != nil { - if out.Error.Sources != nil { - fmt.Fprint(dockerCli.Out(), string(out.Error.Sources)) - } - if len(out.Error.Logs) > 0 { - fmt.Fprintln(dockerCli.Out(), "Logs:") - fmt.Fprintf(dockerCli.Out(), "> => %s:\n", out.Error.Name) - for _, l := range out.Error.Logs { - fmt.Fprintln(dockerCli.Out(), "> "+l) - } - fmt.Fprintln(dockerCli.Out()) - } - if len(out.Error.Stack) > 0 { - if debug.IsEnabled() { - fmt.Fprintf(dockerCli.Out(), "\n%s\n", out.Error.Stack) - } else { - fmt.Fprintf(dockerCli.Out(), "Enable --debug to see stack traces for error\n") - } - } + printErrorDetails(dockerCli.Out(), out.Error) } fmt.Fprintf(dockerCli.Out(), "Print build logs: docker buildx history logs %s\n", rec.Ref) @@ -671,6 +624,78 @@ func inspectCmd(dockerCli command.Cli, rootOpts RootOptions) *cobra.Command { return cmd } +// printErrorDetails prints the sources, logs, and stack trace from an error output. +func printErrorDetails(w io.Writer, errOut *errorOutput) { + if len(errOut.Sources) > 0 { + fmt.Fprint(w, string(errOut.Sources)) + } + if len(errOut.Logs) > 0 { + fmt.Fprintln(w, "Logs:") + fmt.Fprintf(w, "> => %s:\n", errOut.Name) + for _, l := range errOut.Logs { + fmt.Fprintln(w, "> "+l) + } + fmt.Fprintln(w) + } + if len(errOut.Stack) > 0 { + if debug.IsEnabled() { + fmt.Fprintf(w, "\n%s\n", errOut.Stack) + } else { + fmt.Fprintf(w, "Enable --debug to see stack traces for error\n") + } + } +} + +// loadBuildErrorOutput builds an errorOutput from a history record's error fields. +// It returns nil if the record has no error. +func loadBuildErrorOutput(ctx context.Context, c *client.Client, rec *historyRecord) (*errorOutput, error) { + if rec.Error == nil && rec.ExternalError == nil { + return nil, nil + } + + out := &errorOutput{} + + if rec.Error != nil { + out.Code = int(codes.Code(rec.Error.Code)) + out.Message = rec.Error.Message + } + + if rec.ExternalError != nil { + store := proxy.NewContentStore(c.ContentClient()) + dt, err := content.ReadBlob(ctx, store, ociDesc(rec.ExternalError)) + if err != nil { + return nil, errors.Wrapf(err, "failed to read external error %s", rec.ExternalError.Digest) + } + var st spb.Status + if err := proto.Unmarshal(dt, &st); err != nil { + return nil, errors.Wrapf(err, "failed to unmarshal external error %s", rec.ExternalError.Digest) + } + retErr := grpcerrors.FromGRPC(status.ErrorProto(&st)) + var errsources bytes.Buffer + for _, s := range errdefs.Sources(retErr) { + s.Print(&errsources) + errsources.WriteString("\n") + } + out.Sources = errsources.Bytes() + var ve *errdefs.VertexError + if errors.As(retErr, &ve) { + dgst, err := digest.Parse(ve.Digest) + if err != nil { + return nil, errors.Wrapf(err, "failed to parse vertex digest %s", ve.Digest) + } + name, logs, err := loadVertexLogs(ctx, c, rec.Ref, dgst, 16) + if err != nil { + return nil, errors.Wrapf(err, "failed to load vertex logs %s", dgst) + } + out.Name = name + out.Logs = logs + } + out.Stack = fmt.Appendf(nil, "%+v", stack.Formatter(retErr)) + } + + return out, nil +} + func loadVertexLogs(ctx context.Context, c *client.Client, ref string, dgst digest.Digest, limit int) (string, []string, error) { st, err := c.ControlClient().Status(ctx, &controlapi.StatusRequest{ Ref: ref, diff --git a/commands/history/logs.go b/commands/history/logs.go index 5604a9fa8267..40e1bbb69985 100644 --- a/commands/history/logs.go +++ b/commands/history/logs.go @@ -2,6 +2,7 @@ package history import ( "context" + "fmt" "io" "os" @@ -13,6 +14,7 @@ import ( "github.com/moby/buildkit/util/progress/progressui" "github.com/pkg/errors" "github.com/spf13/cobra" + "google.golang.org/grpc/codes" ) type logsOptions struct { @@ -79,7 +81,29 @@ loop0: } } - return printer.Wait() + printerErr := printer.Wait() + + errOut, err := loadBuildErrorOutput(ctx, c, rec) + if err != nil { + return err + } + printLogsError(dockerCli.Err(), errOut) + + return printerErr +} + +// printLogsError prints a summary of a build error at the end of log output. +func printLogsError(w io.Writer, errOut *errorOutput) { + if errOut == nil { + return + } + fmt.Fprintln(w) + if codes.Code(errOut.Code) == codes.Canceled { + fmt.Fprintf(w, "Build canceled\n") + } else if errOut.Message != "" { + fmt.Fprintf(w, "Error: %s %s\n", codes.Code(errOut.Code).String(), errOut.Message) + } + printErrorDetails(w, errOut) } func logsCmd(dockerCli command.Cli, rootOpts RootOptions) *cobra.Command { diff --git a/commands/history/logs_test.go b/commands/history/logs_test.go new file mode 100644 index 000000000000..f3eb05ae8cd8 --- /dev/null +++ b/commands/history/logs_test.go @@ -0,0 +1,140 @@ +package history + +import ( + "bytes" + "context" + "testing" + + controlapi "github.com/moby/buildkit/api/services/control" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + spb "google.golang.org/genproto/googleapis/rpc/status" + "google.golang.org/grpc/codes" +) + +func TestLoadBuildErrorOutput_NoError(t *testing.T) { + rec := &historyRecord{ + BuildHistoryRecord: &controlapi.BuildHistoryRecord{}, + } + out, err := loadBuildErrorOutput(context.Background(), nil, rec) + require.NoError(t, err) + assert.Nil(t, out) +} + +func TestLoadBuildErrorOutput_GRPCError(t *testing.T) { + rec := &historyRecord{ + BuildHistoryRecord: &controlapi.BuildHistoryRecord{ + Error: &spb.Status{ + Code: int32(codes.Internal), + Message: "failed to solve: process did not complete successfully", + }, + }, + } + out, err := loadBuildErrorOutput(context.Background(), nil, rec) + require.NoError(t, err) + require.NotNil(t, out) + assert.Equal(t, int(codes.Internal), out.Code) + assert.Equal(t, "failed to solve: process did not complete successfully", out.Message) + assert.Nil(t, out.Sources) + assert.Empty(t, out.Logs) +} + +func TestLoadBuildErrorOutput_CanceledError(t *testing.T) { + rec := &historyRecord{ + BuildHistoryRecord: &controlapi.BuildHistoryRecord{ + Error: &spb.Status{ + Code: int32(codes.Canceled), + Message: "context canceled", + }, + }, + } + out, err := loadBuildErrorOutput(context.Background(), nil, rec) + require.NoError(t, err) + require.NotNil(t, out) + assert.Equal(t, int(codes.Canceled), out.Code) +} + +func TestPrintLogsError_Nil(t *testing.T) { + var buf bytes.Buffer + printLogsError(&buf, nil) + assert.Empty(t, buf.String()) +} + +func TestPrintLogsError_GRPCError(t *testing.T) { + var buf bytes.Buffer + printLogsError(&buf, &errorOutput{ + Code: int(codes.Internal), + Message: "failed to solve: dockerfile parse error", + }) + out := buf.String() + assert.Contains(t, out, "Error: Internal failed to solve: dockerfile parse error") +} + +func TestPrintLogsError_CanceledError(t *testing.T) { + var buf bytes.Buffer + printLogsError(&buf, &errorOutput{ + Code: int(codes.Canceled), + }) + out := buf.String() + assert.Contains(t, out, "Build canceled") + assert.NotContains(t, out, "Error:") +} + +func TestPrintLogsError_WithSources(t *testing.T) { + var buf bytes.Buffer + printLogsError(&buf, &errorOutput{ + Code: int(codes.Internal), + Message: "failed to solve", + Sources: []byte("Dockerfile:5\n > 5: RUN exit 1\n"), + }) + out := buf.String() + assert.Contains(t, out, "Error: Internal failed to solve") + assert.Contains(t, out, "Dockerfile:5") + assert.Contains(t, out, "RUN exit 1") +} + +func TestPrintLogsError_WithLogs(t *testing.T) { + var buf bytes.Buffer + printLogsError(&buf, &errorOutput{ + Code: int(codes.Internal), + Message: "failed to solve", + Name: "RUN echo hello", + Logs: []string{"hello", "world"}, + }) + out := buf.String() + assert.Contains(t, out, "Logs:") + assert.Contains(t, out, "> => RUN echo hello:") + assert.Contains(t, out, "> hello") + assert.Contains(t, out, "> world") +} + +func TestPrintErrorDetails_SourcesLogsStack(t *testing.T) { + var buf bytes.Buffer + printErrorDetails(&buf, &errorOutput{ + Sources: []byte("Dockerfile:5\n > 5: RUN exit 1\n"), + Name: "RUN exit 1", + Logs: []string{"step output"}, + Stack: []byte("goroutine 1 [running]:\n..."), + }) + out := buf.String() + assert.Contains(t, out, "Dockerfile:5") + assert.Contains(t, out, "Logs:") + assert.Contains(t, out, "> step output") + assert.Contains(t, out, "Enable --debug to see stack traces for error") + // header line is not printed by printErrorDetails + assert.NotContains(t, out, "Error:") + assert.NotContains(t, out, "Build canceled") +} + +func TestPrintLogsError_StackWithoutDebug(t *testing.T) { + var buf bytes.Buffer + printLogsError(&buf, &errorOutput{ + Code: int(codes.Internal), + Message: "failed to solve", + Stack: []byte("goroutine 1 [running]:\n..."), + }) + out := buf.String() + // debug is not enabled in tests, so we should see the hint + assert.Contains(t, out, "Enable --debug to see stack traces for error") + assert.NotContains(t, out, "goroutine 1") +}