telemetry: report segment events asynchronously (#1222)

Instead of blocking the process from exiting, buffer Segment events to
disk and start another process to upload them. With this change all
telemetry should be non-blocking.

Most of the Segment event logic now lives in the telemetry package
instead of the cobra middleware. A bunch of the unused logic around
tracking CLI SSH sessions has also been removed. The telemetry package
API now looks something like:

```go
type EventName int

const (
	EventCommandSuccess EventName = iota
	EventShellInteractive
	EventShellReady
)

func Error(err error, meta Metadata)
func Event(e EventName, meta Metadata)
func Start()
func Stop()
func Upload()
```

Fixes #1003.

Author: gcurtis

internal/boxcli/log.go

@@ -27,11 +27,21 @@ func doLogCommand(cmd *cobra.Command, args []string) error {
 		return usererr.New("expect an <event-name> arg for command: %s", cmd.CommandPath())
 	}
 
-	if args[0] == "shell-ready" || args[0] == "shell-interactive" {
+	switch eventName := args[0]; eventName {
+	case "shell-ready":
 		if len(args) < 2 {
 			return usererr.New("expected a start-time argument for logging the shell-ready event")
 		}
-		return telemetry.LogShellDurationEvent(args[0] /*event name*/, args[1] /*startTime*/)
+		telemetry.Event(telemetry.EventShellReady, telemetry.Metadata{
+			CommandStart: telemetry.ParseShellStart(args[1]),
+		})
+	case "shell-interactive":
+		if len(args) < 2 {
+			return usererr.New("expected a start-time argument for logging the shell-interactive event")
+		}
+		telemetry.Event(telemetry.EventShellInteractive, telemetry.Metadata{
+			CommandStart: telemetry.ParseShellStart(args[1]),
+		})
 	}
 	return usererr.New("unrecognized event-name %s for command: %s", args[0], cmd.CommandPath())
 }

internal/boxcli/midcobra/telemetry.go

@@ -4,20 +4,15 @@
 package midcobra
 
 import (
-	"fmt"
 	"os"
 	"runtime/trace"
 	"sort"
-	"strings"
-	"time"
 
-	segment "github.com/segmentio/analytics-go"
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
 
 	"go.jetpack.io/devbox"
 	"go.jetpack.io/devbox/internal/boxcli/featureflag"
-	"go.jetpack.io/devbox/internal/build"
 	"go.jetpack.io/devbox/internal/envir"
 	"go.jetpack.io/devbox/internal/impl/devopt"
 	"go.jetpack.io/devbox/internal/telemetry"
@@ -33,24 +28,13 @@ func Telemetry() Middleware {
 	return &telemetryMiddleware{}
 }
 
-type telemetryMiddleware struct {
-	// Used during execution:
-	startTime time.Time
-}
+type telemetryMiddleware struct{}
 
 // telemetryMiddleware implements interface Middleware (compile-time check)
 var _ Middleware = (*telemetryMiddleware)(nil)
 
 func (m *telemetryMiddleware) preRun(cmd *cobra.Command, args []string) {
-	m.startTime = telemetry.CommandStartTime()
-
-	telemetry.Start(telemetry.AppDevbox)
-	ctx := cmd.Context()
-	defer trace.StartRegion(ctx, "telemetryPreRun").End()
-	if !telemetry.Enabled() {
-		trace.Log(ctx, "telemetry", "telemetry is disabled")
-		return
-	}
+	telemetry.Start()
 }
 
 func (m *telemetryMiddleware) postRun(cmd *cobra.Command, args []string, runErr error) {
@@ -74,127 +58,12 @@ func (m *telemetryMiddleware) postRun(cmd *cobra.Command, args []string, runErr
 	meta.InShell = envir.IsDevboxShellEnabled()
 	meta.InBrowser = envir.IsInBrowser()
 	meta.InCloud = envir.IsDevboxCloud()
-	telemetry.Error(runErr, meta)
-
-	if !telemetry.Enabled() {
-		return
-	}
-	evt := m.newEventIfValid(cmd, args, runErr)
-	if evt == nil {
-		return
-	}
-	m.trackEvent(evt) // Segment
-}
-
-// Consider renaming this to commandEvent
-// since it has info about the specific command run.
-type event struct {
-	telemetry.Event
-	Command       string
-	CommandArgs   []string
-	CommandError  error
-	CommandHidden bool
-	Failed        bool
-	Packages      []string
-	CommitHash    string // the nikpkgs commit hash in devbox.json
-	InDevboxShell bool
-	DevboxEnv     map[string]any // Devbox-specific environment variables
-	SentryEventID string
-	Shell         string
-}
-
-// newEventIfValid creates a new telemetry event, but returns nil if we cannot construct
-// a valid event.
-func (m *telemetryMiddleware) newEventIfValid(cmd *cobra.Command, args []string, runErr error) *event {
-	subcmd, flags, parseErr := getSubcommand(cmd, args)
-	if parseErr != nil {
-		// Ignore invalid commands
-		return nil
-	}
-
-	pkgs, hash := getPackagesAndCommitHash(cmd)
 
-	// an empty userID means that we do not have a github username saved
-	userID := telemetry.UserIDFromGithubUsername()
-
-	devboxEnv := map[string]interface{}{}
-	for _, e := range os.Environ() {
-		if strings.HasPrefix(e, "DEVBOX") && strings.Contains(e, "=") {
-			key := strings.Split(e, "=")[0]
-			devboxEnv[key] = os.Getenv(key)
-		}
-	}
-
-	return &event{
-		Event: telemetry.Event{
-			AnonymousID: telemetry.DeviceID,
-			AppName:     telemetry.AppDevbox,
-			AppVersion:  build.Version,
-			CloudRegion: os.Getenv(envir.DevboxRegion),
-			Duration:    time.Since(m.startTime),
-			OsName:      build.OS(),
-			UserID:      userID,
-		},
-		Command:      subcmd.CommandPath(),
-		CommandArgs:  flags,
-		CommandError: runErr,
-		// The command is hidden if either the top-level command is hidden or
-		// the specific sub-command that was executed is hidden.
-		CommandHidden: cmd.Hidden || subcmd.Hidden,
-		Failed:        runErr != nil,
-		Packages:      pkgs,
-		CommitHash:    hash,
-		InDevboxShell: envir.IsDevboxShellEnabled(),
-		DevboxEnv:     devboxEnv,
-		Shell:         os.Getenv(envir.Shell),
-	}
-}
-
-func (m *telemetryMiddleware) trackEvent(evt *event) {
-	if evt == nil || evt.CommandHidden {
+	if runErr != nil {
+		telemetry.Error(runErr, meta)
 		return
 	}
-
-	if evt.CommandError != nil {
-		evt.SentryEventID = telemetry.ExecutionID
-	}
-	segmentClient := telemetry.NewSegmentClient(build.TelemetryKey)
-	defer func() {
-		_ = segmentClient.Close()
-	}()
-
-	// deliberately ignore error
-	_ = segmentClient.Enqueue(segment.Identify{
-		AnonymousId: evt.AnonymousID,
-		UserId:      evt.UserID,
-	})
-
-	_ = segmentClient.Enqueue(segment.Track{ // Ignore errors, telemetry is best effort
-		AnonymousId: evt.AnonymousID, // Use device id instead
-		Event:       fmt.Sprintf("[%s] Command: %s", evt.AppName, evt.Command),
-		Context: &segment.Context{
-			Device: segment.DeviceInfo{
-				Id: evt.AnonymousID,
-			},
-			App: segment.AppInfo{
-				Name:    evt.AppName,
-				Version: evt.AppVersion,
-			},
-			OS: segment.OSInfo{
-				Name: evt.OsName,
-			},
-		},
-		Properties: segment.NewProperties().
-			Set("cloud_region", evt.CloudRegion).
-			Set("command", evt.Command).
-			Set("command_args", evt.CommandArgs).
-			Set("failed", evt.Failed).
-			Set("duration", evt.Duration.Milliseconds()).
-			Set("packages", evt.Packages).
-			Set("sentry_event_id", evt.SentryEventID).
-			Set("shell", evt.Shell),
-		UserId: evt.UserID,
-	})
+	telemetry.Event(telemetry.EventCommandSuccess, meta)
 }
 
 func getSubcommand(cmd *cobra.Command, args []string) (subcmd *cobra.Command, flags []string, err error) {

internal/boxcli/root.go

@@ -9,6 +9,7 @@ import (
 	"io"
 	"os"
 	"strings"
+	"time"
 
 	"github.com/spf13/cobra"
 
@@ -110,8 +111,14 @@ func Main() {
 		os.Exit(sshshim.Execute(ctx, os.Args))
 	}
 
-	if len(os.Args) > 1 && os.Args[1] == "bug" {
-		telemetry.ReportErrors()
+	if len(os.Args) > 1 && os.Args[1] == "upload-telemetry" {
+		// This subcommand is hidden and only run by devbox itself as a
+		// child process. We need to really make sure that we always
+		// exit and don't leave orphaned processes laying around.
+		time.AfterFunc(5*time.Second, func() {
+			os.Exit(0)
+		})
+		telemetry.Upload()
 		return
 	}
 

internal/cloud/cloud.go

@@ -445,7 +445,7 @@ func shell(username, hostname, projectDir string, shellStartTime time.Time) erro
 	cmd := &openssh.Cmd{
 		DestinationAddr: hostname,
 		PathInVM:        absoluteProjectPathInVM(username, projectPath),
-		ShellStartTime:  telemetry.UnixTimestampFromTime(shellStartTime),
+		ShellStartTime:  telemetry.FormatShellStart(shellStartTime),
 		Username:        username,
 	}
 	sessionErrors := newSSHSessionErrors()

internal/cloud/openssh/sshshim/command.go

@@ -14,7 +14,7 @@ import (
 
 func Execute(ctx context.Context, args []string) int {
 	defer debug.Recover()
-	telemetry.Start(telemetry.AppSSHShim)
+	telemetry.Start()
 	defer telemetry.Stop()
 
 	if err := execute(ctx, args); err != nil {

internal/envir/env.go

@@ -5,7 +5,6 @@ package envir
 
 const (
 	DevboxCache         = "DEVBOX_CACHE"
-	devboxCLICloudShell = "DEVBOX_CLI_CLOUD_SHELL"
 	DevboxDebug         = "DEVBOX_DEBUG"
 	DevboxFeaturePrefix = "DEVBOX_FEATURE_"
 	DevboxGateway       = "DEVBOX_GATEWAY"
@@ -21,7 +20,8 @@ const (
 	LauncherVersion = "LAUNCHER_VERSION"
 	LauncherPath    = "LAUNCHER_PATH"
 
-	SSHTTY = "SSH_TTY"
+	GitHubUsername = "GITHUB_USER_NAME"
+	SSHTTY         = "SSH_TTY"
 
 	XDGDataHome   = "XDG_DATA_HOME"
 	XDGConfigHome = "XDG_CONFIG_HOME"

internal/envir/util.go

@@ -8,11 +8,6 @@ import (
 	"strconv"
 )
 
-func IsCLICloudShell() bool { // TODO: not used any more
-	cliCloudShell, _ := strconv.ParseBool(os.Getenv(devboxCLICloudShell))
-	return cliCloudShell
-}
-
 func IsDevboxCloud() bool {
 	return os.Getenv(DevboxRegion) != ""
 }

internal/impl/devbox.go

@@ -22,6 +22,7 @@ import (
 	"go.jetpack.io/devbox/internal/boxcli/featureflag"
 	"go.jetpack.io/devbox/internal/impl/generate"
 	"go.jetpack.io/devbox/internal/shellgen"
+	"go.jetpack.io/devbox/internal/telemetry"
 	"golang.org/x/exp/slices"
 
 	"go.jetpack.io/devbox/internal/boxcli/usererr"
@@ -39,7 +40,6 @@ import (
 	"go.jetpack.io/devbox/internal/redact"
 	"go.jetpack.io/devbox/internal/searcher"
 	"go.jetpack.io/devbox/internal/services"
-	"go.jetpack.io/devbox/internal/telemetry"
 	"go.jetpack.io/devbox/internal/ux"
 	"go.jetpack.io/devbox/internal/wrapnix"
 )
@@ -185,18 +185,13 @@ func (d *Devbox) Shell(ctx context.Context) error {
 		return err
 	}
 
-	shellStartTime := envir.GetValueOrDefault(
-		envir.DevboxShellStartTime,
-		telemetry.UnixTimestampFromTime(telemetry.CommandStartTime()),
-	)
-
 	opts := []ShellOption{
 		WithHooksFilePath(shellgen.ScriptPath(d.ProjectDir(), shellgen.HooksFilename)),
 		WithProfile(profileDir),
 		WithHistoryFile(filepath.Join(d.projectDir, shellHistoryFile)),
 		WithProjectDir(d.projectDir),
 		WithEnvVariables(envs),
-		WithShellStartTime(shellStartTime),
+		WithShellStartTime(telemetry.ShellStart()),
 	}
 
 	shell, err := NewDevboxShell(d, opts...)
@@ -985,7 +980,6 @@ func (d *Devbox) checkOldEnvrc() error {
 					"Run `devbox generate direnv --force` to update it.\n"+
 					"Or silence this warning by setting DEVBOX_NO_ENVRC_UPDATE=1 env variable.\n",
 			)
-
 		}
 	}
 	return nil
@@ -1058,7 +1052,6 @@ func (d *Devbox) setCommonHelperEnvVars(env map[string]string) {
 // buildInputs
 func (d *Devbox) NixBins(ctx context.Context) ([]string, error) {
 	env, err := d.nixEnv(ctx)
-
 	if err != nil {
 		return nil, err
 	}
@@ -1132,7 +1125,6 @@ func (d *Devbox) parseEnvAndExcludeSpecialCases(currentEnv []string) (map[string
 
 // ExportifySystemPathWithoutWrappers is a small utility to filter WrapperBin paths from PATH
 func ExportifySystemPathWithoutWrappers() string {
-
 	path := []string{}
 	for _, p := range strings.Split(os.Getenv("PATH"), string(filepath.ListSeparator)) {
 		// Intentionally do not include projectDir with plugin.WrapperBinPath so that

internal/impl/shell.go

@@ -13,11 +13,13 @@ import (
 	"path/filepath"
 	"strings"
 	"text/template"
+	"time"
 
 	"github.com/alessio/shellescape"
 	"github.com/pkg/errors"
 	"go.jetpack.io/devbox/internal/boxcli/featureflag"
 	"go.jetpack.io/devbox/internal/shenv"
+	"go.jetpack.io/devbox/internal/telemetry"
 
 	"go.jetpack.io/devbox/internal/debug"
 	"go.jetpack.io/devbox/internal/envir"
@@ -65,7 +67,7 @@ type DevboxShell struct {
 	historyFile string
 
 	// shellStartTime is the unix timestamp for when the command was invoked
-	shellStartTime string
+	shellStartTime time.Time
 }
 
 type ShellOption func(*DevboxShell)
@@ -197,9 +199,9 @@ func WithProjectDir(projectDir string) ShellOption {
 	}
 }
 
-func WithShellStartTime(time string) ShellOption {
+func WithShellStartTime(t time.Time) ShellOption {
 	return func(s *DevboxShell) {
-		s.shellStartTime = time
+		s.shellStartTime = t
 	}
 }
 
@@ -331,7 +333,7 @@ func (s *DevboxShell) writeDevboxShellrc() (path string, err error) {
 		OriginalInitPath:  s.userShellrcPath,
 		HooksFilePath:     s.hooksFilePath,
 		ShellName:         string(s.name),
-		ShellStartTime:    s.shellStartTime,
+		ShellStartTime:    telemetry.FormatShellStart(s.shellStartTime),
 		HistoryFile:       strings.TrimSpace(s.historyFile),
 		ExportEnv:         exportify(s.env),
 		PromptHookEnabled: featureflag.PromptHook.Enabled(),