Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

update desktop to use slogger #1525

Merged
merged 6 commits into from
Dec 29, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 2 additions & 1 deletion cmd/launcher/desktop_test.go
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
Original file line number Diff line number Diff line change
Expand Up @@ -327,7 +327,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
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
Loading