From f41b7cc46843da18b3c013d32c3492a9a41009de Mon Sep 17 00:00:00 2001 From: james pickett Date: Fri, 29 Dec 2023 10:26:15 -0800 Subject: [PATCH 1/5] update desktop to use slogger --- cmd/launcher/desktop_test.go | 3 +- cmd/launcher/launcher.go | 1 - ee/desktop/runner/runner.go | 151 +++++++++++++++--------- ee/desktop/runner/runner_test.go | 10 +- ee/desktop/runner/server/server.go | 21 ++-- ee/desktop/runner/server/server_test.go | 4 +- 6 files changed, 116 insertions(+), 74 deletions(-) diff --git a/cmd/launcher/desktop_test.go b/cmd/launcher/desktop_test.go index e3f5e19a5..4150fa9ce 100644 --- a/cmd/launcher/desktop_test.go +++ b/cmd/launcher/desktop_test.go @@ -9,12 +9,13 @@ import ( "github.com/go-kit/kit/log" runnerserver "github.com/kolide/launcher/ee/desktop/runner/server" + "github.com/kolide/launcher/pkg/log/multislogger" "github.com/kolide/launcher/pkg/threadsafebuffer" "github.com/stretchr/testify/require" ) func Test_desktopMonitorParentProcess(t *testing.T) { //nolint:paralleltest - runnerServer, err := runnerserver.New(log.NewNopLogger(), nil) + runnerServer, err := runnerserver.New(multislogger.New().Logger, nil) require.NoError(t, err) // register client and get token diff --git a/cmd/launcher/launcher.go b/cmd/launcher/launcher.go index 996622f25..af70610a5 100644 --- a/cmd/launcher/launcher.go +++ b/cmd/launcher/launcher.go @@ -324,7 +324,6 @@ func runLauncher(ctx context.Context, cancel func(), slogger, systemSlogger *mul runner, err = desktopRunner.New( k, - desktopRunner.WithLogger(logger), desktopRunner.WithAuthToken(ulid.New()), desktopRunner.WithUsersFilesRoot(rootDirectory), ) diff --git a/ee/desktop/runner/runner.go b/ee/desktop/runner/runner.go index d91875057..851d522af 100644 --- a/ee/desktop/runner/runner.go +++ b/ee/desktop/runner/runner.go @@ -8,6 +8,7 @@ import ( "errors" "fmt" "io" + "log/slog" "math/rand" "net/http" "os" @@ -19,8 +20,6 @@ import ( "sync" "time" - "github.com/go-kit/kit/log" - "github.com/go-kit/kit/log/level" "github.com/kolide/kit/ulid" "github.com/kolide/kit/version" "github.com/kolide/launcher/ee/agent" @@ -43,14 +42,6 @@ const nonWindowsDesktopSocketPrefix = "desktop.sock" type desktopUsersProcessesRunnerOption func(*DesktopUsersProcessesRunner) -func WithLogger(logger log.Logger) desktopUsersProcessesRunnerOption { - return func(r *DesktopUsersProcessesRunner) { - r.logger = log.With(logger, - "component", "desktop_users_processes_runner", - ) - } -} - // WithExecutablePath sets the path to the executable that will be run for each desktop. func WithExecutablePath(path string) desktopUsersProcessesRunnerOption { return func(r *DesktopUsersProcessesRunner) { @@ -102,7 +93,7 @@ func InstanceDesktopProcessRecords() map[string]processRecord { // will create a new one. // Initialize with New(). type DesktopUsersProcessesRunner struct { - logger log.Logger + slogger *slog.Logger // updateInterval is the interval on which desktop processes will be spawned, if necessary updateInterval time.Duration // menuRefreshInterval is the interval on which the desktop menu will be refreshed @@ -162,7 +153,6 @@ func (pr processRecord) String() string { // New creates and returns a new DesktopUsersProcessesRunner runner and initializes all required fields func New(k types.Knapsack, opts ...desktopUsersProcessesRunnerOption) (*DesktopUsersProcessesRunner, error) { runner := &DesktopUsersProcessesRunner{ - logger: log.NewNopLogger(), interrupt: make(chan struct{}), uidProcs: make(map[string]processRecord), updateInterval: k.DesktopUpdateInterval(), @@ -175,6 +165,8 @@ func New(k types.Knapsack, opts ...desktopUsersProcessesRunnerOption) (*DesktopU knapsack: k, } + runner.slogger = k.Slogger().With("component", "desktop_runner") + for _, opt := range opts { opt(runner) } @@ -186,16 +178,18 @@ func New(k types.Knapsack, opts ...desktopUsersProcessesRunnerOption) (*DesktopU // Observe DesktopEnabled changes to know when to enable/disable process spawning runner.knapsack.RegisterChangeObserver(runner, keys.DesktopEnabled) - rs, err := runnerserver.New(runner.logger, k) + rs, err := runnerserver.New(runner.slogger, k) if err != nil { return nil, fmt.Errorf("creating desktop runner server: %w", err) } + ctx := context.TODO() + runner.runnerServer = rs go func() { if err := runner.runnerServer.Serve(); err != nil && !errors.Is(err, http.ErrServerClosed) { - level.Error(runner.logger).Log( - "msg", "running monitor server", + runner.slogger.Log(ctx, slog.LevelError, + "running monitor server", "err", err, ) } @@ -204,7 +198,10 @@ func New(k types.Knapsack, opts ...desktopUsersProcessesRunnerOption) (*DesktopU if runtime.GOOS == "darwin" { osversion, err := osversion() if err != nil { - level.Error(runner.logger).Log("msg", "getting os version", "err", err) + runner.slogger.Log(ctx, slog.LevelError, + "getting os version", + "err", err, + ) } runner.osVersion = osversion } @@ -223,10 +220,15 @@ func (r *DesktopUsersProcessesRunner) Execute() error { osUpdateCheckTicker := time.NewTicker(1 * time.Minute) defer osUpdateCheckTicker.Stop() + ctx := context.TODO() + for { // Check immediately on each iteration, avoiding the initial ticker delay if err := r.runConsoleUserDesktop(); err != nil { - level.Info(r.logger).Log("msg", "running console user desktop", "err", err) + r.slogger.Log(ctx, slog.LevelInfo, + "running console user desktop", + "err", err, + ) } select { @@ -239,7 +241,9 @@ func (r *DesktopUsersProcessesRunner) Execute() error { r.checkOsUpdate() continue case <-r.interrupt: - level.Debug(r.logger).Log("msg", "interrupt received, exiting desktop execute loop") + r.slogger.Log(ctx, slog.LevelDebug, + "interrupt received, exiting desktop execute loop", + ) return nil } } @@ -265,8 +269,8 @@ func (r *DesktopUsersProcessesRunner) Interrupt(_ error) { defer cancel() if err := r.runnerServer.Shutdown(ctx); err != nil { - level.Error(r.logger).Log( - "msg", "shutting down monitor server", + r.slogger.Log(ctx, slog.LevelError, + "shutting down monitor server", "err", err, ) } @@ -280,6 +284,7 @@ func (r *DesktopUsersProcessesRunner) killDesktopProcesses() { r.procsWg.Wait() }() + ctx := context.TODO() shutdownRequestCount := 0 for uid, proc := range r.uidProcs { // unregistering client from runner server so server will not respond to its requests @@ -287,8 +292,8 @@ func (r *DesktopUsersProcessesRunner) killDesktopProcesses() { client := client.New(r.userServerAuthToken, proc.socketPath) if err := client.Shutdown(); err != nil { - level.Error(r.logger).Log( - "msg", "error sending shutdown command to user desktop process", + r.slogger.Log(ctx, slog.LevelError, + "sending shutdown command to user desktop process", "uid", uid, "pid", proc.Process.Pid, "path", proc.path, @@ -302,8 +307,8 @@ func (r *DesktopUsersProcessesRunner) killDesktopProcesses() { select { case <-wgDone: if shutdownRequestCount > 0 { - level.Debug(r.logger).Log( - "msg", "successfully completed desktop process shutdown requests", + r.slogger.Log(ctx, slog.LevelDebug, + "successfully completed desktop process shutdown requests", "count", shutdownRequestCount, ) } @@ -311,14 +316,17 @@ func (r *DesktopUsersProcessesRunner) killDesktopProcesses() { maps.Clear(r.uidProcs) return case <-time.After(r.interruptTimeout): - level.Error(r.logger).Log("msg", "timeout waiting for desktop processes to exit, now killing") + r.slogger.Log(ctx, slog.LevelError, + "timeout waiting for desktop processes to exit, now killing", + ) + for uid, processRecord := range r.uidProcs { if !r.processExists(processRecord) { continue } if err := processRecord.Process.Kill(); err != nil { - level.Error(r.logger).Log( - "msg", "error killing desktop process", + r.slogger.Log(ctx, slog.LevelError, + "killing desktop process", "uid", uid, "pid", processRecord.Process.Pid, "path", processRecord.path, @@ -364,7 +372,10 @@ func (r *DesktopUsersProcessesRunner) Update(data io.Reader) error { return fmt.Errorf("error reading control data: %w", err) } if err := r.writeSharedFile(r.menuTemplatePath(), dataBytes); err != nil { - level.Error(r.logger).Log("msg", "menu template file did not exist, could not create it", "err", err) + r.slogger.Log(context.TODO(), slog.LevelError, + "menu template file did not exist, could not create it", + "err", err, + ) } // Regardless, we will write the menu data out to a file that can be grabbed by @@ -377,7 +388,10 @@ func (r *DesktopUsersProcessesRunner) Update(data io.Reader) error { func (r *DesktopUsersProcessesRunner) FlagsChanged(flagKeys ...keys.FlagKey) { if slices.Contains(flagKeys, keys.DesktopEnabled) { r.processSpawningEnabled = r.knapsack.DesktopEnabled() - level.Debug(r.logger).Log("msg", fmt.Sprintf("runner processSpawningEnabled set by control server: %s", strconv.FormatBool(r.processSpawningEnabled))) + r.slogger.Log(context.TODO(), slog.LevelDebug, + "runner processSpawningEnabled set by control server", + "processSpawningEnabled", r.processSpawningEnabled, + ) } } @@ -403,11 +417,12 @@ func (r *DesktopUsersProcessesRunner) writeSharedFile(path string, data []byte) // refreshMenu updates the menu file and tells desktop processes to refresh their menus func (r *DesktopUsersProcessesRunner) refreshMenu() { + ctx := context.TODO() if err := r.generateMenuFile(); err != nil { if r.knapsack.DebugServerData() { - level.Error(r.logger).Log( - "msg", "failed to generate menu file", - "error", err, + r.slogger.Log(ctx, slog.LevelError, + "failed to generate menu file", + "err", err, ) } } @@ -416,8 +431,9 @@ func (r *DesktopUsersProcessesRunner) refreshMenu() { for uid, proc := range r.uidProcs { client := client.New(r.userServerAuthToken, proc.socketPath) if err := client.Refresh(); err != nil { - level.Error(r.logger).Log( - "msg", "error sending refresh command to desktop process", + + r.slogger.Log(ctx, slog.LevelError, + "sending refresh command to user desktop process", "uid", uid, "pid", proc.Process.Pid, "path", proc.path, @@ -477,10 +493,16 @@ func (r *DesktopUsersProcessesRunner) writeDefaultMenuTemplateFile() { if os.IsNotExist(err) { if err := r.writeSharedFile(menuTemplatePath, menu.InitialMenu); err != nil { - level.Error(r.logger).Log("msg", "menu template file did not exist, could not create it", "err", err) + r.slogger.Log(context.TODO(), slog.LevelError, + "menu template file did not exist, could not create it", + "err", err, + ) } } else if err != nil { - level.Error(r.logger).Log("msg", "could not check if menu template file exists", "err", err) + r.slogger.Log(context.TODO(), slog.LevelError, + "could not check if menu template file exists", + "err", err, + ) } } @@ -553,8 +575,8 @@ func (r *DesktopUsersProcessesRunner) spawnForUser(ctx context.Context, uid stri r.runnerServer.DeRegisterClient(uid) if err := cmd.Process.Kill(); err != nil { - level.Error(r.logger).Log( - "msg", "killing user desktop process after startup ping failed", + r.slogger.Log(ctx, slog.LevelError, + "killing user desktop process after startup ping failed", "uid", uid, "pid", cmd.Process.Pid, "path", cmd.Path, @@ -567,11 +589,12 @@ func (r *DesktopUsersProcessesRunner) spawnForUser(ctx context.Context, uid stri return fmt.Errorf("pinging user desktop server after startup: pid %d: %w", cmd.Process.Pid, err) } - level.Debug(r.logger).Log( - "msg", "desktop started", + r.slogger.Log(ctx, slog.LevelDebug, + "desktop process started", "uid", uid, "pid", cmd.Process.Pid, ) + span.AddEvent("desktop_started") if err := r.addProcessTrackingRecordForUser(uid, socketPath, cmd.Process); err != nil { @@ -618,8 +641,8 @@ func (r *DesktopUsersProcessesRunner) waitOnProcessAsync(uid string, proc *os.Pr // waiting here gives the parent a chance to clean up state, err := proc.Wait() if err != nil { - level.Info(r.logger).Log( - "msg", "desktop process died", + r.slogger.Log(context.TODO(), slog.LevelInfo, + "desktop process died", "uid", uid, "pid", proc.Pid, "err", err, @@ -653,10 +676,10 @@ func (r *DesktopUsersProcessesRunner) userHasDesktopProcess(uid string) bool { // have a record of process, but it died for some reason, log it if !r.processExists(proc) { - level.Info(r.logger).Log( - "msg", "found existing desktop process dead for console user", - "pid", r.uidProcs[uid].Process.Pid, - "process_path", r.uidProcs[uid].path, + r.slogger.Log(context.TODO(), slog.LevelInfo, + "found existing desktop process dead for console user", + "pid", proc.Process.Pid, + "process_path", proc.path, "uid", uid, ) @@ -677,8 +700,8 @@ func (r *DesktopUsersProcessesRunner) processExists(processRecord processRecord) // the call to process.NewProcessWithContext ensures process exists proc, err := process.NewProcessWithContext(ctx, int32(processRecord.Process.Pid)) if err != nil { - level.Info(r.logger).Log( - "msg", "looking up existing desktop process", + r.slogger.Log(ctx, slog.LevelInfo, + "error checking existing desktop process", "pid", processRecord.Process.Pid, "process_path", processRecord.path, "err", err, @@ -688,8 +711,8 @@ func (r *DesktopUsersProcessesRunner) processExists(processRecord processRecord) path, err := proc.ExeWithContext(ctx) if err != nil || path != processRecord.path { - level.Info(r.logger).Log( - "msg", "error or path mismatch checking existing desktop process path", + r.slogger.Log(ctx, slog.LevelInfo, + "error or path mismatch checking existing desktop process path", "pid", processRecord.Process.Pid, "process_record_path", processRecord.path, "err", err, @@ -725,8 +748,8 @@ func (r *DesktopUsersProcessesRunner) setupSocketPath(uid string) (string, error } if err := removeFilesWithPrefix(userFolderPath, nonWindowsDesktopSocketPrefix); err != nil { - level.Info(r.logger).Log( - "msg", "removing existing desktop sockets for user", + r.slogger.Log(context.TODO(), slog.LevelInfo, + "removing existing desktop sockets for user", "uid", uid, "err", err, ) @@ -792,12 +815,13 @@ func (r *DesktopUsersProcessesRunner) desktopCommand(executablePath, uid, socket go func() { combined := io.MultiReader(stdErr, stdOut) scanner := bufio.NewScanner(combined) + ctx := context.TODO() for scanner.Scan() { - level.Debug(r.logger).Log( + r.slogger.Log(ctx, slog.LevelDebug, + scanner.Text(), "uid", uid, "subprocess", "desktop", - "msg", scanner.Text(), ) } }() @@ -812,10 +836,16 @@ func (r *DesktopUsersProcessesRunner) writeIconFile() { if os.IsNotExist(err) { if err := os.WriteFile(expectedLocation, assets.MenubarDefaultLightmodeIco, 0644); err != nil { - level.Error(r.logger).Log("msg", "icon file did not exist, could not create it", "err", err) + r.slogger.Log(context.TODO(), slog.LevelError, + "icon file did not exist, could not create it", + "err", err, + ) } } else if err != nil { - level.Error(r.logger).Log("msg", "could not check if icon file exists", "err", err) + r.slogger.Log(context.TODO(), slog.LevelError, + "could not check if icon file exists", + "err", err, + ) } } @@ -859,13 +889,16 @@ func (r *DesktopUsersProcessesRunner) checkOsUpdate() { osVersion, err := osversion() if err != nil { - level.Error(r.logger).Log("msg", "getting os version", "err", err) + r.slogger.Log(context.TODO(), slog.LevelError, + "getting os version", + "err", err, + ) return } if osVersion != r.osVersion { - level.Debug(r.logger).Log( - "msg", "os version changed, restarting desktop", + r.slogger.Log(context.TODO(), slog.LevelInfo, + "os version changed, restarting desktop", "old", r.osVersion, "new", osVersion, ) diff --git a/ee/desktop/runner/runner_test.go b/ee/desktop/runner/runner_test.go index 1e4478c7f..0144333a3 100644 --- a/ee/desktop/runner/runner_test.go +++ b/ee/desktop/runner/runner_test.go @@ -4,6 +4,7 @@ import ( "context" "fmt" "io" + "log/slog" "os" "os/exec" "os/user" @@ -13,11 +14,11 @@ import ( "testing" "time" - "github.com/go-kit/kit/log" "github.com/kolide/kit/ulid" "github.com/kolide/launcher/ee/agent/flags/keys" "github.com/kolide/launcher/ee/agent/types/mocks" "github.com/kolide/launcher/ee/desktop/user/notify" + "github.com/kolide/launcher/pkg/log/multislogger" "github.com/kolide/launcher/pkg/threadsafebuffer" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/mock" @@ -113,6 +114,9 @@ func TestDesktopUserProcessRunner_Execute(t *testing.T) { t.Parallel() var logBytes threadsafebuffer.ThreadSafeBuffer + slogger := slog.New(slog.NewTextHandler(&logBytes, &slog.HandlerOptions{ + Level: slog.LevelDebug, + })) mockKnapsack := mocks.NewKnapsack(t) mockKnapsack.On("RegisterChangeObserver", mock.Anything, keys.DesktopEnabled) @@ -120,6 +124,7 @@ func TestDesktopUserProcessRunner_Execute(t *testing.T) { mockKnapsack.On("DesktopMenuRefreshInterval").Return(time.Millisecond * 250) mockKnapsack.On("KolideServerURL").Return("somewhere-over-the-rainbow.example.com") mockKnapsack.On("DesktopEnabled").Return(true) + mockKnapsack.On("Slogger").Return(slogger) if os.Getenv("CI") != "true" || runtime.GOOS != "linux" { // Only expect that we call Debug (to set the DEBUG flag on the process) if we actually expect @@ -129,7 +134,6 @@ func TestDesktopUserProcessRunner_Execute(t *testing.T) { r, err := New( mockKnapsack, - WithLogger(log.NewLogfmtLogger(&logBytes)), WithExecutablePath(executablePath), WithInterruptTimeout(time.Second*5), WithAuthToken("test-auth-token"), @@ -292,6 +296,7 @@ func TestUpdate(t *testing.T) { mockKnapsack.On("DesktopMenuRefreshInterval").Return(time.Millisecond * 250) mockKnapsack.On("KolideServerURL").Return("somewhere-over-the-rainbow.example.com") mockKnapsack.On("DesktopEnabled").Return(true) + mockKnapsack.On("Slogger").Return(multislogger.New().Logger) dir := t.TempDir() r, err := New(mockKnapsack, WithUsersFilesRoot(dir)) @@ -325,6 +330,7 @@ func TestSendNotification_NoProcessesYet(t *testing.T) { mockKnapsack.On("DesktopMenuRefreshInterval").Return(time.Millisecond * 250) mockKnapsack.On("KolideServerURL").Return("somewhere-over-the-rainbow.example.com") mockKnapsack.On("DesktopEnabled").Return(true) + mockKnapsack.On("Slogger").Return(multislogger.New().Logger) dir := t.TempDir() r, err := New(mockKnapsack, WithUsersFilesRoot(dir)) diff --git a/ee/desktop/runner/server/server.go b/ee/desktop/runner/server/server.go index 38f537fb2..559437155 100644 --- a/ee/desktop/runner/server/server.go +++ b/ee/desktop/runner/server/server.go @@ -3,14 +3,13 @@ package server import ( "context" "fmt" + "log/slog" "net" "net/http" "strings" "sync" "time" - "github.com/go-kit/kit/log" - "github.com/go-kit/kit/log/level" "github.com/kolide/kit/ulid" ) @@ -19,7 +18,7 @@ import ( type RunnerServer struct { server *http.Server listener net.Listener - logger log.Logger + slogger *slog.Logger desktopProcAuthTokens map[string]string mutex sync.Mutex controlRequestIntervalOverrider controlRequestIntervalOverrider @@ -36,7 +35,7 @@ type controlRequestIntervalOverrider interface { SetControlRequestIntervalOverride(time.Duration, time.Duration) } -func New(logger log.Logger, controlRequestIntervalOverrider controlRequestIntervalOverrider) (*RunnerServer, error) { +func New(slogger *slog.Logger, controlRequestIntervalOverrider controlRequestIntervalOverrider) (*RunnerServer, error) { listener, err := net.Listen("tcp", "localhost:0") if err != nil { return nil, fmt.Errorf("creating net listener: %w", err) @@ -44,13 +43,13 @@ func New(logger log.Logger, controlRequestIntervalOverrider controlRequestInterv rs := &RunnerServer{ listener: listener, - logger: logger, + slogger: slogger, desktopProcAuthTokens: make(map[string]string), controlRequestIntervalOverrider: controlRequestIntervalOverrider, } - if rs.logger != nil { - rs.logger = log.With(rs.logger, "component", "desktop_runner_root_server") + if rs.slogger != nil { + rs.slogger = slogger.With("component", "desktop_runner_root_server") } mux := http.NewServeMux() @@ -118,13 +117,17 @@ func (ms *RunnerServer) authMiddleware(next http.Handler) http.Handler { authHeader := strings.Split(r.Header.Get("Authorization"), "Bearer ") if len(authHeader) != 2 { - level.Debug(ms.logger).Log("msg", "malformed authorization header") + ms.slogger.Log(r.Context(), slog.LevelDebug, + "malformed authorization header", + ) w.WriteHeader(http.StatusUnauthorized) return } if !ms.isAuthTokenValid(authHeader[1]) { - level.Debug(ms.logger).Log("msg", "invalid desktop auth token") + ms.slogger.Log(r.Context(), slog.LevelDebug, + "invalid desktop auth token", + ) w.WriteHeader(http.StatusUnauthorized) return } diff --git a/ee/desktop/runner/server/server_test.go b/ee/desktop/runner/server/server_test.go index 71cfd7589..95ff02611 100644 --- a/ee/desktop/runner/server/server_test.go +++ b/ee/desktop/runner/server/server_test.go @@ -7,9 +7,9 @@ import ( "testing" "time" - "github.com/go-kit/kit/log" "github.com/kolide/launcher/ee/agent/types/mocks" "github.com/kolide/launcher/pkg/authedclient" + "github.com/kolide/launcher/pkg/log/multislogger" "github.com/stretchr/testify/mock" "github.com/stretchr/testify/require" ) @@ -20,7 +20,7 @@ func TestRootServer(t *testing.T) { mockSack := mocks.NewKnapsack(t) mockSack.On("SetControlRequestIntervalOverride", mock.Anything, mock.Anything) - monitorServer, err := New(log.NewNopLogger(), mockSack) + monitorServer, err := New(multislogger.New().Logger, mockSack) require.NoError(t, err) go func() { From a4b333a065f50a99cf2f57f5bca97dd7227e7302 Mon Sep 17 00:00:00 2001 From: james pickett Date: Fri, 29 Dec 2023 10:53:46 -0800 Subject: [PATCH 2/5] update linux --- ee/desktop/runner/runner_linux.go | 60 ++++++++++++++++--------------- 1 file changed, 31 insertions(+), 29 deletions(-) diff --git a/ee/desktop/runner/runner_linux.go b/ee/desktop/runner/runner_linux.go index 72934d2f2..7a32c93ff 100644 --- a/ee/desktop/runner/runner_linux.go +++ b/ee/desktop/runner/runner_linux.go @@ -7,6 +7,7 @@ import ( "context" "errors" "fmt" + "log/slog" "os" "os/exec" "os/user" @@ -15,7 +16,6 @@ import ( "strings" "syscall" - "github.com/go-kit/kit/log/level" "github.com/kolide/launcher/ee/allowedcmd" "github.com/kolide/launcher/pkg/traces" "github.com/shirou/gopsutil/v3/process" @@ -83,8 +83,8 @@ func (r *DesktopUsersProcessesRunner) userEnvVars(ctx context.Context, uid strin uidInt, err := strconv.ParseInt(uid, 10, 32) if err != nil { - level.Debug(r.logger).Log( - "msg", "could not convert uid to int32", + r.slogger.Log(ctx, slog.LevelDebug, + "could not convert uid to int32", "err", err, ) return envVars @@ -93,8 +93,8 @@ func (r *DesktopUsersProcessesRunner) userEnvVars(ctx context.Context, uid strin // Get the user's session so we can get their display (needed for opening notification action URLs in browser) cmd, err := allowedcmd.Loginctl(ctx, "show-user", uid, "--value", "--property=Sessions") if err != nil { - level.Debug(r.logger).Log( - "msg", "could not create loginctl command", + r.slogger.Log(ctx, slog.LevelDebug, + "could not create loginctl command", "uid", uid, "err", err, ) @@ -102,8 +102,8 @@ func (r *DesktopUsersProcessesRunner) userEnvVars(ctx context.Context, uid strin } sessionOutput, err := cmd.Output() if err != nil { - level.Debug(r.logger).Log( - "msg", "could not get user session", + r.slogger.Log(ctx, slog.LevelDebug, + "could not get user session", "uid", uid, "err", err, ) @@ -120,8 +120,8 @@ func (r *DesktopUsersProcessesRunner) userEnvVars(ctx context.Context, uid strin // Figure out what type of graphical session the user has -- x11, wayland? cmd, err := allowedcmd.Loginctl(ctx, "show-session", session, "--value", "--property=Type") if err != nil { - level.Debug(r.logger).Log( - "msg", "could not create loginctl command to get session type", + r.slogger.Log(ctx, slog.LevelDebug, + "could not create loginctl command to get session type", "uid", uid, "err", err, ) @@ -129,8 +129,8 @@ func (r *DesktopUsersProcessesRunner) userEnvVars(ctx context.Context, uid strin } typeOutput, err := cmd.Output() if err != nil { - level.Debug(r.logger).Log( - "msg", "could not get session type", + r.slogger.Log(ctx, slog.LevelDebug, + "could not get session type", "uid", uid, "err", err, ) @@ -168,16 +168,16 @@ func (r *DesktopUsersProcessesRunner) displayFromX11(ctx context.Context, sessio // We can read $DISPLAY from the session properties cmd, err := allowedcmd.Loginctl(ctx, "show-session", session, "--value", "--property=Display") if err != nil { - level.Debug(r.logger).Log( - "msg", "could not create command to get Display from user session", + r.slogger.Log(ctx, slog.LevelDebug, + "could not create command to get Display from user session", "err", err, ) return r.displayFromXDisplayServerProcess(ctx, uid) } xDisplayOutput, err := cmd.Output() if err != nil { - level.Debug(r.logger).Log( - "msg", "could not get Display from user session", + r.slogger.Log(ctx, slog.LevelDebug, + "could not get Display from user session", "err", err, ) return r.displayFromXDisplayServerProcess(ctx, uid) @@ -194,8 +194,8 @@ func (r *DesktopUsersProcessesRunner) displayFromX11(ctx context.Context, sessio func (r *DesktopUsersProcessesRunner) displayFromXDisplayServerProcess(ctx context.Context, uid int32) string { processes, err := process.ProcessesWithContext(ctx) if err != nil { - level.Debug(r.logger).Log( - "msg", "could not query processes to find display server process", + r.slogger.Log(ctx, slog.LevelDebug, + "could not query processes to find display server process", "err", err, ) return defaultDisplay @@ -204,8 +204,8 @@ func (r *DesktopUsersProcessesRunner) displayFromXDisplayServerProcess(ctx conte for _, p := range processes { cmdline, err := p.CmdlineWithContext(ctx) if err != nil { - level.Debug(r.logger).Log( - "msg", "could not get cmdline slice for process", + r.slogger.Log(ctx, slog.LevelDebug, + "could not get cmdline slice for process", "err", err, ) continue @@ -218,8 +218,8 @@ func (r *DesktopUsersProcessesRunner) displayFromXDisplayServerProcess(ctx conte // We have an Xorg or Xvfb process -- check to make sure it's for our running user uids, err := p.UidsWithContext(ctx) if err != nil { - level.Debug(r.logger).Log( - "msg", "could not get uids for process", + r.slogger.Log(ctx, slog.LevelDebug, + "could not get uids for process", "err", err, ) continue @@ -257,8 +257,8 @@ func (r *DesktopUsersProcessesRunner) displayFromXwayland(ctx context.Context, u // the Xwayland process and examining its args. processes, err := process.ProcessesWithContext(ctx) if err != nil { - level.Debug(r.logger).Log( - "msg", "could not query processes to find Xwayland process", + r.slogger.Log(ctx, slog.LevelDebug, + "could not query processes to find Xwayland process", "err", err, ) return defaultDisplay @@ -267,8 +267,8 @@ func (r *DesktopUsersProcessesRunner) displayFromXwayland(ctx context.Context, u for _, p := range processes { cmdline, err := p.CmdlineWithContext(ctx) if err != nil { - level.Debug(r.logger).Log( - "msg", "could not get cmdline slice for process", + r.slogger.Log(ctx, slog.LevelDebug, + "could not get cmdline slice for process", "err", err, ) continue @@ -281,8 +281,8 @@ func (r *DesktopUsersProcessesRunner) displayFromXwayland(ctx context.Context, u // We have an Xwayland process -- check to make sure it's for our running user uids, err := p.UidsWithContext(ctx) if err != nil { - level.Debug(r.logger).Log( - "msg", "could not get uids for process", + r.slogger.Log(ctx, slog.LevelDebug, + "could not get uids for process", "err", err, ) continue @@ -333,10 +333,12 @@ func (r *DesktopUsersProcessesRunner) getXauthority(ctx context.Context, uid str return homeLocation } - level.Debug(r.logger).Log("msg", "could not find xauthority in any known location", + r.slogger.Log(ctx, slog.LevelDebug, + "could not find xauthority in any known location", "wayland", waylandXAuthorityLocationPattern, "x11", x11XauthorityLocation, - "default", homeLocation) + "default", homeLocation, + ) return "" } From bc01d56c767219cae7602c5847741b16ca9e731a Mon Sep 17 00:00:00 2001 From: james pickett Date: Fri, 29 Dec 2023 10:56:05 -0800 Subject: [PATCH 3/5] remove declaring context.TODO --- ee/desktop/runner/runner.go | 29 +++++++++++------------------ 1 file changed, 11 insertions(+), 18 deletions(-) diff --git a/ee/desktop/runner/runner.go b/ee/desktop/runner/runner.go index 851d522af..401d2272c 100644 --- a/ee/desktop/runner/runner.go +++ b/ee/desktop/runner/runner.go @@ -183,12 +183,10 @@ func New(k types.Knapsack, opts ...desktopUsersProcessesRunnerOption) (*DesktopU return nil, fmt.Errorf("creating desktop runner server: %w", err) } - ctx := context.TODO() - runner.runnerServer = rs go func() { if err := runner.runnerServer.Serve(); err != nil && !errors.Is(err, http.ErrServerClosed) { - runner.slogger.Log(ctx, slog.LevelError, + runner.slogger.Log(context.TODO(), slog.LevelError, "running monitor server", "err", err, ) @@ -198,7 +196,7 @@ func New(k types.Knapsack, opts ...desktopUsersProcessesRunnerOption) (*DesktopU if runtime.GOOS == "darwin" { osversion, err := osversion() if err != nil { - runner.slogger.Log(ctx, slog.LevelError, + runner.slogger.Log(context.TODO(), slog.LevelError, "getting os version", "err", err, ) @@ -220,12 +218,10 @@ func (r *DesktopUsersProcessesRunner) Execute() error { osUpdateCheckTicker := time.NewTicker(1 * time.Minute) defer osUpdateCheckTicker.Stop() - ctx := context.TODO() - for { // Check immediately on each iteration, avoiding the initial ticker delay if err := r.runConsoleUserDesktop(); err != nil { - r.slogger.Log(ctx, slog.LevelInfo, + r.slogger.Log(context.TODO(), slog.LevelInfo, "running console user desktop", "err", err, ) @@ -241,7 +237,7 @@ func (r *DesktopUsersProcessesRunner) Execute() error { r.checkOsUpdate() continue case <-r.interrupt: - r.slogger.Log(ctx, slog.LevelDebug, + r.slogger.Log(context.TODO(), slog.LevelDebug, "interrupt received, exiting desktop execute loop", ) return nil @@ -284,7 +280,6 @@ func (r *DesktopUsersProcessesRunner) killDesktopProcesses() { r.procsWg.Wait() }() - ctx := context.TODO() shutdownRequestCount := 0 for uid, proc := range r.uidProcs { // unregistering client from runner server so server will not respond to its requests @@ -292,7 +287,7 @@ func (r *DesktopUsersProcessesRunner) killDesktopProcesses() { client := client.New(r.userServerAuthToken, proc.socketPath) if err := client.Shutdown(); err != nil { - r.slogger.Log(ctx, slog.LevelError, + r.slogger.Log(context.TODO(), slog.LevelError, "sending shutdown command to user desktop process", "uid", uid, "pid", proc.Process.Pid, @@ -307,7 +302,7 @@ func (r *DesktopUsersProcessesRunner) killDesktopProcesses() { select { case <-wgDone: if shutdownRequestCount > 0 { - r.slogger.Log(ctx, slog.LevelDebug, + r.slogger.Log(context.TODO(), slog.LevelDebug, "successfully completed desktop process shutdown requests", "count", shutdownRequestCount, ) @@ -316,7 +311,7 @@ func (r *DesktopUsersProcessesRunner) killDesktopProcesses() { maps.Clear(r.uidProcs) return case <-time.After(r.interruptTimeout): - r.slogger.Log(ctx, slog.LevelError, + r.slogger.Log(context.TODO(), slog.LevelError, "timeout waiting for desktop processes to exit, now killing", ) @@ -325,7 +320,7 @@ func (r *DesktopUsersProcessesRunner) killDesktopProcesses() { continue } if err := processRecord.Process.Kill(); err != nil { - r.slogger.Log(ctx, slog.LevelError, + r.slogger.Log(context.TODO(), slog.LevelError, "killing desktop process", "uid", uid, "pid", processRecord.Process.Pid, @@ -417,10 +412,9 @@ func (r *DesktopUsersProcessesRunner) writeSharedFile(path string, data []byte) // refreshMenu updates the menu file and tells desktop processes to refresh their menus func (r *DesktopUsersProcessesRunner) refreshMenu() { - ctx := context.TODO() if err := r.generateMenuFile(); err != nil { if r.knapsack.DebugServerData() { - r.slogger.Log(ctx, slog.LevelError, + r.slogger.Log(context.TODO(), slog.LevelError, "failed to generate menu file", "err", err, ) @@ -432,7 +426,7 @@ func (r *DesktopUsersProcessesRunner) refreshMenu() { client := client.New(r.userServerAuthToken, proc.socketPath) if err := client.Refresh(); err != nil { - r.slogger.Log(ctx, slog.LevelError, + r.slogger.Log(context.TODO(), slog.LevelError, "sending refresh command to user desktop process", "uid", uid, "pid", proc.Process.Pid, @@ -815,10 +809,9 @@ func (r *DesktopUsersProcessesRunner) desktopCommand(executablePath, uid, socket go func() { combined := io.MultiReader(stdErr, stdOut) scanner := bufio.NewScanner(combined) - ctx := context.TODO() for scanner.Scan() { - r.slogger.Log(ctx, slog.LevelDebug, + r.slogger.Log(context.TODO(), slog.LevelDebug, scanner.Text(), "uid", uid, "subprocess", "desktop", From 99d49ef1f41a2fcbb9ec07cf88acd4f2266974f9 Mon Sep 17 00:00:00 2001 From: james pickett Date: Fri, 29 Dec 2023 11:52:40 -0800 Subject: [PATCH 4/5] desktop server error if slogger is nil --- ee/desktop/runner/server/server.go | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/ee/desktop/runner/server/server.go b/ee/desktop/runner/server/server.go index 559437155..f9adf8d7d 100644 --- a/ee/desktop/runner/server/server.go +++ b/ee/desktop/runner/server/server.go @@ -48,10 +48,12 @@ func New(slogger *slog.Logger, controlRequestIntervalOverrider controlRequestInt controlRequestIntervalOverrider: controlRequestIntervalOverrider, } - if rs.slogger != nil { - rs.slogger = slogger.With("component", "desktop_runner_root_server") + if rs.slogger == nil { + return nil, fmt.Errorf("slogger is nil") } + rs.slogger = slogger.With("component", "desktop_runner_root_server") + mux := http.NewServeMux() // health check endpoint From fa32c206237d249a794029fc6fb264cae84aee39 Mon Sep 17 00:00:00 2001 From: james pickett Date: Fri, 29 Dec 2023 11:55:21 -0800 Subject: [PATCH 5/5] use errors.New --- ee/desktop/runner/server/server.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/ee/desktop/runner/server/server.go b/ee/desktop/runner/server/server.go index f9adf8d7d..3ccf9d809 100644 --- a/ee/desktop/runner/server/server.go +++ b/ee/desktop/runner/server/server.go @@ -2,6 +2,7 @@ package server import ( "context" + "errors" "fmt" "log/slog" "net" @@ -49,7 +50,7 @@ func New(slogger *slog.Logger, controlRequestIntervalOverrider controlRequestInt } if rs.slogger == nil { - return nil, fmt.Errorf("slogger is nil") + return nil, errors.New("slogger cannot be nil") } rs.slogger = slogger.With("component", "desktop_runner_root_server")