diff --git a/commands/history/inspect.go b/commands/history/inspect.go index d3be630fb4e4..3f11a8ccfbe3 100644 --- a/commands/history/inspect.go +++ b/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,6 +658,75 @@ 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, @@ -714,6 +734,7 @@ func loadVertexLogs(ctx context.Context, c *client.Client, ref string, dgst dige 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() diff --git a/commands/history/logs.go b/commands/history/logs.go index 5604a9fa8267..d1dbcd964883 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 { @@ -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 { diff --git a/commands/history/logs_test.go b/commands/history/logs_test.go new file mode 100644 index 000000000000..52ef8a983617 --- /dev/null +++ b/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()) + }) + } +} diff --git a/tests/history.go b/tests/history.go index 3adabc28dde4..e456b0e02bec 100644 --- a/tests/history.go +++ b/tests/history.go @@ -12,6 +12,7 @@ import ( "github.com/containerd/continuity/fs/fstest" "github.com/docker/buildx/util/gitutil" "github.com/docker/buildx/util/gitutil/gittestutil" + "github.com/moby/buildkit/identity" bkgitutil "github.com/moby/buildkit/util/gitutil" "github.com/moby/buildkit/util/testutil/integration" "github.com/stretchr/testify/require" @@ -23,6 +24,7 @@ var historyTests = []func(t *testing.T, sb integration.Sandbox){ testHistoryExportFinalizeMultiNodeRef, testHistoryExportFinalizeMultiNodeAll, testHistoryInspect, + testHistoryLogsError, testHistoryLs, testHistoryRm, testHistoryLsStoppedBuilder, @@ -113,6 +115,50 @@ func testHistoryInspect(t *testing.T, sb integration.Sandbox) { require.NotEmpty(t, rec.Name) } +func testHistoryLogsError(t *testing.T, sb integration.Sandbox) { + buildName := "history-logs-error-" + identity.NewID() + dir := tmpdir(t, fstest.CreateFile("Dockerfile", []byte(`FROM scratch +COPY missing / +`), 0o600)) + + cmd := buildxCmd(sb, withArgs( + "build", + "--progress=quiet", + "--build-arg=BUILDKIT_BUILD_NAME="+buildName, + "--output=type=cacheonly", + dir, + )) + out, err := cmd.CombinedOutput() + require.Error(t, err, string(out)) + + cmd = buildxCmd(sb, withArgs("history", "ls", "--filter=status=error", "--format=json")) + out, err = cmd.CombinedOutput() + require.NoError(t, err, string(out)) + + var ref string + for line := range strings.SplitSeq(strings.TrimSpace(string(out)), "\n") { + line = strings.TrimSpace(line) + if !strings.HasPrefix(line, "{") { + continue + } + var rec historyLsRecord + require.NoError(t, json.Unmarshal([]byte(line), &rec)) + if rec.Name == buildName { + ref = rec.Ref + break + } + } + require.NotEmpty(t, ref, "failed build not found in history:\n%s", string(out)) + + refParts := strings.Split(ref, "/") + require.Len(t, refParts, 3) + cmd = buildxCmd(sb, withArgs("history", "logs", refParts[2], "--progress=plain")) + out, err = cmd.CombinedOutput() + require.NoError(t, err, string(out)) + require.Contains(t, string(out), "Error: ") + require.Contains(t, string(out), "Dockerfile:2") +} + func testHistoryLs(t *testing.T, sb integration.Sandbox) { ref := buildTestProject(t, sb) require.NotEmpty(t, ref.Ref)