perf(telemetry): reuse opened project, cache device ID, throttle uploads

internal/boxcli/midcobra/telemetry.go

@@ -12,7 +12,6 @@ import (
 	"github.com/spf13/pflag"
 	"go.jetify.com/devbox/internal/boxcli/featureflag"
 	"go.jetify.com/devbox/internal/devbox"
-	"go.jetify.com/devbox/internal/devbox/devopt"
 	"go.jetify.com/devbox/internal/envir"
 	"go.jetify.com/devbox/internal/telemetry"
 )
@@ -40,6 +39,10 @@ func (m *telemetryMiddleware) postRun(cmd *cobra.Command, args []string, runErr
 	defer trace.StartRegion(cmd.Context(), "telemetryPostRun").End()
 	defer telemetry.Stop()
 
+	if !telemetry.Enabled() {
+		return
+	}
+
 	meta := telemetry.Metadata{
 		FeatureFlags: featureflag.All(),
 		CloudRegion:  os.Getenv(envir.DevboxRegion),
@@ -54,7 +57,7 @@ func (m *telemetryMiddleware) postRun(cmd *cobra.Command, args []string, runErr
 	meta.Command = subcmd.CommandPath()
 	meta.CommandFlags = flags
 
-	meta.Packages, meta.NixpkgsHash = getPackagesAndCommitHash(subcmd)
+	meta.Packages, meta.NixpkgsHash = getPackagesAndCommitHash()
 	meta.InShell = envir.IsDevboxShellEnabled()
 	meta.InBrowser = envir.IsInBrowser()
 	meta.InCloud = envir.IsDevboxCloud()
@@ -81,28 +84,15 @@ func getSubcommand(cmd *cobra.Command, args []string) (subcmd *cobra.Command, fl
 	return subcmd, flags, err
 }
 
-func getPackagesAndCommitHash(c *cobra.Command) ([]string, string) {
-	configFlag := c.Flag("config")
-	// for shell, run, and add command, path can be set via --config
-	// if --config is not set, default to current directory which is ""
-	// the only exception is the init command, for the path can be set with args
-	// since after running init there will be no packages set in devbox.json
-	// we can safely ignore this case.
-	var path string
-	if configFlag != nil {
-		path = configFlag.Value.String()
-	}
-
-	box, err := devbox.Open(&devopt.Opts{
-		Dir:              path,
-		Stderr:           os.Stderr,
-		IgnoreWarnings:   true,
-		SkipVersionCheck: true,
-	})
-	if err != nil {
+// getPackagesAndCommitHash returns the packages and nixpkgs commit of the
+// project that the command opened. It reuses the already-opened project instead
+// of opening it again, which would re-parse the config and reload plugins.
+// Commands that don't open a project report no packages.
+func getPackagesAndCommitHash() ([]string, string) {
+	box := devbox.LastOpened()
+	if box == nil {
 		return []string{}, ""
 	}
-
 	return box.AllPackageNamesIncludingRemovedTriggerPackages(),
 		box.Lockfile().Stdenv().Rev
 }

internal/boxcli/midcobra/telemetry_test.go

@@ -3,7 +3,6 @@ package midcobra
 import (
 	"testing"
 
-	"github.com/spf13/cobra"
 	"go.jetify.com/devbox/internal/devbox"
 	"go.jetify.com/devbox/internal/devbox/devopt"
 )
@@ -17,30 +16,17 @@ func TestGetPackagesAndCommitHash(t *testing.T) {
 	box, err := devbox.Open(&devopt.Opts{
 		Dir: dir,
 	})
-	// Create a mock cobra command
-	cmd := &cobra.Command{
-		Use: "test",
-		Run: func(cmd *cobra.Command, args []string) {},
-	}
-
-	// Add a mock flag to the command
-	cmd.Flags().String("config", "", "config file")
-	if err := cmd.Flags().Set("config", dir); err != nil {
-		t.Errorf("Expected no error, got %s", err)
+	if err != nil {
+		t.Fatalf("Expected no error, got %s", err)
 	}
 
-	// Call the function with the mock command
-	packages, commitHash := getPackagesAndCommitHash(cmd)
+	packages, commitHash := getPackagesAndCommitHash()
 
 	// Check if the returned packages and commitHash are as expected
 	if len(packages) != 0 {
 		t.Errorf("Expected no packages, got %d", len(packages))
 	}
 
-	if err != nil {
-		t.Errorf("Expected no error, got %s", err)
-	}
-
 	if commitHash != box.Lockfile().Stdenv().Rev {
 		t.Errorf("Expected commitHash %s, got %s", box.Lockfile().Stdenv().Rev, commitHash)
 	}

internal/devbox/devbox.go

@@ -18,6 +18,7 @@ import (
 	"slices"
 	"strconv"
 	"strings"
+	"sync/atomic"
 	"time"
 
 	"github.com/briandowns/spinner"
@@ -76,6 +77,16 @@ type Devbox struct {
 
 var legacyPackagesWarningHasBeenShown = false
 
+// lastOpened is the project most recently returned by Open. Telemetry reads it
+// after a command runs so that it doesn't have to open the project again.
+var lastOpened atomic.Pointer[Devbox]
+
+// LastOpened returns the project most recently returned by Open, or nil if
+// this process hasn't opened one.
+func LastOpened() *Devbox {
+	return lastOpened.Load()
+}
+
 func InitConfig(dir string) error {
 	_, err := devconfig.Init(dir)
 	return err
@@ -185,6 +196,7 @@ func Open(opts *devopt.Opts) (*Devbox, error) {
 		)
 	}
 
+	lastOpened.Store(box)
 	return box, nil
 }
 

internal/telemetry/telemetry.go

@@ -51,7 +51,20 @@ var (
 	// procStartTime records the start time of the current process.
 	procStartTime = time.Now()
 	needsFlush    atomic.Bool
-	started       bool
+	// uploadNow skips upload throttling. It's set when an error is buffered
+	// so that errors are reported promptly.
+	uploadNow atomic.Bool
+	started   bool
+)
+
+const (
+	// uploadInterval is the minimum time between spawning upload processes.
+	// Events are buffered on disk in the meantime.
+	uploadInterval = 30 * time.Minute
+
+	// uploadThreshold is the number of buffered events that triggers an
+	// upload before uploadInterval has passed.
+	uploadThreshold = 50
 )
 
 // Start enables telemetry for the current program.
@@ -60,12 +73,33 @@ func Start() {
 		return
 	}
 
-	const deviceSalt = "64ee464f-9450-4b14-8d9c-014c0012ac1a"
-	deviceID, _ = machineid.ProtectedID(deviceSalt)
-
+	deviceID = loadDeviceID()
 	started = true
 }
 
+// Enabled reports whether telemetry was started for the current program.
+func Enabled() bool {
+	return started
+}
+
+// loadDeviceID returns the device ID cached in the state dir, computing and
+// caching it if needed. Computing it is slow on macOS because it runs ioreg.
+func loadDeviceID() string {
+	if data, err := os.ReadFile(deviceIDFile); err == nil {
+		if id := strings.TrimSpace(string(data)); id != "" {
+			return id
+		}
+	}
+
+	const deviceSalt = "64ee464f-9450-4b14-8d9c-014c0012ac1a"
+	id, err := machineid.ProtectedID(deviceSalt)
+	if err != nil {
+		return ""
+	}
+	_ = writeStateFile(deviceIDFile, []byte(id))
+	return id
+}
+
 func userID() string {
 	if username := os.Getenv(envir.GitHubUsername); username != "" {
 		const uidSalt = "d6134cd5-347d-4b7c-a2d0-295c0f677948"
@@ -78,18 +112,58 @@ func userID() string {
 	return ""
 }
 
-// Stop stops gathering telemetry and flushes buffered events to disk.
+// Stop stops gathering telemetry and, if it's time for an upload, uploads
+// buffered events in a separate process.
 func Stop() {
 	if !started || !needsFlush.Load() {
 		return
 	}
+	started = false
+	if !shouldUpload() {
+		return
+	}
+
+	// Record the upload time before spawning so that other commands running
+	// at the same time don't also spawn an uploader.
+	_ = writeStateFile(lastUploadFile, []byte(strconv.FormatInt(time.Now().Unix(), 10)))
 
 	// Report errors in a separate process so we don't block exiting.
 	exe, err := os.Executable()
 	if err == nil {
 		_ = exec.Command(exe, "upload-telemetry").Start()
 	}
-	started = false
+}
+
+// shouldUpload reports whether buffered events should be uploaded now. Uploads
+// happen at most once per uploadInterval unless an error was reported or
+// there are at least uploadThreshold buffered events.
+func shouldUpload() bool {
+	if uploadNow.Load() {
+		return true
+	}
+	data, err := os.ReadFile(lastUploadFile)
+	if err != nil {
+		return true
+	}
+	lastUpload, err := strconv.ParseInt(strings.TrimSpace(string(data)), 10, 64)
+	if err != nil {
+		return true
+	}
+	// A last upload time in the future means the clock changed, so don't
+	// trust it.
+	if age := time.Since(time.Unix(lastUpload, 0)); age < 0 || age >= uploadInterval {
+		return true
+	}
+	return bufferedEventCount() >= uploadThreshold
+}
+
+func bufferedEventCount() int {
+	count := 0
+	for _, dir := range []string{segmentBufferDir, sentryBufferDir} {
+		entries, _ := os.ReadDir(dir)
+		count += len(entries)
+	}
+	return count
 }
 
 func Event(e EventName, meta Metadata) {
@@ -132,7 +206,10 @@ func Error(err error, meta Metadata) {
 	nixVersion := cmp.Or(nix.Version(), "unknown")
 
 	event := &sentry.Event{
-		EventID:   sentry.EventID(ExecutionID),
+		EventID: sentry.EventID(ExecutionID),
+		// Uploads are throttled, so record when the error happened rather
+		// than when it's uploaded.
+		Timestamp: time.Now(),
 		Level:     sentry.LevelError,
 		User:      sentry.User{ID: deviceID},
 		Exception: newSentryException(redact.Error(errToLog)),
@@ -174,6 +251,7 @@ func Error(err error, meta Metadata) {
 		event.User.ID = uid
 	}
 	bufferSentryEvent(event)
+	uploadNow.Store(true)
 
 	msgID, msg := commandEvent(meta)
 	msg.Properties["failed"] = true
@@ -258,6 +336,9 @@ func (m *Metadata) pkgContext() map[string]any {
 var (
 	sentryBufferDir  = xdg.StateSubpath(filepath.FromSlash("devbox/sentry"))
 	segmentBufferDir = xdg.StateSubpath(filepath.FromSlash("devbox/segment"))
+
+	deviceIDFile   = xdg.StateSubpath(filepath.FromSlash("devbox/telemetry/device-id"))
+	lastUploadFile = xdg.StateSubpath(filepath.FromSlash("devbox/telemetry/last-upload"))
 )
 
 func Upload() {
@@ -326,18 +407,23 @@ func bufferEvent(file string, event any) {
 	if err != nil {
 		return
 	}
+	if writeStateFile(file, data) == nil {
+		needsFlush.Store(true)
+	}
+}
 
-	err = os.WriteFile(file, data, 0o600)
+// writeStateFile writes data to a file in the XDG state dir, creating its
+// parent directory if needed.
+func writeStateFile(file string, data []byte) error {
+	err := os.WriteFile(file, data, 0o600)
 	if errors.Is(err, fs.ErrNotExist) {
 		// XDG specifies perms 0700.
 		if err := os.MkdirAll(filepath.Dir(file), 0o700); err != nil {
-			return
+			return err
 		}
 		err = os.WriteFile(file, data, 0o600)
 	}
-	if err == nil {
-		needsFlush.Store(true)
-	}
+	return err
 }
 
 func newEventID() string {