metrics: add build command duration metric

This adds a build duration metric for the build command with attributes
related to the buildx driver, the error type (if any), and which options
were used to perform the build from a subset of the options.

This also refactors some of the utility methods used by the git tool to
determine filepaths into its own separate package so they can be reused
in another place.

Also adds a test to ensure the resource is initialized correctly and
doesn't error. The otel handler logging message is suppressed on buildx
invocations so we never see the error if there's a problem with the
schema url. It's so easy to mess up the schema url when upgrading OTEL
that we need a proper test to make sure we haven't broken the
functionality.

Signed-off-by: Jonathan A. Sternberg <jonathan.sternberg@docker.com>

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))
+}