Add Metrics (#609)

Adds metrics from https://github.com/abcxyz/abc-updater

See updates to README.md for more information.

README.md

@@ -1281,3 +1281,24 @@ with a list of versions and constraints `ABC_IGNORE_VERSIONS=<2.0.0,3.5.0`.
 
 This check is not done on non-release builds, as they don't have canonical
 version to check against.
+
+## Metrics
+Google collects usage statics. No identifible data is collected.
+Mtrics are collected using [abcxyz/abc-updater](https://github.com/abcxyz/abc-updater).
+
+Currently, data is collected on:
+- Count of total invocations
+- Count of each sub-command (render, describe, upgrade, ect)
+- Count of invocations running in panic
+- Runtime in ms of each invocation
+
+Along with each metric, the following metadata is recorded:
+- Application version
+- Installation time with minute granularity
+
+Metrics data is retained for 24 months.
+
+You can **opt-out** of collection by setting the following environment variable:
+```shell
+ABC_NO_METRICS=TRUE
+```

cmd/abc/abc.go

@@ -28,7 +28,9 @@ import (
 
 	"golang.org/x/sys/unix"
 
+	"github.com/abcxyz/abc-updater/pkg/metrics"
 	"github.com/abcxyz/abc-updater/pkg/updater"
+	"github.com/abcxyz/abc/internal/metricswrap"
 	"github.com/abcxyz/abc/internal/version"
 	"github.com/abcxyz/abc/templates/commands/describe"
 	"github.com/abcxyz/abc/templates/commands/goldentest"
@@ -43,6 +45,11 @@ import (
 const (
 	defaultLogLevel  = logging.LevelWarning
 	defaultLogFormat = logging.FormatText
+	// Long since only runs once every 24 hours.
+	updateTimeout = time.Second
+	// Shorter since nothing can be done in parallel due to it starting after
+	// program logic finishes.
+	runtimeMetricsTimeout = 200 * time.Millisecond
 )
 
 var templateCommands = map[string]cli.CommandFactory{
@@ -136,32 +143,62 @@ func setLogEnvVars() {
 	}
 }
 
+func checkVersion(ctx context.Context) func() {
+	// Only check for updates if not built from HEAD.
+	if version.Version == "source" {
+		return func() {}
+	}
+	updaterCtx, updaterDone := context.WithTimeout(ctx, updateTimeout)
+	results := updater.CheckAppVersionAsync(updaterCtx, &updater.CheckVersionParams{
+		AppID:   version.Name,
+		Version: version.Version,
+	})
+	return func() {
+		defer updaterDone()
+		logger := logging.FromContext(ctx)
+		if msg, err := results(); err != nil {
+			// Debug log since not necessarily actionable.
+			logger.DebugContext(ctx, "failed to check for updates", "err", err.Error())
+		} else if msg != "" {
+			logger.InfoContext(ctx, fmt.Sprintf("\n%s\n", msg))
+		}
+	}
+}
+
 func realMain(ctx context.Context) error {
+	start := time.Now()
 	if err := checkSupportedOS(); err != nil {
 		return err
 	}
 
-	// Only check for updates if not built from HEAD.
-	if version.Version != "source" {
-		// Timeout updater after 1 second.
-		updaterCtx, updaterDone := context.WithTimeout(ctx, time.Second)
-		defer updaterDone()
-		results := updater.CheckAppVersionAsync(updaterCtx, &updater.CheckVersionParams{
-			AppID:   version.Name,
-			Version: version.Version,
-		})
-
-		defer func() {
-			message, err := results()
-			if err != nil {
-				logger := logging.FromContext(ctx)
-				logger.InfoContext(ctx, "failed to check for new versions", "error", err)
-				return
-			}
-			fmt.Fprintf(os.Stderr, "\n%s\n", message)
-		}()
+	updateResult := checkVersion(ctx)
+	defer updateResult()
+
+	mClient, err := metrics.New(ctx, version.Name, version.Version)
+	if err != nil {
+		fmt.Printf("metric client creation failed: %v\n", err)
 	}
 
+	ctx = metrics.WithClient(ctx, mClient)
+	defer func() {
+		if r := recover(); r != nil {
+			handler := metricswrap.WriteMetric(ctx, mClient, "panics", 1)
+			defer handler()
+			panic(r)
+		}
+	}()
+
+	cleanup := metricswrap.WriteMetric(ctx, mClient, "runs", 1)
+	defer cleanup()
+
+	runtimeCtx, closer := context.WithTimeout(ctx, runtimeMetricsTimeout)
+	defer closer()
+	// TODO: This will cause a synchronous metrics call, may be way too slow.
+	defer func() {
+		cleanup := metricswrap.WriteMetric(runtimeCtx, mClient, "runtime_millis", time.Since(start).Milliseconds())
+		defer cleanup()
+	}()
+
 	return rootCmd().Run(ctx, os.Args[1:]) //nolint:wrapcheck
 }
 
@@ -182,12 +219,12 @@ func checkSupportedOS() error {
 }
 
 func checkDarwinVersion(utsRelease string) error {
-	// We support Mac OS 13 and newer, which corresponds to Darwin kernel
+	// We support macOS 13 and newer, which corresponds to Darwin kernel
 	// version 22 and newer. The mappings from macOS version to Darwin
 	// version are taken from
 	// https://en.wikipedia.org/wiki/Darwin_(operating_system)#Release_history.
 	// Regrettably, the unix.Uname() function only gives darwin version, not
-	// macos version.
+	// macOS version.
 	const (
 		// These two must match. Whenever one is changed, the other must
 		// also be changed to match.

go.mod

@@ -6,7 +6,7 @@ toolchain go1.22.1
 
 require (
 	github.com/Masterminds/semver/v3 v3.2.1
-	github.com/abcxyz/abc-updater v0.2.0
+	github.com/abcxyz/abc-updater v0.3.0
 	github.com/abcxyz/pkg v1.1.1
 	github.com/acarl005/stripansi v0.0.0-20180116102854-5a71ef0e047d
 	github.com/alessio/shellescape v1.4.2

go.sum

@@ -1,7 +1,7 @@
 github.com/Masterminds/semver/v3 v3.2.1 h1:RN9w6+7QoMeJVGyfmbcgs28Br8cvmnucEXnY0rYXWg0=
 github.com/Masterminds/semver/v3 v3.2.1/go.mod h1:qvl/7zhW3nngYb5+80sSMF+FG2BjYrf8m9wsX0PNOMQ=
-github.com/abcxyz/abc-updater v0.2.0 h1:uF4LbQVxDjewk0NKZseJaQgecrVFTQDXxuvsF2rFEs8=
-github.com/abcxyz/abc-updater v0.2.0/go.mod h1:t8QKGyq682NiuXeNGfbXaMl1jisYrSd7wV55nMm9uvM=
+github.com/abcxyz/abc-updater v0.3.0 h1:34cCQia6NUDCTvQ0Pz3HIXyQjC59o5c6iCrzQgAwC24=
+github.com/abcxyz/abc-updater v0.3.0/go.mod h1:t8QKGyq682NiuXeNGfbXaMl1jisYrSd7wV55nMm9uvM=
 github.com/abcxyz/pkg v1.1.1 h1:y0IfzdZrZT355EYQA8amE5c/PUsA86gw6SzqxeSAz2I=
 github.com/abcxyz/pkg v1.1.1/go.mod h1:oNJANNMDik+8WfOc8lgHSMdGn1+e/62VBrc25VN5cAM=
 github.com/acarl005/stripansi v0.0.0-20180116102854-5a71ef0e047d h1:licZJFw2RwpHMqeKTCYkitsPqHNxTmd4SNR5r94FGM8=

internal/metricswrap/metrics.go

@@ -0,0 +1,47 @@
+// Copyright 2024 The Authors (see AUTHORS file)
+//
+// 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 metricswrap
+
+import (
+	"context"
+	"time"
+
+	"github.com/abcxyz/abc-updater/pkg/metrics"
+	"github.com/abcxyz/pkg/logging"
+)
+
+// A little on the long side to tolerate cold starts. Metrics run concurrently
+// so users will see at most 500ms runtime from this in most cases.
+const defaultMetricsTimeout = 500 * time.Millisecond
+
+// WriteMetric is an async wrapper for metrics.WriteMetric.
+// It returns a function that blocks on completion and handles any errors.
+func WriteMetric(ctx context.Context, client *metrics.Client, name string, count int64) func() {
+	ctx, done := context.WithTimeout(ctx, defaultMetricsTimeout)
+	errCh := make(chan error, 1)
+	go func() {
+		defer done()
+		defer close(errCh)
+		errCh <- client.WriteMetric(ctx, name, count)
+	}()
+
+	return func() {
+		err := <-errCh
+		if err != nil {
+			logger := logging.FromContext(ctx)
+			logger.DebugContext(ctx, "Metric writing failed.", "err", err)
+		}
+	}
+}

templates/commands/describe/describe.go

@@ -24,6 +24,8 @@ import (
 	"github.com/posener/complete/v2"
 	"github.com/posener/complete/v2/predict"
 
+	"github.com/abcxyz/abc-updater/pkg/metrics"
+	"github.com/abcxyz/abc/internal/metricswrap"
 	"github.com/abcxyz/abc/templates/common"
 	"github.com/abcxyz/abc/templates/common/specutil"
 	"github.com/abcxyz/abc/templates/common/tempdir"
@@ -80,6 +82,10 @@ type runParams struct {
 }
 
 func (c *Command) Run(ctx context.Context, args []string) error {
+	mClient := metrics.FromContext(ctx)
+	cleanup := metricswrap.WriteMetric(ctx, mClient, "command_describe", 1)
+	defer cleanup()
+
 	if err := c.Flags().Parse(args); err != nil {
 		return fmt.Errorf("failed to parse flags: %w", err)
 	}

templates/commands/goldentest/new_test_cli.go

@@ -28,6 +28,8 @@ import (
 	"github.com/posener/complete/v2/predict"
 	"gopkg.in/yaml.v3"
 
+	"github.com/abcxyz/abc-updater/pkg/metrics"
+	"github.com/abcxyz/abc/internal/metricswrap"
 	"github.com/abcxyz/abc/internal/version"
 	"github.com/abcxyz/abc/templates/common"
 	"github.com/abcxyz/abc/templates/common/builtinvar"
@@ -79,6 +81,10 @@ func (c *NewTestCommand) PredictArgs() complete.Predictor {
 func (c *NewTestCommand) Run(ctx context.Context, args []string) (rErr error) {
 	logger := logging.FromContext(ctx)
 
+	mClient := metrics.FromContext(ctx)
+	cleanup := metricswrap.WriteMetric(ctx, mClient, "command_goldentest_new", 1)
+	defer cleanup()
+
 	if err := c.Flags().Parse(args); err != nil {
 		return fmt.Errorf("failed to parse flags: %w", err)
 	}

templates/commands/goldentest/record.go

@@ -28,6 +28,8 @@ import (
 	"github.com/posener/complete/v2"
 	"github.com/posener/complete/v2/predict"
 
+	"github.com/abcxyz/abc-updater/pkg/metrics"
+	"github.com/abcxyz/abc/internal/metricswrap"
 	"github.com/abcxyz/abc/templates/common"
 	"github.com/abcxyz/abc/templates/common/tempdir"
 	"github.com/abcxyz/pkg/cli"
@@ -75,6 +77,10 @@ func (c *RecordCommand) PredictArgs() complete.Predictor {
 }
 
 func (c *RecordCommand) Run(ctx context.Context, args []string) error {
+	mClient := metrics.FromContext(ctx)
+	cleanup := metricswrap.WriteMetric(ctx, mClient, "command_goldentest_record", 1)
+	defer cleanup()
+
 	if err := c.Flags().Parse(args); err != nil {
 		return fmt.Errorf("failed to parse flags: %w", err)
 	}

templates/commands/goldentest/verify.go

@@ -34,6 +34,8 @@ import (
 	"github.com/posener/complete/v2"
 	"github.com/posener/complete/v2/predict"
 
+	"github.com/abcxyz/abc-updater/pkg/metrics"
+	"github.com/abcxyz/abc/internal/metricswrap"
 	"github.com/abcxyz/abc/templates/common"
 	"github.com/abcxyz/abc/templates/common/run"
 	"github.com/abcxyz/abc/templates/common/tempdir"
@@ -81,6 +83,10 @@ func (c *VerifyCommand) PredictArgs() complete.Predictor {
 }
 
 func (c *VerifyCommand) Run(ctx context.Context, args []string) (rErr error) {
+	mClient := metrics.FromContext(ctx)
+	cleanup := metricswrap.WriteMetric(ctx, mClient, "command_goldentest_verify", 1)
+	defer cleanup()
+
 	if err := c.Flags().Parse(args); err != nil {
 		return fmt.Errorf("failed to parse flags: %w", err)
 	}

templates/commands/render/render.go

@@ -29,6 +29,8 @@ import (
 	"github.com/posener/complete/v2"
 	"github.com/posener/complete/v2/predict"
 
+	"github.com/abcxyz/abc-updater/pkg/metrics"
+	"github.com/abcxyz/abc/internal/metricswrap"
 	"github.com/abcxyz/abc/templates/common"
 	"github.com/abcxyz/abc/templates/common/render"
 	"github.com/abcxyz/abc/templates/common/templatesource"
@@ -80,6 +82,10 @@ func (c *Command) PredictArgs() complete.Predictor {
 }
 
 func (c *Command) Run(ctx context.Context, args []string) error {
+	mClient := metrics.FromContext(ctx)
+	cleanup := metricswrap.WriteMetric(ctx, mClient, "command_render", 1)
+	defer cleanup()
+
 	if err := c.Flags().Parse(args); err != nil {
 		return fmt.Errorf("failed to parse flags: %w", err)
 	}

templates/commands/upgrade/upgrade.go

@@ -26,6 +26,8 @@ import (
 	"github.com/posener/complete/v2"
 	"github.com/posener/complete/v2/predict"
 
+	"github.com/abcxyz/abc-updater/pkg/metrics"
+	"github.com/abcxyz/abc/internal/metricswrap"
 	"github.com/abcxyz/abc/templates/common"
 	"github.com/abcxyz/abc/templates/common/upgrade"
 	"github.com/abcxyz/pkg/cli"
@@ -123,6 +125,10 @@ To resolve this conflict, please manually apply the rejected hunks in the given
 )
 
 func (c *Command) Run(ctx context.Context, args []string) error {
+	mClient := metrics.FromContext(ctx)
+	cleanup := metricswrap.WriteMetric(ctx, mClient, "command_upgrade", 1)
+	defer cleanup()
+
 	if err := c.Flags().Parse(args); err != nil {
 		return fmt.Errorf("failed to parse flags: %w", err)
 	}