Skip to content

Commit

Permalink
update desktop to use slogger (#1525)
Browse files Browse the repository at this point in the history
  • Loading branch information
@James-Pickett
James-Pickett authored Dec 29, 2023
1 parent 111a479 commit 6cb95a7
Show file tree
Hide file tree
Showing 7 changed files with 143 additions and 103 deletions.
3 changes: 2 additions & 1 deletion cmd/launcher/desktop_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
1 change: 0 additions & 1 deletion cmd/launcher/launcher.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -334,7 +334,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),
)
Expand Down
144 changes: 85 additions & 59 deletions ee/desktop/runner/runner.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import (
"errors"
"fmt"
"io"
"log/slog"
"math/rand"
"net/http"
"os"
Expand All @@ -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"
Expand All @@ -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) {
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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(),
Expand All @@ -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)
}
Expand All @@ -186,16 +178,16 @@ 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)
}

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(context.TODO(), slog.LevelError,
"running monitor server",
"err", err,
)
}
Expand All @@ -204,7 +196,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(context.TODO(), slog.LevelError,
"getting os version",
"err", err,
)
}
runner.osVersion = osversion
}
Expand All @@ -226,7 +221,10 @@ func (r *DesktopUsersProcessesRunner) Execute() error {
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(context.TODO(), slog.LevelInfo,
"running console user desktop",
"err", err,
)
}

select {
Expand All @@ -239,7 +237,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(context.TODO(), slog.LevelDebug,
"interrupt received, exiting desktop execute loop",
)
return nil
}
}
Expand All @@ -265,8 +265,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,
)
}
Expand All @@ -287,8 +287,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(context.TODO(), slog.LevelError,
"sending shutdown command to user desktop process",
"uid", uid,
"pid", proc.Process.Pid,
"path", proc.path,
Expand All @@ -302,23 +302,26 @@ 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(context.TODO(), slog.LevelDebug,
"successfully completed desktop process shutdown requests",
"count", shutdownRequestCount,
)
}

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(context.TODO(), 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(context.TODO(), slog.LevelError,
"killing desktop process",
"uid", uid,
"pid", processRecord.Process.Pid,
"path", processRecord.path,
Expand Down Expand Up @@ -364,7 +367,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
Expand All @@ -377,7 +383,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,
)
}
}

Expand Down Expand Up @@ -405,9 +414,9 @@ func (r *DesktopUsersProcessesRunner) writeSharedFile(path string, data []byte)
func (r *DesktopUsersProcessesRunner) refreshMenu() {
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(context.TODO(), slog.LevelError,
"failed to generate menu file",
"err", err,
)
}
}
Expand All @@ -416,8 +425,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(context.TODO(), slog.LevelError,
"sending refresh command to user desktop process",
"uid", uid,
"pid", proc.Process.Pid,
"path", proc.path,
Expand Down Expand Up @@ -477,10 +487,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,
)
}
}

Expand Down Expand Up @@ -553,8 +569,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,
Expand All @@ -567,11 +583,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 {
Expand Down Expand Up @@ -618,8 +635,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,
Expand Down Expand Up @@ -653,10 +670,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,
)

Expand All @@ -677,8 +694,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,
Expand All @@ -688,8 +705,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,
Expand Down Expand Up @@ -725,8 +742,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,
)
Expand Down Expand Up @@ -794,10 +811,10 @@ func (r *DesktopUsersProcessesRunner) desktopCommand(executablePath, uid, socket
scanner := bufio.NewScanner(combined)

for scanner.Scan() {
level.Debug(r.logger).Log(
r.slogger.Log(context.TODO(), slog.LevelDebug,
scanner.Text(),
"uid", uid,
"subprocess", "desktop",
"msg", scanner.Text(),
)
}
}()
Expand All @@ -812,10 +829,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,
)
}
}

Expand Down Expand Up @@ -859,13 +882,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,
)
Expand Down
Loading

0 comments on commit 6cb95a7

Please sign in to comment.