From aa357cc14dca7e5c658c5836b349688e3d7ca659 Mon Sep 17 00:00:00 2001 From: Mike Landau Date: Sun, 25 Oct 2026 14:34:58 -0700 Subject: [PATCH 1/2] perf(telemetry): reuse opened project, cache device ID, throttle uploads - Skip the telemetry post-run hook entirely when telemetry is disabled. - Reuse the project the command already opened instead of calling devbox.Open a second time after every command. This also drops the broken --config lookup, which was done on the root command and so never found the flag. - Cache the device ID in the XDG state dir. Computing it runs ioreg on macOS (~20ms). - Only spawn the `upload-telemetry` process at most every 30 minutes, unless an error was reported or 50+ events are buffered. Sentry events now record their own timestamp since they may be uploaded later. Co-Authored-By: Claude Opus 5.5 (1M context) --- internal/boxcli/midcobra/telemetry.go | 34 +++---- internal/boxcli/midcobra/telemetry_test.go | 20 +--- internal/devbox/devbox.go | 12 +++ internal/telemetry/telemetry.go | 110 ++++++++++++++++++--- internal/telemetry/telemetry_test.go | 107 +++++++++++++++++++- 5 files changed, 230 insertions(+), 53 deletions(-) diff --git a/internal/boxcli/midcobra/telemetry.go b/internal/boxcli/midcobra/telemetry.go index 77670974383..44d493e9115 100644 --- a/internal/boxcli/midcobra/telemetry.go +++ b/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 } diff --git a/internal/boxcli/midcobra/telemetry_test.go b/internal/boxcli/midcobra/telemetry_test.go index fb436c23a98..159e43f74f4 100644 --- a/internal/boxcli/midcobra/telemetry_test.go +++ b/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) } diff --git a/internal/devbox/devbox.go b/internal/devbox/devbox.go index 351ed7ba143..de72a7bf7cd 100644 --- a/internal/devbox/devbox.go +++ b/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 } diff --git a/internal/telemetry/telemetry.go b/internal/telemetry/telemetry.go index 87f409914a9..7081d6591b7 100644 --- a/internal/telemetry/telemetry.go +++ b/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 { diff --git a/internal/telemetry/telemetry_test.go b/internal/telemetry/telemetry_test.go index 97524376a10..43ec66e66c2 100644 --- a/internal/telemetry/telemetry_test.go +++ b/internal/telemetry/telemetry_test.go @@ -2,18 +2,121 @@ package telemetry import ( "errors" + "os" + "path/filepath" + "strconv" "testing" + "time" ) // TestErrorBasic does a very simple sanity check to ensure the error can be sent // to the sentry and segment buffers func TestErrorBasic(t *testing.T) { - segmentBufferDir = t.TempDir() - sentryBufferDir = t.TempDir() + setTestStateDir(t) started = true fakeErr := errors.New("fake error") meta := Metadata{} Error(fakeErr, meta) + if !uploadNow.Load() { + t.Error("Error didn't request an immediate upload") + } +} + +func setTestStateDir(t *testing.T) { + t.Helper() + dir := t.TempDir() + segmentBufferDir = filepath.Join(dir, "segment") + sentryBufferDir = filepath.Join(dir, "sentry") + deviceIDFile = filepath.Join(dir, "telemetry", "device-id") + lastUploadFile = filepath.Join(dir, "telemetry", "last-upload") + uploadNow.Store(false) + t.Cleanup(func() { uploadNow.Store(false) }) +} + +func TestLoadDeviceIDCached(t *testing.T) { + setTestStateDir(t) + + if err := writeStateFile(deviceIDFile, []byte("cached-id\n")); err != nil { + t.Fatal(err) + } + if got := loadDeviceID(); got != "cached-id" { + t.Errorf("got device ID %q, want %q", got, "cached-id") + } +} + +func TestLoadDeviceIDWritesCache(t *testing.T) { + setTestStateDir(t) + + id := loadDeviceID() + if id == "" { + t.Skip("machine ID is unavailable on this machine") + } + data, err := os.ReadFile(deviceIDFile) + if err != nil { + t.Fatalf("device ID wasn't cached: %v", err) + } + if string(data) != id { + t.Errorf("got cached device ID %q, want %q", data, id) + } +} + +func TestShouldUpload(t *testing.T) { + writeLastUpload := func(t *testing.T, ts time.Time) { + t.Helper() + data := []byte(strconv.FormatInt(ts.Unix(), 10)) + if err := writeStateFile(lastUploadFile, data); err != nil { + t.Fatal(err) + } + } + + t.Run("NeverUploaded", func(t *testing.T) { + setTestStateDir(t) + if !shouldUpload() { + t.Error("got shouldUpload() = false, want true") + } + }) + t.Run("RecentUpload", func(t *testing.T) { + setTestStateDir(t) + writeLastUpload(t, time.Now()) + if shouldUpload() { + t.Error("got shouldUpload() = true, want false") + } + }) + t.Run("StaleUpload", func(t *testing.T) { + setTestStateDir(t) + writeLastUpload(t, time.Now().Add(-uploadInterval)) + if !shouldUpload() { + t.Error("got shouldUpload() = false, want true") + } + }) + t.Run("FutureUpload", func(t *testing.T) { + setTestStateDir(t) + writeLastUpload(t, time.Now().Add(time.Hour)) + if !shouldUpload() { + t.Error("got shouldUpload() = false, want true") + } + }) + t.Run("Error", func(t *testing.T) { + setTestStateDir(t) + writeLastUpload(t, time.Now()) + uploadNow.Store(true) + if !shouldUpload() { + t.Error("got shouldUpload() = false, want true") + } + }) + t.Run("ManyBufferedEvents", func(t *testing.T) { + setTestStateDir(t) + writeLastUpload(t, time.Now()) + for i := range uploadThreshold { + file := filepath.Join(segmentBufferDir, strconv.Itoa(i)+".json") + if err := writeStateFile(file, []byte("{}")); err != nil { + t.Fatal(err) + } + } + if !shouldUpload() { + t.Error("got shouldUpload() = false, want true") + } + }) } From 17547a56dabe68ac79f083edd0c06ae437416719 Mon Sep 17 00:00:00 2001 From: Mike Landau Date: Sun, 25 Oct 2026 14:46:32 -0700 Subject: [PATCH 2/2] docs(specs): mark perf item(s) 2 3 4 done Co-Authored-By: Claude Opus 5.5 (1M context) --- specs/perf-improvements.md | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/specs/perf-improvements.md b/specs/perf-improvements.md index 70ff55bfe03..5f5cdfb22b5 100644 --- a/specs/perf-improvements.md +++ b/specs/perf-improvements.md @@ -67,7 +67,7 @@ Fix: `ExcludedPlatforms` is set, so `nix.System()` is never called in the common case. ~3–5 LOC. -### 2. Telemetry re-opens the whole project after every command +### 2. Telemetry re-opens the whole project after every command (done in #3021) **Win:** one extra `devbox.Open` per command (re-parses devbox.json and devbox.lock, reloads plugins, which can hit the network). @@ -85,7 +85,7 @@ Fix: so it is always nil and `--config` is ignored. Look it up on the resolved subcommand instead. ~2–5 LOC. -### 3. Cache the macOS machine ID +### 3. Cache the macOS machine ID (done in #3021) **Win:** ~20ms per command on macOS. **Effort:** ~30–50 LOC. @@ -94,7 +94,7 @@ Fix: `ioreg` every time. Fix: compute it once and store it in the XDG state dir; read the file on subsequent runs. -### 4. Throttle the `devbox upload-telemetry` child process +### 4. Throttle the `devbox upload-telemetry` child process (done in #3021) **Win:** removes a second devbox process + HTTPS calls on every command (every direnv `cd`).