Repository: docker/compose-cli
Pull request #2225 (2023-02-06 22:11:48)

metrics: initial logic for command execution duration
Add a timer around command invocations to be reported with metrics.
This isn't actually sent anywhere currently, as it's meant for
evented data which is forthcoming. (We could report it with the
current events, but it's not clear that there's any value in doing
so.)

The signature for `Track()` has been changed to take an object with
all the fields. This is both for sanity to keep the method from
getting ridiculously long, and to make it easier to unify the usage
(heartbeat) and event code paths by ensuring we have all the data
for both.

(Replaces #2224 which I accidentally closed and can't re-open 😅)


Patch:
diff --git a/cli/main.go b/cli/main.go
index 03cafd8d..81729ebf 100644
--- a/cli/main.go
+++ b/cli/main.go
@@ -253,10 +253,20 @@ func main() {
 
 	root.AddCommand(command)
 
-	if err = root.ExecuteContext(ctx); err != nil {
-		handleError(ctx, err, ctype, currentContext, cc, root)
+	start := time.Now().UTC()
+	err = root.ExecuteContext(ctx)
+	duration := time.Since(start)
+	if err != nil {
+		handleError(ctx, err, ctype, currentContext, cc, root, start, duration)
 	}
-	metricsClient.Track(ctype, os.Args[1:], compose.SuccessStatus)
+	metricsClient.Track(
+		metrics.CmdMeta{
+			ContextType: ctype,
+			Args:        os.Args[1:],
+			Status:      metrics.SuccessStatus,
+			Start:       start,
+			Duration:    duration,
+		})
 }
 
 func customizeCliForACI(command *cobra.Command, proxy *api.ServiceProxy) {
@@ -275,47 +285,87 @@ func customizeCliForACI(command *cobra.Command, proxy *api.ServiceProxy) {
 	}
 }
 
-func handleError(ctx context.Context, err error, ctype string, currentContext string, cc *store.DockerContext, root *cobra.Command) {
+func handleError(
+	ctx context.Context,
+	err error,
+	ctype string,
+	currentContext string,
+	cc *store.DockerContext,
+	root *cobra.Command,
+	start time.Time,
+	duration time.Duration,
+) {
 	// if user canceled request, simply exit without any error message
 	if api.IsErrCanceled(err) || errors.Is(ctx.Err(), context.Canceled) {
-		metricsClient.Track(ctype, os.Args[1:], compose.CanceledStatus)
+		metricsClient.Track(
+			metrics.CmdMeta{
+				ContextType: ctype,
+				Args:        os.Args[1:],
+				Status:      metrics.CanceledStatus,
+				Start:       start,
+				Duration:    duration,
+			},
+		)
 		os.Exit(130)
 	}
 	if ctype == store.AwsContextType {
-		exit(currentContext, errors.Errorf(`%q context type has been renamed. Recreate the context by running:
-$ docker context create %s <name>`, cc.Type(), store.EcsContextType), ctype)
+		exit(
+			currentContext,
+			errors.Errorf(`%q context type has been renamed. Recreate the context by running:
+$ docker context create %s <name>`, cc.Type(), store.EcsContextType),
+			ctype,
+			start,
+			duration,
+		)
 	}
 
 	// Context should always be handled by new CLI
 	requiredCmd, _, _ := root.Find(os.Args[1:])
 	if requiredCmd != nil && isContextAgnosticCommand(requiredCmd) {
-		exit(currentContext, err, ctype)
+		exit(currentContext, err, ctype, start, duration)
 	}
 	mobycli.ExecIfDefaultCtxType(ctx, root)
 
 	checkIfUnknownCommandExistInDefaultContext(err, currentContext, ctype)
 
-	exit(currentContext, err, ctype)
+	exit(currentContext, err, ctype, start, duration)
 }
 
-func exit(ctx string, err error, ctype string) {
+func exit(ctx string, err error, ctype string, start time.Time, duration time.Duration) {
 	if exit, ok := err.(cli.StatusError); ok {
-		metricsClient.Track(ctype, os.Args[1:], compose.SuccessStatus)
+		// TODO(milas): shouldn't this use the exit code to determine status?
+		metricsClient.Track(
+			metrics.CmdMeta{
+				ContextType: ctype,
+				Args:        os.Args[1:],
+				Status:      metrics.SuccessStatus,
+				Start:       start,
+				Duration:    duration,
+			},
+		)
 		os.Exit(exit.StatusCode)
 	}
 
 	var composeErr compose.Error
-	metricsStatus := compose.FailureStatus
+	metricsStatus := metrics.FailureStatus
 	exitCode := 1
 	if errors.As(err, &composeErr) {
 		metricsStatus = composeErr.GetMetricsFailureCategory().MetricsStatus
 		exitCode = composeErr.GetMetricsFailureCategory().ExitCode
 	}
 	if strings.HasPrefix(err.Error(), "unknown shorthand flag:") || strings.HasPrefix(err.Error(), "unknown flag:") || strings.HasPrefix(err.Error(), "unknown docker command:") {
-		metricsStatus = compose.CommandSyntaxFailure.MetricsStatus
-		exitCode = compose.CommandSyntaxFailure.ExitCode
+		metricsStatus = metrics.CommandSyntaxFailure.MetricsStatus
+		exitCode = metrics.CommandSyntaxFailure.ExitCode
 	}
-	metricsClient.Track(ctype, os.Args[1:], metricsStatus)
+	metricsClient.Track(
+		metrics.CmdMeta{
+			ContextType: ctype,
+			Args:        os.Args[1:],
+			Status:      metricsStatus,
+			Start:       start,
+			Duration:    duration,
+		},
+	)
 
 	if errors.Is(err, api.ErrLoginRequired) {
 		fmt.Fprintln(os.Stderr, err)
@@ -350,7 +400,11 @@ func checkIfUnknownCommandExistInDefaultContext(err error, currentContext string
 
 		if mobycli.IsDefaultContextCommand(dockerCommand) {
 			fmt.Fprintf(os.Stderr, "Command %q not available in current context (%s), you can use the \"default\" context to run this command\n", dockerCommand, currentContext)
-			metricsClient.Track(contextType, os.Args[1:], compose.FailureStatus)
+			metricsClient.Track(metrics.CmdMeta{
+				ContextType: contextType,
+				Args:        os.Args[1:],
+				Status:      metrics.FailureStatus,
+			})
 			os.Exit(1)
 		}
 	}
diff --git a/cli/metrics/client.go b/cli/metrics/client.go
index 4b012483..896bf3cd 100644
--- a/cli/metrics/client.go
+++ b/cli/metrics/client.go
@@ -26,6 +26,15 @@ import (
 // specified file path.
 const EnvVarDebugMetricsPath = "DOCKER_METRICS_DEBUG_LOG"
 
+type CmdMeta struct {
+	ContextType string
+	Args        []string
+	Status      string
+	ExitCode    int
+	Start       time.Time
+	Duration    time.Duration
+}
+
 type client struct {
 	cliversion *cliversion
 	reporter   Reporter
@@ -57,12 +66,12 @@ type Client interface {
 	// WithCliVersionFunc sets the docker cli version func
 	// that returns the docker cli version (com.docker.cli)
 	WithCliVersionFunc(f func() string)
-	// Send sends the command to Docker Desktop. Note that the function doesn't
-	// return anything, not even an error, this is because we don't really care
-	// if the metrics were sent or not. We only fire and forget.
-	Send(Command)
-	// Track sends the tracking analytics to Docker Desktop
-	Track(context string, args []string, status string)
+	// SendUsage sends the command to Docker Desktop.
+	//
+	// Note that metric collection is best-effort, so any errors are ignored.
+	SendUsage(Command)
+	// Track creates an event for a command execution and reports it.
+	Track(cmd CmdMeta)
 }
 
 // NewClient returns a new metrics client that will send metrics using the
@@ -98,7 +107,7 @@ func (c *client) WithCliVersionFunc(f func() string) {
 	c.cliversion.f = f
 }
 
-func (c *client) Send(command Command) {
+func (c *client) SendUsage(command Command) {
 	result := make(chan bool, 1)
 	go func() {
 		c.reporter.Heartbeat(command)
diff --git a/cli/metrics/event.go b/cli/metrics/event.go
new file mode 100644
index 00000000..e5c73d5f
--- /dev/null
+++ b/cli/metrics/event.go
@@ -0,0 +1,79 @@
+/*
+   Copyright 2020 Docker Compose CLI authors
+
+   Licensed under the Apache License, Version 2.0 (the "License");
+   you may not use this file except in compliance with the License.
+   You may obtain a copy of the License at
+
+       http://www.apache.org/licenses/LICENSE-2.0
+
+   Unless required by applicable law or agreed to in writing, software
+   distributed under the License is distributed on an "AS IS" BASIS,
+   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+   See the License for the specific language governing permissions and
+   limitations under the License.
+*/
+
+package metrics
+
+// FailureCategory struct regrouping metrics failure status and specific exit code
+type FailureCategory struct {
+	MetricsStatus string
+	ExitCode      int
+}
+
+const (
+	// APISource is sent for API metrics
+	APISource = "api"
+	// SuccessStatus command success
+	SuccessStatus = "success"
+	// FailureStatus command failure
+	FailureStatus = "failure"
+	// ComposeParseFailureStatus failure while parsing compose file
+	ComposeParseFailureStatus = "failure-compose-parse"
+	// FileNotFoundFailureStatus failure getting compose file
+	FileNotFoundFailureStatus = "failure-file-not-found"
+	// CommandSyntaxFailureStatus failure reading command
+	CommandSyntaxFailureStatus = "failure-cmd-syntax"
+	// BuildFailureStatus failure building imge
+	BuildFailureStatus = "failure-build"
+	// PullFailureStatus failure pulling imge
+	PullFailureStatus = "failure-pull"
+	// CanceledStatus command canceled
+	CanceledStatus = "canceled"
+)
+
+var (
+	// FileNotFoundFailure failure for compose file not found
+	FileNotFoundFailure = FailureCategory{MetricsStatus: FileNotFoundFailureStatus, ExitCode: 14}
+	// ComposeParseFailure failure for composefile parse error
+	ComposeParseFailure = FailureCategory{MetricsStatus: ComposeParseFailureStatus, ExitCode: 15}
+	// CommandSyntaxFailure failure for command line syntax
+	CommandSyntaxFailure = FailureCategory{MetricsStatus: CommandSyntaxFailureStatus, ExitCode: 16}
+	// BuildFailure failure while building images.
+	BuildFailure = FailureCategory{MetricsStatus: BuildFailureStatus, ExitCode: 17}
+	// PullFailure failure while pulling image
+	PullFailure = FailureCategory{MetricsStatus: PullFailureStatus, ExitCode: 18}
+)
+
+// FailureCategoryFromExitCode retrieve FailureCategory based on command exit code
+func FailureCategoryFromExitCode(exitCode int) FailureCategory {
+	switch exitCode {
+	case 0:
+		return FailureCategory{MetricsStatus: SuccessStatus, ExitCode: 0}
+	case 14:
+		return FileNotFoundFailure
+	case 15:
+		return ComposeParseFailure
+	case 16:
+		return CommandSyntaxFailure
+	case 17:
+		return BuildFailure
+	case 18:
+		return PullFailure
+	case 130:
+		return FailureCategory{MetricsStatus: CanceledStatus, ExitCode: exitCode}
+	default:
+		return FailureCategory{MetricsStatus: FailureStatus, ExitCode: exitCode}
+	}
+}
diff --git a/cli/metrics/metrics.go b/cli/metrics/metrics.go
index 82edfd2c..71572732 100644
--- a/cli/metrics/metrics.go
+++ b/cli/metrics/metrics.go
@@ -25,17 +25,17 @@ import (
 	"github.com/docker/compose-cli/cli/metrics/metadata"
 )
 
-func (c *client) Track(context string, args []string, status string) {
+func (c *client) Track(cmd CmdMeta) {
 	if isInvokedAsCliBackend() {
 		return
 	}
-	command := GetCommand(args)
+	command := GetCommand(cmd.Args)
 	if command != "" {
-		c.Send(Command{
+		c.SendUsage(Command{
 			Command: command,
-			Context: context,
-			Source:  c.getMetadata(CLISource, args),
-			Status:  status,
+			Context: cmd.ContextType,
+			Source:  c.getMetadata(CLISource, cmd.Args),
+			Status:  cmd.Status,
 		})
 	}
 }
diff --git a/cli/mobycli/exec.go b/cli/mobycli/exec.go
index 4b4e9abe..9d1d2046 100644
--- a/cli/mobycli/exec.go
+++ b/cli/mobycli/exec.go
@@ -27,8 +27,8 @@ import (
 	"regexp"
 	"runtime"
 	"strings"
+	"time"
 
-	"github.com/docker/compose/v2/pkg/compose"
 	"github.com/google/shlex"
 	"github.com/spf13/cobra"
 
@@ -72,21 +72,40 @@ func mustDelegateToMoby(ctxType string) bool {
 }
 
 // Exec delegates to com.docker.cli if on moby context
-func Exec(root *cobra.Command) {
+func Exec(_ *cobra.Command) {
 	metricsClient := metrics.NewDefaultClient()
 	metricsClient.WithCliVersionFunc(func() string {
 		return CliVersion()
 	})
+	start := time.Now().UTC()
 	childExit := make(chan bool)
 	err := RunDocker(childExit, os.Args[1:]...)
 	childExit <- true
+	duration := time.Since(start)
 	if err != nil {
 		if exiterr, ok := err.(*exec.ExitError); ok {
 			exitCode := exiterr.ExitCode()
-			metricsClient.Track(store.DefaultContextType, os.Args[1:], compose.ByExitCode(exitCode).MetricsStatus)
+			metricsClient.Track(
+				metrics.CmdMeta{
+					ContextType: store.DefaultContextType,
+					Args:        os.Args[1:],
+					Status:      metrics.FailureCategoryFromExitCode(exitCode).MetricsStatus,
+					ExitCode:    exitCode,
+					Start:       start,
+					Duration:    duration,
+				},
+			)
 			os.Exit(exitCode)
 		}
-		metricsClient.Track(store.DefaultContextType, os.Args[1:], compose.FailureStatus)
+		metricsClient.Track(
+			metrics.CmdMeta{
+				ContextType: store.DefaultContextType,
+				Args:        os.Args[1:],
+				Status:      metrics.FailureStatus,
+				Start:       start,
+				Duration:    duration,
+			},
+		)
 		fmt.Fprintln(os.Stderr, err)
 		os.Exit(1)
 	}
@@ -95,7 +114,16 @@ func Exec(root *cobra.Command) {
 	if command == "login" && !metrics.HasQuietFlag(commandArgs) {
 		displayPATSuggestMsg(commandArgs)
 	}
-	metricsClient.Track(store.DefaultContextType, os.Args[1:], compose.SuccessStatus)
+	metricsClient.Track(
+		metrics.CmdMeta{
+			ContextType: store.DefaultContextType,
+			Args:        os.Args[1:],
+			Status:      metrics.SuccessStatus,
+			ExitCode:    0,
+			Start:       start,
+			Duration:    duration,
+		},
+	)
 
 	os.Exit(0)
 }
diff --git a/cli/server/metrics.go b/cli/server/metrics.go
index 17881a84..683cfd36 100644
--- a/cli/server/metrics.go
+++ b/cli/server/metrics.go
@@ -19,7 +19,6 @@ package server
 import (
 	"context"
 
-	"github.com/docker/compose/v2/pkg/compose"
 	"google.golang.org/grpc"
 
 	"github.com/docker/compose-cli/cli/metrics"
@@ -61,16 +60,16 @@ func metricsServerInterceptor(client metrics.Client) grpc.UnaryServerInterceptor
 
 		data, err := handler(ctx, req)
 
-		status := compose.SuccessStatus
+		status := metrics.SuccessStatus
 		if err != nil {
-			status = compose.FailureStatus
+			status = metrics.FailureStatus
 		}
 		command := methodMapping[info.FullMethod]
 		if command != "" {
-			client.Send(metrics.Command{
+			client.SendUsage(metrics.Command{
 				Command: command,
 				Context: contextType,
-				Source:  compose.APISource,
+				Source:  metrics.APISource,
 				Status:  status,
 			})
 		}


Test patch:
diff --git a/cli/server/metrics_test.go b/cli/server/metrics_test.go
index b830e2c0..4c99e6b0 100644
--- a/cli/server/metrics_test.go
+++ b/cli/server/metrics_test.go
@@ -60,7 +60,7 @@ func TestAllMethodsHaveCorrespondingCliCommand(t *testing.T) {
 
 func TestTrackSuccess(t *testing.T) {
 	var mockMetrics = &mockMetricsClient{}
-	mockMetrics.On("Send", metrics.Command{Command: "ps", Context: "aci", Status: "success", Source: "api"}).Return()
+	mockMetrics.On("SendUsage", metrics.Command{Command: "ps", Context: "aci", Status: "success", Source: "api"}).Return()
 	newClient := client.NewClient("aci", noopService{})
 	interceptor := metricsServerInterceptor(mockMetrics)
 
@@ -126,10 +126,10 @@ func (s *mockMetricsClient) WithCliVersionFunc(f func() string) {
 	s.Called(f)
 }
 
-func (s *mockMetricsClient) Send(command metrics.Command) {
+func (s *mockMetricsClient) SendUsage(command metrics.Command) {
 	s.Called(command)
 }
 
-func (s *mockMetricsClient) Track(context string, args []string, status string) {
-	s.Called(context, args, status)
+func (s *mockMetricsClient) Track(cmd metrics.CmdMeta) {
+	s.Called(cmd)
 }