Speed up launcher startup and collect more data about slow parts of startup

cmd/launcher/launcher.go

@@ -327,8 +327,9 @@ func runLauncher(ctx context.Context, cancel func(), multiSlogger, systemMultiSl
 	signalListener := newSignalListener(sigChannel, cancel, slogger)
 	runGroup.Add("sigChannel", signalListener.Execute, signalListener.Interrupt)
 
-	// For now, remediation is not performed -- we only log the hardware change.
-	agent.DetectAndRemediateHardwareChange(ctx, k)
+	// For now, remediation is not performed -- we only log the hardware change. So we can
+	// perform this operation in the background to avoid slowing down launcher startup.
+	go agent.DetectAndRemediateHardwareChange(ctx, k)
 
 	powerEventSubscriber := powereventwatcher.NewKnapsackSleepStateUpdater(slogger, k)
 	powerEventWatcher, err := powereventwatcher.New(ctx, slogger, powerEventSubscriber)

ee/agent/storage/bbolt/keyvalue_store_bbolt.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"log/slog"
 
+	"github.com/kolide/launcher/pkg/traces"
 	"go.etcd.io/bbolt"
 )
 
@@ -34,7 +35,10 @@ type bboltKeyValueStore struct {
 	bucketName string
 }
 
-func NewStore(slogger *slog.Logger, db *bbolt.DB, bucketName string) (*bboltKeyValueStore, error) {
+func NewStore(ctx context.Context, slogger *slog.Logger, db *bbolt.DB, bucketName string) (*bboltKeyValueStore, error) {
+	_, span := traces.StartSpan(ctx, "bucket_name", bucketName)
+	defer span.End()
+
 	err := db.Update(func(tx *bbolt.Tx) error {
 		_, err := tx.CreateBucketIfNotExists([]byte(bucketName))
 		if err != nil {

ee/agent/storage/bbolt/stores_bbolt.go

@@ -13,7 +13,7 @@ import (
 
 // MakeStores creates all the KVStores used by launcher
 func MakeStores(ctx context.Context, slogger *slog.Logger, db *bbolt.DB) (map[storage.Store]types.KVStore, error) {
-	_, span := traces.StartSpan(ctx)
+	ctx, span := traces.StartSpan(ctx)
 	defer span.End()
 
 	stores := make(map[storage.Store]types.KVStore)
@@ -37,7 +37,7 @@ func MakeStores(ctx context.Context, slogger *slog.Logger, db *bbolt.DB) (map[st
 	}
 
 	for _, storeName := range storeNames {
-		store, err := NewStore(slogger, db, storeName.String())
+		store, err := NewStore(ctx, slogger, db, storeName.String())
 		if err != nil {
 			return nil, fmt.Errorf("failed to create '%s' KVStore: %w", storeName, err)
 		}

ee/agent/storage/ci/keyvalue_store_ci.go

@@ -1,6 +1,7 @@
 package storageci
 
 import (
+	"context"
 	"fmt"
 	"log/slog"
 	"os"
@@ -23,7 +24,7 @@ func NewStore(t *testing.T, slogger *slog.Logger, bucketName string) (types.KVSt
 		return inmemory.NewStore(), nil
 	}
 
-	return agentbbolt.NewStore(slogger, SetupDB(t), bucketName)
+	return agentbbolt.NewStore(context.TODO(), slogger, SetupDB(t), bucketName)
 }
 
 // SetupDB is used for creating bbolt databases for testing

ee/agent/storage/ci/keyvalue_store_test.go

@@ -1,6 +1,7 @@
 package storageci
 
 import (
+	"context"
 	"errors"
 	"fmt"
 	"sync"
@@ -16,7 +17,7 @@ import (
 
 func getStores(t *testing.T) []types.KVStore {
 	db := SetupDB(t)
-	bboltStore, err := agentbbolt.NewStore(multislogger.NewNopLogger(), db, "test_bucket")
+	bboltStore, err := agentbbolt.NewStore(context.TODO(), multislogger.NewNopLogger(), db, "test_bucket")
 	require.NoError(t, err)
 
 	stores := []types.KVStore{

ee/agent/storage/ci/stores_ci.go

@@ -1,6 +1,7 @@
 package storageci
 
 import (
+	"context"
 	"fmt"
 	"log/slog"
 	"os"
@@ -54,7 +55,7 @@ func makeBboltStores(t *testing.T, slogger *slog.Logger, db *bbolt.DB, storeName
 	stores := make(map[storage.Store]types.KVStore)
 
 	for _, storeName := range storeNames {
-		store, err := agentbbolt.NewStore(slogger, db, storeName.String())
+		store, err := agentbbolt.NewStore(context.TODO(), slogger, db, storeName.String())
 		if err != nil {
 			return nil, fmt.Errorf("failed to create '%s' KVStore: %w", storeName, err)
 		}

ee/tuf/util.go

@@ -16,10 +16,10 @@ import (
 // CheckExecutable tests whether something is an executable. It
 // examines permissions, mode, and tries to exec it directly.
 func CheckExecutable(ctx context.Context, potentialBinary string, args ...string) error {
-	ctx, span := traces.StartSpan(ctx)
+	ctx, span := traces.StartSpan(ctx, "binary_path", potentialBinary)
 	defer span.End()
 
-	if err := checkExecutablePermissions(potentialBinary); err != nil {
+	if err := checkExecutablePermissions(ctx, potentialBinary); err != nil {
 		return err
 	}
 
@@ -36,34 +36,46 @@ func CheckExecutable(ctx context.Context, potentialBinary string, args ...string
 	// in that circumstance.
 	// See: https://github.com/golang/go/issues/22315
 	for i := 0; i < 3; i += 1 {
-		ctx, cancel := context.WithTimeout(ctx, 5*time.Second)
-		defer cancel()
-
-		cmd := exec.CommandContext(ctx, potentialBinary, args...) //nolint:forbidigo // We trust the autoupdate library to find the correct location so we don't need allowedcmd
-
-		// Set env, this should prevent launcher for fork-bombing
-		cmd.Env = append(cmd.Env, "LAUNCHER_SKIP_UPDATES=TRUE")
-
-		out, execErr := cmd.CombinedOutput()
+		out, execErr := runExecutableCheck(ctx, potentialBinary, args...)
 		if execErr != nil && errors.Is(execErr, syscall.ETXTBSY) {
 			continue
 		}
 
-		if ctx.Err() != nil {
-			return fmt.Errorf("timeout when checking executable: %w", ctx.Err())
-		}
-
-		return supressRoutineErrors(execErr, out)
+		return supressRoutineErrors(ctx, execErr, out)
 	}
 
 	return fmt.Errorf("could not exec %s despite retries due to text file busy", potentialBinary)
 }
 
+// runExecutableCheck runs a single exec against the given binary and returns the result.
+func runExecutableCheck(ctx context.Context, potentialBinary string, args ...string) ([]byte, error) {
+	ctx, span := traces.StartSpan(ctx)
+	defer span.End()
+
+	ctx, cancel := context.WithTimeout(ctx, 5*time.Second)
+	defer cancel()
+
+	cmd := exec.CommandContext(ctx, potentialBinary, args...) //nolint:forbidigo // We trust the autoupdate library to find the correct location so we don't need allowedcmd
+
+	// Set env, this should prevent launcher for fork-bombing
+	cmd.Env = append(cmd.Env, "LAUNCHER_SKIP_UPDATES=TRUE")
+
+	out, err := cmd.CombinedOutput()
+	if ctx.Err() != nil {
+		return nil, fmt.Errorf("timeout when checking executable: %w", ctx.Err())
+	}
+
+	return out, err
+}
+
 // supressRoutineErrors attempts to tell whether the error was a
 // program that has executed, and then exited, vs one that's execution
 // was entirely unsuccessful. This differentiation allows us to
 // detect, and recover, from corrupt updates vs something in-app.
-func supressRoutineErrors(err error, combinedOutput []byte) error {
+func supressRoutineErrors(ctx context.Context, err error, combinedOutput []byte) error {
+	_, span := traces.StartSpan(ctx)
+	defer span.End()
+
 	if err == nil {
 		return nil
 	}

ee/tuf/util_darwin.go

@@ -4,10 +4,13 @@
 package tuf
 
 import (
+	"context"
 	"errors"
 	"fmt"
 	"os"
 	"path/filepath"
+
+	"github.com/kolide/launcher/pkg/traces"
 )
 
 // executableLocation returns the path to the executable in `updateDirectory`.
@@ -33,7 +36,10 @@ func executableLocation(updateDirectory string, binary autoupdatableBinary) stri
 // checkExecutablePermissions checks whether a specific file looks
 // like it's executable. This is used in evaluating whether something
 // is an updated version.
-func checkExecutablePermissions(potentialBinary string) error {
+func checkExecutablePermissions(ctx context.Context, potentialBinary string) error {
+	_, span := traces.StartSpan(ctx)
+	defer span.End()
+
 	if potentialBinary == "" {
 		return errors.New("empty string isn't executable")
 	}

ee/tuf/util_linux.go

@@ -4,10 +4,13 @@
 package tuf
 
 import (
+	"context"
 	"errors"
 	"fmt"
 	"os"
 	"path/filepath"
+
+	"github.com/kolide/launcher/pkg/traces"
 )
 
 // executableLocation returns the path to the executable in `updateDirectory`.
@@ -18,7 +21,10 @@ func executableLocation(updateDirectory string, binary autoupdatableBinary) stri
 // checkExecutablePermissions checks whether a specific file looks
 // like it's executable. This is used in evaluating whether something
 // is an updated version.
-func checkExecutablePermissions(potentialBinary string) error {
+func checkExecutablePermissions(ctx context.Context, potentialBinary string) error {
+	_, span := traces.StartSpan(ctx)
+	defer span.End()
+
 	if potentialBinary == "" {
 		return errors.New("empty string isn't executable")
 	}

ee/tuf/util_test.go

@@ -196,13 +196,13 @@ func windowsAddExe(in string) string {
 func Test_checkExecutablePermissions(t *testing.T) {
 	t.Parallel()
 
-	require.Error(t, checkExecutablePermissions(""), "passing empty string")
-	require.Error(t, checkExecutablePermissions("/random/path/should/not/exist"), "passing non-existent file path")
+	require.Error(t, checkExecutablePermissions(context.TODO(), ""), "passing empty string")
+	require.Error(t, checkExecutablePermissions(context.TODO(), "/random/path/should/not/exist"), "passing non-existent file path")
 
 	// Setup the tests
 	tmpDir := t.TempDir()
 
-	require.Error(t, checkExecutablePermissions(tmpDir), "directory should not be executable")
+	require.Error(t, checkExecutablePermissions(context.TODO(), tmpDir), "directory should not be executable")
 
 	dotExe := ""
 	if runtime.GOOS == "windows" {
@@ -222,17 +222,17 @@ func Test_checkExecutablePermissions(t *testing.T) {
 
 	// windows doesn't have an executable bit
 	if runtime.GOOS == "windows" {
-		require.NoError(t, checkExecutablePermissions(fileName), "plain file")
-		require.NoError(t, checkExecutablePermissions(hardLink), "hard link")
-		require.NoError(t, checkExecutablePermissions(symLink), "symlink")
+		require.NoError(t, checkExecutablePermissions(context.TODO(), fileName), "plain file")
+		require.NoError(t, checkExecutablePermissions(context.TODO(), hardLink), "hard link")
+		require.NoError(t, checkExecutablePermissions(context.TODO(), symLink), "symlink")
 	} else {
-		require.Error(t, checkExecutablePermissions(fileName), "plain file")
-		require.Error(t, checkExecutablePermissions(hardLink), "hard link")
-		require.Error(t, checkExecutablePermissions(symLink), "symlink")
+		require.Error(t, checkExecutablePermissions(context.TODO(), fileName), "plain file")
+		require.Error(t, checkExecutablePermissions(context.TODO(), hardLink), "hard link")
+		require.Error(t, checkExecutablePermissions(context.TODO(), symLink), "symlink")
 
 		require.NoError(t, os.Chmod(fileName, 0755))
-		require.NoError(t, checkExecutablePermissions(fileName), "plain file")
-		require.NoError(t, checkExecutablePermissions(hardLink), "hard link")
-		require.NoError(t, checkExecutablePermissions(symLink), "symlink")
+		require.NoError(t, checkExecutablePermissions(context.TODO(), fileName), "plain file")
+		require.NoError(t, checkExecutablePermissions(context.TODO(), hardLink), "hard link")
+		require.NoError(t, checkExecutablePermissions(context.TODO(), symLink), "symlink")
 	}
 }

ee/tuf/util_windows.go

@@ -4,11 +4,14 @@
 package tuf
 
 import (
+	"context"
 	"errors"
 	"fmt"
 	"os"
 	"path/filepath"
 	"strings"
+
+	"github.com/kolide/launcher/pkg/traces"
 )
 
 // executableLocation returns the path to the executable in `updateDirectory`.
@@ -22,7 +25,10 @@ func executableLocation(updateDirectory string, binary autoupdatableBinary) stri
 //
 // Windows does not have executable bits, so we omit those. And
 // instead check the file extension.
-func checkExecutablePermissions(potentialBinary string) error {
+func checkExecutablePermissions(ctx context.Context, potentialBinary string) error {
+	_, span := traces.StartSpan(ctx)
+	defer span.End()
+
 	if potentialBinary == "" {
 		return errors.New("empty string isn't executable")
 	}

pkg/osquery/extension_test.go

@@ -99,7 +99,7 @@ func TestNewExtensionDatabaseError(t *testing.T) {
 	}()
 
 	m := mocks.NewKnapsack(t)
-	m.On("ConfigStore").Return(agentbbolt.NewStore(multislogger.NewNopLogger(), db, storage.ConfigStore.String()))
+	m.On("ConfigStore").Return(agentbbolt.NewStore(context.TODO(), multislogger.NewNopLogger(), db, storage.ConfigStore.String()))
 	m.On("Slogger").Return(multislogger.NewNopLogger()).Maybe()
 
 	e, err := NewExtension(context.TODO(), &mock.KolideService{}, m, ulid.New(), ExtensionOpts{})