history: print build errors at the end of history logs

commands/history/inspect.go

@@ -304,49 +304,17 @@ workers0:
 		out.Status = statusComplete
 	}
 
-	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))
+	if rec.Error != nil {
+		if codes.Code(rec.Error.Code) == codes.Canceled {
+			out.Status = statusCanceled
+		} else {
+			out.Status = statusError
 		}
 	}
+	out.Error, err = loadErrorOutput(ctx, c, rec)
+	if err != nil {
+		return err
+	}
 
 	if out.StartedAt != nil {
 		if out.CompletedAt != nil {
@@ -652,24 +620,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)
@@ -707,13 +658,83 @@ func inspectCmd(dockerCli command.Cli, rootOpts RootOptions) *cobra.Command {
 	return cmd
 }
 
+func loadErrorOutput(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 {
+		return out, 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 printErrorDetails(w io.Writer, out *errorOutput) {
+	if len(out.Sources) > 0 {
+		fmt.Fprint(w, string(out.Sources))
+	}
+	if len(out.Logs) > 0 {
+		fmt.Fprintln(w, "Logs:")
+		fmt.Fprintf(w, "> => %s:\n", out.Name)
+		for _, l := range out.Logs {
+			fmt.Fprintln(w, "> "+l)
+		}
+		fmt.Fprintln(w)
+	}
+	if len(out.Stack) > 0 {
+		if debug.IsEnabled() {
+			fmt.Fprintf(w, "\n%s\n", out.Stack)
+		} else {
+			fmt.Fprintln(w, "Enable --debug to see stack traces for error")
+		}
+	}
+}
+
 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,
 	})
 	if err != nil {
 		return "", nil, err
 	}
+	defer st.CloseSend()
 
 	var name string
 	var logs []string
@@ -723,7 +744,6 @@ loop0:
 	for {
 		select {
 		case <-ctx.Done():
-			st.CloseSend()
 			return "", nil, context.Cause(ctx)
 		default:
 			ev, err := st.Recv()

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 {
@@ -51,21 +53,22 @@ func runLogs(ctx context.Context, dockerCli command.Cli, opts logsOptions) error
 	if err != nil {
 		return err
 	}
+	defer cl.CloseSend()
 
 	mode := progressui.DisplayMode(opts.progress)
 	if mode == progressui.AutoMode {
 		mode = progressui.PlainMode
 	}
-	printer, err := progress.NewPrinter(context.TODO(), os.Stderr, mode)
+	printer, err := progress.NewPrinter(context.WithoutCancel(ctx), os.Stderr, mode)
 	if err != nil {
 		return err
 	}
+	defer printer.Wait()
 
 loop0:
 	for {
 		select {
 		case <-ctx.Done():
-			cl.CloseSend()
 			return context.Cause(ctx)
 		default:
 			ev, err := cl.Recv()
@@ -79,7 +82,29 @@ loop0:
 		}
 	}
 
-	return printer.Wait()
+	printerErr := printer.Wait()
+
+	errOut, err := loadErrorOutput(ctx, c, rec)
+	if err != nil {
+		return err
+	}
+	printLogError(os.Stderr, mode, errOut)
+
+	return printerErr
+}
+
+func printLogError(w io.Writer, mode progressui.DisplayMode, out *errorOutput) {
+	if out == nil || mode == progressui.RawJSONMode {
+		return
+	}
+
+	fmt.Fprintln(w)
+	if codes.Code(out.Code) == codes.Canceled {
+		fmt.Fprintln(w, "Build canceled")
+	} else if out.Message != "" {
+		fmt.Fprintf(w, "Error: %s %s\n", codes.Code(out.Code), out.Message)
+	}
+	printErrorDetails(w, out)
 }
 
 func logsCmd(dockerCli command.Cli, rootOpts RootOptions) *cobra.Command {

commands/history/logs_test.go

@@ -0,0 +1,96 @@
+package history
+
+import (
+	"bytes"
+	"context"
+	"testing"
+
+	controlapi "github.com/moby/buildkit/api/services/control"
+	"github.com/moby/buildkit/util/progress/progressui"
+	"github.com/stretchr/testify/require"
+	spb "google.golang.org/genproto/googleapis/rpc/status"
+	"google.golang.org/grpc/codes"
+)
+
+func TestLoadErrorOutput(t *testing.T) {
+	t.Run("no error", func(t *testing.T) {
+		out, err := loadErrorOutput(context.Background(), nil, &historyRecord{
+			BuildHistoryRecord: &controlapi.BuildHistoryRecord{},
+		})
+		require.NoError(t, err)
+		require.Nil(t, out)
+	})
+
+	t.Run("record error", func(t *testing.T) {
+		out, err := loadErrorOutput(context.Background(), nil, &historyRecord{
+			BuildHistoryRecord: &controlapi.BuildHistoryRecord{
+				Error: &spb.Status{
+					Code:    int32(codes.Internal),
+					Message: "failed to solve",
+				},
+			},
+		})
+		require.NoError(t, err)
+		require.Equal(t, &errorOutput{
+			Code:    int(codes.Internal),
+			Message: "failed to solve",
+		}, out)
+	})
+}
+
+func TestPrintLogError(t *testing.T) {
+	for _, tt := range []struct {
+		name string
+		mode progressui.DisplayMode
+		in   *errorOutput
+		want string
+	}{
+		{
+			name: "none",
+		},
+		{
+			name: "error",
+			mode: progressui.PlainMode,
+			in: &errorOutput{
+				Code:    int(codes.Internal),
+				Message: "failed to solve",
+			},
+			want: "\nError: Internal failed to solve\n",
+		},
+		{
+			name: "canceled",
+			mode: progressui.PlainMode,
+			in: &errorOutput{
+				Code:    int(codes.Canceled),
+				Message: "context canceled",
+			},
+			want: "\nBuild canceled\n",
+		},
+		{
+			name: "details",
+			mode: progressui.PlainMode,
+			in: &errorOutput{
+				Code:    int(codes.Internal),
+				Message: "failed to solve",
+				Name:    "[1/1] RUN exit 1",
+				Logs:    []string{"process exited with code 1"},
+				Sources: []byte("Dockerfile:1\n"),
+			},
+			want: "\nError: Internal failed to solve\nDockerfile:1\nLogs:\n> => [1/1] RUN exit 1:\n> process exited with code 1\n\n",
+		},
+		{
+			name: "rawjson",
+			mode: progressui.RawJSONMode,
+			in: &errorOutput{
+				Code:    int(codes.Internal),
+				Message: "failed to solve",
+			},
+		},
+	} {
+		t.Run(tt.name, func(t *testing.T) {
+			var buf bytes.Buffer
+			printLogError(&buf, tt.mode, tt.in)
+			require.Equal(t, tt.want, buf.String())
+		})
+	}
+}