Merge pull request #2225 from milas/metrics-duration

metrics: initial logic for command execution duration

Author: milas

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:], metrics.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,33 +285,64 @@ 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:], metrics.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 {
 		// TODO(milas): shouldn't this use the exit code to determine status?
-		metricsClient.Track(ctype, os.Args[1:], metrics.SuccessStatus)
+		metricsClient.Track(
+			metrics.CmdMeta{
+				ContextType: ctype,
+				Args:        os.Args[1:],
+				Status:      metrics.SuccessStatus,
+				Start:       start,
+				Duration:    duration,
+			},
+		)
 		os.Exit(exit.StatusCode)
 	}
 
@@ -316,7 +357,15 @@ func exit(ctx string, err error, ctype string) {
 		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)
@@ -351,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:], metrics.FailureStatus)
+			metricsClient.Track(metrics.CmdMeta{
+				ContextType: contextType,
+				Args:        os.Args[1:],
+				Status:      metrics.FailureStatus,
+			})
 			os.Exit(1)
 		}
 	}

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
@@ -62,7 +71,7 @@ type Client interface {
 	// 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(context string, args []string, status string)
+	Track(cmd CmdMeta)
 }
 
 // NewClient returns a new metrics client that will send metrics using the

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.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,
 		})
 	}
 }

cli/mobycli/exec.go

@@ -27,6 +27,7 @@ import (
 	"regexp"
 	"runtime"
 	"strings"
+	"time"
 
 	"github.com/google/shlex"
 	"github.com/spf13/cobra"
@@ -76,20 +77,35 @@ func Exec(_ *cobra.Command) {
 	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:],
-				metrics.FailureCategoryFromExitCode(exitCode).MetricsStatus,
+				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:], metrics.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)
 	}
@@ -98,7 +114,16 @@ func Exec(_ *cobra.Command) {
 	if command == "login" && !metrics.HasQuietFlag(commandArgs) {
 		displayPATSuggestMsg(commandArgs)
 	}
-	metricsClient.Track(store.DefaultContextType, os.Args[1:], metrics.SuccessStatus)
+	metricsClient.Track(
+		metrics.CmdMeta{
+			ContextType: store.DefaultContextType,
+			Args:        os.Args[1:],
+			Status:      metrics.SuccessStatus,
+			ExitCode:    0,
+			Start:       start,
+			Duration:    duration,
+		},
+	)
 
 	os.Exit(0)
 }

cli/server/metrics_test.go

@@ -130,6 +130,6 @@ 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)
 }