Merge pull request #2225 from jsternberg/command-duration-metric

metrics: add build command duration metric

build/build.go

@@ -4,10 +4,8 @@ import (
 	"bufio"
 	"bytes"
 	"context"
-	"crypto/rand"
 	_ "crypto/sha256" // ensure digests can be computed
 	"encoding/base64"
-	"encoding/hex"
 	"encoding/json"
 	"fmt"
 	"io"
@@ -26,9 +24,11 @@ import (
 	"github.com/distribution/reference"
 	"github.com/docker/buildx/builder"
 	"github.com/docker/buildx/driver"
+	"github.com/docker/buildx/util/confutil"
 	"github.com/docker/buildx/util/desktop"
 	"github.com/docker/buildx/util/dockerutil"
 	"github.com/docker/buildx/util/imagetools"
+	"github.com/docker/buildx/util/osutil"
 	"github.com/docker/buildx/util/progress"
 	"github.com/docker/buildx/util/resolver"
 	"github.com/docker/buildx/util/waitmap"
@@ -389,7 +389,7 @@ func toSolveOpt(ctx context.Context, node builder.Node, multiDriver bool, opt Op
 		if p, err := filepath.Abs(sharedKey); err == nil {
 			sharedKey = filepath.Base(p)
 		}
-		so.SharedKey = sharedKey + ":" + tryNodeIdentifier(configDir)
+		so.SharedKey = sharedKey + ":" + confutil.TryNodeIdentifier(configDir)
 	}
 
 	if opt.Pull {
@@ -1148,7 +1148,7 @@ func LoadInputs(ctx context.Context, d *driver.DriverHandle, inp Inputs, pw prog
 				target.LocalDirs["context"] = inp.ContextPath
 			}
 		}
-	case isLocalDir(inp.ContextPath):
+	case osutil.IsLocalDir(inp.ContextPath):
 		target.LocalDirs["context"] = inp.ContextPath
 		switch inp.DockerfilePath {
 		case "-":
@@ -1465,31 +1465,6 @@ func handleLowercaseDockerfile(dir, p string) string {
 	return p
 }
 
-var nodeIdentifierMu sync.Mutex
-
-func tryNodeIdentifier(configDir string) (out string) {
-	nodeIdentifierMu.Lock()
-	defer nodeIdentifierMu.Unlock()
-	sessionFile := filepath.Join(configDir, ".buildNodeID")
-	if _, err := os.Lstat(sessionFile); err != nil {
-		if os.IsNotExist(err) { // create a new file with stored randomness
-			b := make([]byte, 8)
-			if _, err := rand.Read(b); err != nil {
-				return out
-			}
-			if err := os.WriteFile(sessionFile, []byte(hex.EncodeToString(b)), 0600); err != nil {
-				return out
-			}
-		}
-	}
-
-	dt, err := os.ReadFile(sessionFile)
-	if err == nil {
-		return string(dt)
-	}
-	return
-}
-
 func noPrintFunc(opt map[string]Options) bool {
 	for _, v := range opt {
 		if v.PrintFunc != nil {

build/git.go

@@ -9,6 +9,7 @@ import (
 	"strings"
 
 	"github.com/docker/buildx/util/gitutil"
+	"github.com/docker/buildx/util/osutil"
 	"github.com/moby/buildkit/client"
 	specs "github.com/opencontainers/image-spec/specs-go/v1"
 	"github.com/pkg/errors"
@@ -46,9 +47,9 @@ func getGitAttributes(ctx context.Context, contextPath string, dockerfilePath st
 	if filepath.IsAbs(contextPath) {
 		wd = contextPath
 	} else {
-		wd, _ = filepath.Abs(filepath.Join(getWd(), contextPath))
+		wd, _ = filepath.Abs(filepath.Join(osutil.GetWd(), contextPath))
 	}
-	wd = gitutil.SanitizePath(wd)
+	wd = osutil.SanitizePath(wd)
 
 	gitc, err := gitutil.New(gitutil.WithContext(ctx), gitutil.WithWorkingDir(wd))
 	if err != nil {
@@ -104,7 +105,7 @@ func getGitAttributes(ctx context.Context, contextPath string, dockerfilePath st
 			dockerfilePath = filepath.Join(wd, "Dockerfile")
 		}
 		if !filepath.IsAbs(dockerfilePath) {
-			dockerfilePath = filepath.Join(getWd(), dockerfilePath)
+			dockerfilePath = filepath.Join(osutil.GetWd(), dockerfilePath)
 		}
 		if r, err := filepath.Rel(root, dockerfilePath); err == nil && !strings.HasPrefix(r, "..") {
 			res["label:"+DockerfileLabel] = r
@@ -124,21 +125,13 @@ func getGitAttributes(ctx context.Context, contextPath string, dockerfilePath st
 			if err != nil {
 				continue
 			}
-			if lp, err := getLongPathName(dir); err == nil {
+			if lp, err := osutil.GetLongPathName(dir); err == nil {
 				dir = lp
 			}
-			dir = gitutil.SanitizePath(dir)
+			dir = osutil.SanitizePath(dir)
 			if r, err := filepath.Rel(root, dir); err == nil && !strings.HasPrefix(r, "..") {
 				so.FrontendAttrs["vcs:localdir:"+k] = r
 			}
 		}
 	}, nil
 }
-
-func getWd() string {
-	wd, _ := os.Getwd()
-	if lp, err := getLongPathName(wd); err == nil {
-		return lp
-	}
-	return wd
-}

build/git_unix.go

@@ -1,9 +0,0 @@
-//go:build !windows
-// +build !windows
-
-package build
-
-// getLongPathName is a no-op on non-Windows platforms.
-func getLongPathName(path string) (string, error) {
-	return path, nil
-}

build/utils.go

@@ -5,7 +5,6 @@ import (
 	"bytes"
 	"context"
 	"net"
-	"os"
 	"strings"
 
 	"github.com/docker/buildx/driver"
@@ -34,11 +33,6 @@ func IsRemoteURL(c string) bool {
 	return false
 }
 
-func isLocalDir(c string) bool {
-	st, err := os.Stat(c)
-	return err == nil && st.IsDir()
-}
-
 func isArchive(header []byte) bool {
 	for _, m := range [][]byte{
 		{0x42, 0x5A, 0x68},                   // bzip2

commands/build.go

@@ -3,8 +3,10 @@ package commands
 import (
 	"bytes"
 	"context"
+	"crypto/sha256"
 	"encoding/base64"
 	"encoding/csv"
+	"encoding/hex"
 	"encoding/json"
 	"fmt"
 	"io"
@@ -13,6 +15,8 @@ import (
 	"path/filepath"
 	"strconv"
 	"strings"
+	"sync"
+	"time"
 
 	"github.com/containerd/console"
 	"github.com/docker/buildx/build"
@@ -28,9 +32,11 @@ import (
 	"github.com/docker/buildx/store/storeutil"
 	"github.com/docker/buildx/util/buildflags"
 	"github.com/docker/buildx/util/cobrautil"
+	"github.com/docker/buildx/util/confutil"
 	"github.com/docker/buildx/util/desktop"
 	"github.com/docker/buildx/util/ioset"
 	"github.com/docker/buildx/util/metricutil"
+	"github.com/docker/buildx/util/osutil"
 	"github.com/docker/buildx/util/progress"
 	"github.com/docker/buildx/util/tracing"
 	"github.com/docker/cli-docs-tool/annotation"
@@ -52,6 +58,8 @@ import (
 	"github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
+	"go.opentelemetry.io/otel/attribute"
+	"go.opentelemetry.io/otel/metric"
 	"google.golang.org/grpc/codes"
 )
 
@@ -211,6 +219,52 @@ func (o *buildOptions) toDisplayMode() (progressui.DisplayMode, error) {
 	return progress, nil
 }
 
+func buildMetricAttributes(dockerCli command.Cli, b *builder.Builder, options *buildOptions) attribute.Set {
+	return attribute.NewSet(
+		attribute.String("command.name", "build"),
+		attribute.Stringer("command.options.hash", &buildOptionsHash{
+			buildOptions: options,
+			configDir:    confutil.ConfigDir(dockerCli),
+		}),
+		attribute.String("driver.name", options.builder),
+		attribute.String("driver.type", b.Driver),
+	)
+}
+
+// buildOptionsHash computes a hash for the buildOptions when the String method is invoked.
+// This is done so we can delay the computation of the hash until needed by OTEL using
+// the fmt.Stringer interface.
+type buildOptionsHash struct {
+	*buildOptions
+	configDir  string
+	result     string
+	resultOnce sync.Once
+}
+
+func (o *buildOptionsHash) String() string {
+	o.resultOnce.Do(func() {
+		target := o.target
+		contextPath := o.contextPath
+		dockerfile := o.dockerfileName
+		if dockerfile == "" {
+			dockerfile = "Dockerfile"
+		}
+
+		if contextPath != "-" && osutil.IsLocalDir(contextPath) {
+			contextPath = osutil.ToAbs(contextPath)
+		}
+		salt := confutil.TryNodeIdentifier(o.configDir)
+
+		h := sha256.New()
+		for _, s := range []string{target, contextPath, dockerfile, salt} {
+			_, _ = io.WriteString(h, s)
+			h.Write([]byte{0})
+		}
+		o.result = hex.EncodeToString(h.Sum(nil))
+	})
+	return o.result
+}
+
 func runBuild(ctx context.Context, dockerCli command.Cli, options buildOptions) (err error) {
 	mp, err := metricutil.NewMeterProvider(ctx, dockerCli)
 	if err != nil {
@@ -279,6 +333,8 @@ func runBuild(ctx context.Context, dockerCli command.Cli, options buildOptions)
 		return err
 	}
 
+	attributes := buildMetricAttributes(dockerCli, b, &options)
+	done := timeBuildCommand(mp, attributes)
 	var resp *client.SolveResponse
 	var retErr error
 	if isExperimental() {
@@ -290,6 +346,8 @@ func runBuild(ctx context.Context, dockerCli command.Cli, options buildOptions)
 	if err := printer.Wait(); retErr == nil {
 		retErr = err
 	}
+
+	done(retErr)
 	if retErr != nil {
 		return retErr
 	}
@@ -933,3 +991,38 @@ func maybeJSONArray(v string) []string {
 	}
 	return []string{v}
 }
+
+// timeBuildCommand will start a timer for timing the build command. It records the time when the returned
+// function is invoked into a metric.
+func timeBuildCommand(mp metric.MeterProvider, attrs attribute.Set) func(err error) {
+	meter := metricutil.Meter(mp)
+	counter, _ := meter.Float64Counter("command.time",
+		metric.WithDescription("Measures the duration of the build command."),
+		metric.WithUnit("ms"),
+	)
+
+	start := time.Now()
+	return func(err error) {
+		dur := float64(time.Since(start)) / float64(time.Millisecond)
+		extraAttrs := attribute.NewSet()
+		if err != nil {
+			extraAttrs = attribute.NewSet(
+				attribute.String("error.type", otelErrorType(err)),
+			)
+		}
+		counter.Add(context.Background(), dur,
+			metric.WithAttributeSet(attrs),
+			metric.WithAttributeSet(extraAttrs),
+		)
+	}
+}
+
+// otelErrorType returns an attribute for the error type based on the error category.
+// If nil, this function returns an invalid attribute.
+func otelErrorType(err error) string {
+	name := "generic"
+	if errors.Is(err, context.Canceled) {
+		name = "canceled"
+	}
+	return name
+}

util/confutil/node.go

@@ -0,0 +1,34 @@
+package confutil
+
+import (
+	"crypto/rand"
+	"encoding/hex"
+	"os"
+	"path/filepath"
+	"sync"
+)
+
+var nodeIdentifierMu sync.Mutex
+
+func TryNodeIdentifier(configDir string) (out string) {
+	nodeIdentifierMu.Lock()
+	defer nodeIdentifierMu.Unlock()
+	sessionFile := filepath.Join(configDir, ".buildNodeID")
+	if _, err := os.Lstat(sessionFile); err != nil {
+		if os.IsNotExist(err) { // create a new file with stored randomness
+			b := make([]byte, 8)
+			if _, err := rand.Read(b); err != nil {
+				return out
+			}
+			if err := os.WriteFile(sessionFile, []byte(hex.EncodeToString(b)), 0600); err != nil {
+				return out
+			}
+		}
+	}
+
+	dt, err := os.ReadFile(sessionFile)
+	if err == nil {
+		return string(dt)
+	}
+	return
+}

util/gitutil/gitutil.go

@@ -9,6 +9,7 @@ import (
 	"path/filepath"
 	"strings"
 
+	"github.com/docker/buildx/util/osutil"
 	"github.com/pkg/errors"
 )
 
@@ -70,7 +71,7 @@ func (c *Git) RootDir() (string, error) {
 	if err != nil {
 		return "", err
 	}
-	return SanitizePath(root), nil
+	return osutil.SanitizePath(root), nil
 }
 
 func (c *Git) GitDir() (string, error) {

util/gitutil/path.go

@@ -7,8 +7,6 @@ import (
 	"os"
 	"os/exec"
 	"path/filepath"
-	"regexp"
-	"strings"
 
 	"github.com/moby/sys/mountinfo"
 )
@@ -42,18 +40,3 @@ func gitPath(wd string) (string, error) {
 	}
 	return exec.LookPath("git")
 }
-
-var windowsPathRegex = regexp.MustCompile(`^[A-Za-z]:[\\/].*$`)
-
-func SanitizePath(path string) string {
-	// If we're running in WSL, we need to convert Windows paths to Unix paths.
-	// This is because the git binary can be invoked through `git.exe` and
-	// therefore returns Windows paths.
-	if os.Getenv("WSL_DISTRO_NAME") != "" && windowsPathRegex.MatchString(path) {
-		unixPath := strings.ReplaceAll(path, "\\", "/")
-		drive := strings.ToLower(string(unixPath[0]))
-		rest := filepath.Clean(unixPath[3:])
-		return filepath.Join("/mnt", drive, rest)
-	}
-	return filepath.Clean(path)
-}

util/gitutil/path_unix_test.go

@@ -6,14 +6,15 @@ package gitutil
 import (
 	"testing"
 
+	"github.com/docker/buildx/util/osutil"
 	"github.com/stretchr/testify/assert"
 )
 
 func TestSanitizePathUnix(t *testing.T) {
-	assert.Equal(t, "/home/foobar", SanitizePath("/home/foobar"))
+	assert.Equal(t, "/home/foobar", osutil.SanitizePath("/home/foobar"))
 }
 
 func TestSanitizePathWSL(t *testing.T) {
 	t.Setenv("WSL_DISTRO_NAME", "Ubuntu")
-	assert.Equal(t, "/mnt/c/Users/foobar", SanitizePath("C:\\Users\\foobar"))
+	assert.Equal(t, "/mnt/c/Users/foobar", osutil.SanitizePath("C:\\Users\\foobar"))
 }

util/gitutil/path_windows.go

@@ -2,13 +2,8 @@ package gitutil
 
 import (
 	"os/exec"
-	"path/filepath"
 )
 
 func gitPath(wd string) (string, error) {
 	return exec.LookPath("git.exe")
 }
-
-func SanitizePath(path string) string {
-	return filepath.ToSlash(filepath.Clean(path))
-}

util/gitutil/path_windows_test.go

@@ -4,6 +4,7 @@ import (
 	"os"
 	"testing"
 
+	"github.com/docker/buildx/util/osutil"
 	"github.com/stretchr/testify/assert"
 )
 
@@ -12,7 +13,7 @@ func TestSanitizePathWindows(t *testing.T) {
 	if isGitBash() {
 		expected = "C:/Users/foobar"
 	}
-	assert.Equal(t, expected, SanitizePath("C:/Users/foobar"))
+	assert.Equal(t, expected, osutil.SanitizePath("C:/Users/foobar"))
 }
 
 func isGitBash() bool {

util/metricutil/metric.go

@@ -11,6 +11,7 @@ import (
 	"github.com/docker/buildx/version"
 	"github.com/docker/cli/cli/command"
 	"github.com/pkg/errors"
+	"go.opentelemetry.io/otel"
 	"go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetricgrpc"
 	"go.opentelemetry.io/otel/metric"
 	"go.opentelemetry.io/otel/metric/noop"
@@ -86,6 +87,7 @@ func (m *MeterProvider) Report(ctx context.Context) {
 	var rm metricdata.ResourceMetrics
 	if err := m.reader.Collect(ctx, &rm); err != nil {
 		// Error when collecting metrics. Do not send any.
+		otel.Handle(err)
 		return
 	}
 
@@ -93,7 +95,9 @@ func (m *MeterProvider) Report(ctx context.Context) {
 	for _, exp := range m.exporters {
 		exp := exp
 		eg.Go(func() error {
-			_ = exp.Export(ctx, &rm)
+			if err := exp.Export(ctx, &rm); err != nil {
+				otel.Handle(err)
+			}
 			_ = exp.Shutdown(ctx)
 			return nil
 		})

util/metricutil/resource_test.go

@@ -0,0 +1,33 @@
+package metricutil
+
+import (
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"go.opentelemetry.io/otel"
+)
+
+func TestResource(t *testing.T) {
+	setErrorHandler(t)
+
+	// Ensure resource creation doesn't result in an error.
+	// This is because the schema urls for the various attributes need to be
+	// the same, but it's really easy to import the wrong package when upgrading
+	// otel to anew version and the buildx CLI swallows any visible errors.
+	res := Resource()
+
+	// Ensure an attribute is present.
+	assert.True(t, res.Set().HasValue("telemetry.sdk.version"), "resource attribute missing")
+}
+
+func setErrorHandler(tb testing.TB) {
+	tb.Helper()
+
+	errorHandler := otel.GetErrorHandler()
+	otel.SetErrorHandler(otel.ErrorHandlerFunc(func(err error) {
+		tb.Errorf("otel error: %s", err)
+	}))
+	tb.Cleanup(func() {
+		otel.SetErrorHandler(errorHandler)
+	})
+}

util/osutil/path.go

@@ -0,0 +1,30 @@
+package osutil
+
+import (
+	"os"
+	"path/filepath"
+)
+
+// GetWd retrieves the current working directory.
+//
+// On Windows, this function will return the long path name
+// version of the path.
+func GetWd() string {
+	wd, _ := os.Getwd()
+	if lp, err := GetLongPathName(wd); err == nil {
+		return lp
+	}
+	return wd
+}
+
+func IsLocalDir(c string) bool {
+	st, err := os.Stat(c)
+	return err == nil && st.IsDir()
+}
+
+func ToAbs(path string) string {
+	if !filepath.IsAbs(path) {
+		path, _ = filepath.Abs(filepath.Join(GetWd(), path))
+	}
+	return SanitizePath(path)
+}

util/osutil/path_unix.go

@@ -0,0 +1,31 @@
+//go:build !windows
+// +build !windows
+
+package osutil
+
+import (
+	"os"
+	"path/filepath"
+	"regexp"
+	"strings"
+)
+
+// GetLongPathName is a no-op on non-Windows platforms.
+func GetLongPathName(path string) (string, error) {
+	return path, nil
+}
+
+var windowsPathRegex = regexp.MustCompile(`^[A-Za-z]:[\\/].*$`)
+
+func SanitizePath(path string) string {
+	// If we're running in WSL, we need to convert Windows paths to Unix paths.
+	// This is because the git binary can be invoked through `git.exe` and
+	// therefore returns Windows paths.
+	if os.Getenv("WSL_DISTRO_NAME") != "" && windowsPathRegex.MatchString(path) {
+		unixPath := strings.ReplaceAll(path, "\\", "/")
+		drive := strings.ToLower(string(unixPath[0]))
+		rest := filepath.Clean(unixPath[3:])
+		return filepath.Join("/mnt", drive, rest)
+	}
+	return filepath.Clean(path)
+}

util/osutil/path_windows.go

@@ -1,10 +1,14 @@
-package build
+package osutil
 
-import "golang.org/x/sys/windows"
+import (
+	"path/filepath"
 
-// getLongPathName converts Windows short pathnames to full pathnames.
+	"golang.org/x/sys/windows"
+)
+
+// GetLongPathName converts Windows short pathnames to full pathnames.
 // For example C:\Users\ADMIN~1 --> C:\Users\Administrator.
-func getLongPathName(path string) (string, error) {
+func GetLongPathName(path string) (string, error) {
 	// See https://groups.google.com/forum/#!topic/golang-dev/1tufzkruoTg
 	p, err := windows.UTF16FromString(path)
 	if err != nil {
@@ -24,3 +28,7 @@ func getLongPathName(path string) (string, error) {
 	}
 	return windows.UTF16ToString(b), nil
 }
+
+func SanitizePath(path string) string {
+	return filepath.ToSlash(filepath.Clean(path))
+}