diff --git a/cmd/buildctl/build.go b/cmd/buildctl/build.go index 1d185bba4734..206be8363952 100644 --- a/cmd/buildctl/build.go +++ b/cmd/buildctl/build.go @@ -8,6 +8,7 @@ import ( "io" "os" "strings" + "time" "github.com/containerd/continuity" "github.com/docker/cli/cli/config" @@ -109,6 +110,10 @@ var buildCommand = cli.Command{ Name: "registry-auth-tlscontext", Usage: "Overwrite TLS configuration when authenticating with registries, e.g. --registry-auth-tlscontext host=https://myserver:2376,insecure=false,ca=/path/to/my/ca.crt,cert=/path/to/my/cert.crt,key=/path/to/my/key.crt", }, + cli.StringFlag{ + Name: "debug-json-cache-metrics", + Usage: "Where to output json cache metrics, use 'stdout' or 'stderr' for standard (error) output.", + }, }, } @@ -143,7 +148,21 @@ func openTraceFile(clicontext *cli.Context) (*os.File, error) { return nil, nil } +func openCacheMetricsFile(clicontext *cli.Context) (*os.File, error) { + switch out := clicontext.String("debug-json-cache-metrics"); out { + case "stdout": + return os.Stdout, nil + case "stderr": + return os.Stderr, nil + case "": + return nil, nil + default: + return os.OpenFile(out, os.O_TRUNC|os.O_CREATE|os.O_WRONLY, 0600) + } +} + func buildAction(clicontext *cli.Context) error { + startTime := time.Now() c, err := bccommon.ResolveClient(clicontext) if err != nil { return err @@ -153,6 +172,11 @@ func buildAction(clicontext *cli.Context) error { if err != nil { return err } + cacheMetricsFile, err := openCacheMetricsFile(clicontext) + if err != nil { + return err + } + var traceEnc *json.Encoder if traceFile != nil { defer traceFile.Close() @@ -296,6 +320,23 @@ func buildAction(clicontext *cli.Context) error { return nil }) } + meg, ctx := errgroup.WithContext(bccommon.CommandContext(clicontext)) + if cacheMetricsFile != nil { + bklog.L.Infof("writing JSON cache metrics to %s", cacheMetricsFile.Name()) + metricsCh := make(chan *client.SolveStatus) + pw = progresswriter.Tee(pw, metricsCh) + meg.Go(func() error { + vtxMap := tailVTXInfo(ctx, pw, metricsCh) + if cacheMetricsFile == os.Stdout || cacheMetricsFile == os.Stdin { + // make sure everything was printed out to get it as the last line. + eg.Wait() + } else { + defer cacheMetricsFile.Close() + } + outputCacheMetrics(cacheMetricsFile, startTime, vtxMap) + return nil + }) + } mw := progresswriter.NewMultiWriter(pw) var writers []progresswriter.Writer @@ -378,6 +419,9 @@ func buildAction(clicontext *cli.Context) error { } } } + + meg.Wait() + return nil } diff --git a/cmd/buildctl/cachemetrics.go b/cmd/buildctl/cachemetrics.go new file mode 100644 index 000000000000..7e59c0c555c1 --- /dev/null +++ b/cmd/buildctl/cachemetrics.go @@ -0,0 +1,92 @@ +package main + +import ( + "context" + "encoding/json" + "fmt" + "os" + "regexp" + "strings" + "time" + + "github.com/moby/buildkit/client" + "github.com/moby/buildkit/util/progress/progresswriter" + digest "github.com/opencontainers/go-digest" +) + +type vtxInfo struct { + cached bool + completed bool + from bool + name string +} + +func tailVTXInfo(ctx context.Context, pw progresswriter.Writer, metricsCh <-chan *client.SolveStatus) map[digest.Digest]*vtxInfo { + fromRegexp := regexp.MustCompile(`^\[.*\] FROM`) + + vtxMap := make(map[digest.Digest]*vtxInfo) + for st := range metricsCh { + for _, vtx := range st.Vertexes { + if _, ok := vtxMap[vtx.Digest]; !ok { + vtxMap[vtx.Digest] = &vtxInfo{ + name: vtx.Name, + } + } + if fromRegexp.MatchString(vtx.Name) { + vtxMap[vtx.Digest].from = true + } + if vtx.Cached { + vtxMap[vtx.Digest].cached = true + } + if vtx.Completed != nil { + vtxMap[vtx.Digest].completed = true + } + } + } + return vtxMap +} + +func outputCacheMetrics(out *os.File, startTime time.Time, vtxMap map[digest.Digest]*vtxInfo) { + metrics := struct { + Total int64 `json:"total"` + Completed int64 `json:"completed"` + UserTotal int64 `json:"user_total"` + UserCached int64 `json:"user_cached"` + UserCompleted int64 `json:"user_completed"` + UserCacheable int64 `json:"user_cacheable"` + From int64 `json:"from"` + Miss int64 `json:"miss"` + ClientDurationMS int64 `json:"client_duration_ms"` + }{ + ClientDurationMS: time.Since(startTime).Milliseconds(), + } + for _, vtx := range vtxMap { + metrics.Total++ + if vtx.completed { + metrics.Completed++ + } + if strings.HasPrefix(vtx.name, "[internal]") || + strings.HasPrefix(vtx.name, "[auth]") || + strings.HasPrefix(vtx.name, "importing cache") || + strings.HasPrefix(vtx.name, "exporting ") { + continue + } + metrics.UserTotal++ + metrics.UserCacheable++ + if vtx.cached { + metrics.UserCached++ + } else if !vtx.from { + metrics.Miss++ + fmt.Fprintf(out, "cache miss: %s\n", vtx.name) + } + if vtx.completed { + metrics.UserCompleted++ + } + if vtx.from { + metrics.From++ + metrics.UserCacheable-- + } + } + dt, _ := json.Marshal(metrics) + fmt.Fprintln(out, string(dt)) +} diff --git a/docs/reference/buildctl.md b/docs/reference/buildctl.md index 27debb9d51af..0f9f904de726 100644 --- a/docs/reference/buildctl.md +++ b/docs/reference/buildctl.md @@ -79,6 +79,7 @@ OPTIONS: --source-policy-file value Read source policy file from a JSON file --ref-file value Write build ref to a file --registry-auth-tlscontext value Overwrite TLS configuration when authenticating with registries, e.g. --registry-auth-tlscontext host=https://myserver:2376,insecure=false,ca=/path/to/my/ca.crt,cert=/path/to/my/cert.crt,key=/path/to/my/key.crt + --debug-json-cache-metrics value Where to output json cache metrics, use 'stdout' or 'stderr' for standard (error) output. ```