From 10cee88bb84ce76ad280487cf9b9d7f97c60807c Mon Sep 17 00:00:00 2001 From: Rebecca Mahany-Horton Date: Wed, 11 Dec 2024 08:54:05 -0500 Subject: [PATCH] One log adapter per osquery instance; set registration ID and instance run ID on log adapter (#1985) --- cmd/launcher/launcher.go | 17 ------ pkg/osquery/runtime/osqueryinstance.go | 47 +++++++------- pkg/osquery/runtime/osqueryinstance_test.go | 11 ++-- .../runtime/osqueryinstance_windows_test.go | 1 + pkg/osquery/runtime/runtime_posix_test.go | 11 ++-- pkg/osquery/runtime/runtime_test.go | 61 ++++++------------- 6 files changed, 52 insertions(+), 96 deletions(-) diff --git a/cmd/launcher/launcher.go b/cmd/launcher/launcher.go index 40df48b40..ecc7e2aa7 100644 --- a/cmd/launcher/launcher.go +++ b/cmd/launcher/launcher.go @@ -42,7 +42,6 @@ import ( "github.com/kolide/launcher/ee/debug/checkups" desktopRunner "github.com/kolide/launcher/ee/desktop/runner" "github.com/kolide/launcher/ee/localserver" - kolidelog "github.com/kolide/launcher/ee/log/osquerylogs" "github.com/kolide/launcher/ee/powereventwatcher" "github.com/kolide/launcher/ee/tuf" "github.com/kolide/launcher/ee/watchdog" @@ -371,22 +370,6 @@ func runLauncher(ctx context.Context, cancel func(), multiSlogger, systemMultiSl osqueryRunner := osqueryruntime.New( k, client, - osqueryruntime.WithStdout(kolidelog.NewOsqueryLogAdapter( - k.Slogger().With( - "component", "osquery", - "osqlevel", "stdout", - ), - k.RootDirectory(), - kolidelog.WithLevel(slog.LevelDebug), - )), - osqueryruntime.WithStderr(kolidelog.NewOsqueryLogAdapter( - k.Slogger().With( - "component", "osquery", - "osqlevel", "stderr", - ), - k.RootDirectory(), - kolidelog.WithLevel(slog.LevelInfo), - )), osqueryruntime.WithAugeasLensFunction(augeas.InstallLenses), ) runGroup.Add("osqueryRunner", osqueryRunner.Run, osqueryRunner.Interrupt) diff --git a/pkg/osquery/runtime/osqueryinstance.go b/pkg/osquery/runtime/osqueryinstance.go index 824af3703..90856781c 100644 --- a/pkg/osquery/runtime/osqueryinstance.go +++ b/pkg/osquery/runtime/osqueryinstance.go @@ -18,6 +18,7 @@ import ( "github.com/kolide/kit/ulid" "github.com/kolide/launcher/ee/agent/types" "github.com/kolide/launcher/ee/gowrapper" + kolidelog "github.com/kolide/launcher/ee/log/osquerylogs" "github.com/kolide/launcher/pkg/backoff" launcherosq "github.com/kolide/launcher/pkg/osquery" "github.com/kolide/launcher/pkg/osquery/runtime/history" @@ -71,24 +72,6 @@ func WithExtensionSocketPath(path string) OsqueryInstanceOption { } } -// WithStdout is a functional option which allows the user to define where the -// stdout of the osquery process should be directed. By default, the output will -// be discarded. This should only be configured once. -func WithStdout(w io.Writer) OsqueryInstanceOption { - return func(i *OsqueryInstance) { - i.opts.stdout = w - } -} - -// WithStderr is a functional option which allows the user to define where the -// stderr of the osquery process should be directed. By default, the output will -// be discarded. This should only be configured once. -func WithStderr(w io.Writer) OsqueryInstanceOption { - return func(i *OsqueryInstance) { - i.opts.stderr = w - } -} - // WithAugeasLensFunction defines a callback function. This can be // used during setup to populate the augeas lenses directory. func WithAugeasLensFunction(f func(dir string) error) OsqueryInstanceOption { @@ -185,8 +168,6 @@ type osqueryOptions struct { // options included by the caller of LaunchOsqueryInstance augeasLensFunc func(dir string) error extensionSocketPath string - stderr io.Writer - stdout io.Writer } func newInstance(registrationId string, knapsack types.Knapsack, serviceClient service.KolideService, opts ...OsqueryInstanceOption) *OsqueryInstance { @@ -767,12 +748,26 @@ func (i *OsqueryInstance) createOsquerydCommand(osquerydBinary string, paths *os } cmd.Args = append(cmd.Args, platformArgs()...) - if i.opts.stdout != nil { - cmd.Stdout = i.opts.stdout - } - if i.opts.stderr != nil { - cmd.Stderr = i.opts.stderr - } + cmd.Stdout = kolidelog.NewOsqueryLogAdapter( + i.knapsack.Slogger().With( + "component", "osquery", + "osqlevel", "stdout", + "registration_id", i.registrationId, + "instance_run_id", i.runId, + ), + i.knapsack.RootDirectory(), + kolidelog.WithLevel(slog.LevelDebug), + ) + cmd.Stderr = kolidelog.NewOsqueryLogAdapter( + i.knapsack.Slogger().With( + "component", "osquery", + "osqlevel", "stderr", + "registration_id", i.registrationId, + "instance_run_id", i.runId, + ), + i.knapsack.RootDirectory(), + kolidelog.WithLevel(slog.LevelInfo), + ) // Apply user-provided flags last so that they can override other flags set // by Launcher (besides the flags below) diff --git a/pkg/osquery/runtime/osqueryinstance_test.go b/pkg/osquery/runtime/osqueryinstance_test.go index cf59febab..1a6a98478 100644 --- a/pkg/osquery/runtime/osqueryinstance_test.go +++ b/pkg/osquery/runtime/osqueryinstance_test.go @@ -3,7 +3,6 @@ package runtime import ( "context" "fmt" - "os" "path/filepath" "runtime" "strings" @@ -61,13 +60,12 @@ func TestCreateOsqueryCommand(t *testing.T) { k.On("OsqueryVerbose").Return(true) k.On("OsqueryFlags").Return([]string{}) k.On("Slogger").Return(multislogger.NewNopLogger()) + k.On("RootDirectory").Return("") - i := newInstance(types.DefaultRegistrationID, k, mockServiceClient(), WithStdout(os.Stdout), WithStderr(os.Stderr)) + i := newInstance(types.DefaultRegistrationID, k, mockServiceClient()) - cmd, err := i.createOsquerydCommand(osquerydPath, paths) + _, err := i.createOsquerydCommand(osquerydPath, paths) require.NoError(t, err) - require.Equal(t, os.Stderr, cmd.Stderr) - require.Equal(t, os.Stdout, cmd.Stdout) k.AssertExpectations(t) } @@ -83,6 +81,7 @@ func TestCreateOsqueryCommandWithFlags(t *testing.T) { k.On("OsqueryFlags").Return([]string{"verbose=false", "windows_event_channels=foo,bar"}) k.On("OsqueryVerbose").Return(true) k.On("Slogger").Return(multislogger.NewNopLogger()) + k.On("RootDirectory").Return("") i := newInstance(types.DefaultRegistrationID, k, mockServiceClient()) @@ -116,6 +115,7 @@ func TestCreateOsqueryCommand_SetsEnabledWatchdogSettingsAppropriately(t *testin k.On("Slogger").Return(multislogger.NewNopLogger()) k.On("OsqueryVerbose").Return(true) k.On("OsqueryFlags").Return([]string{}) + k.On("RootDirectory").Return("") i := newInstance(types.DefaultRegistrationID, k, mockServiceClient()) @@ -165,6 +165,7 @@ func TestCreateOsqueryCommand_SetsDisabledWatchdogSettingsAppropriately(t *testi k.On("Slogger").Return(multislogger.NewNopLogger()) k.On("OsqueryVerbose").Return(true) k.On("OsqueryFlags").Return([]string{}) + k.On("RootDirectory").Return("") i := newInstance(types.DefaultRegistrationID, k, mockServiceClient()) diff --git a/pkg/osquery/runtime/osqueryinstance_windows_test.go b/pkg/osquery/runtime/osqueryinstance_windows_test.go index c5b31528b..d97f00a62 100644 --- a/pkg/osquery/runtime/osqueryinstance_windows_test.go +++ b/pkg/osquery/runtime/osqueryinstance_windows_test.go @@ -26,6 +26,7 @@ func TestCreateOsqueryCommandEnvVars(t *testing.T) { k.On("OsqueryVerbose").Return(true) k.On("OsqueryFlags").Return([]string{}) k.On("Slogger").Return(multislogger.NewNopLogger()) + k.On("RootDirectory").Return("") i := newInstance(types.DefaultRegistrationID, k, mockServiceClient()) diff --git a/pkg/osquery/runtime/runtime_posix_test.go b/pkg/osquery/runtime/runtime_posix_test.go index 03554e176..e5e4b6051 100644 --- a/pkg/osquery/runtime/runtime_posix_test.go +++ b/pkg/osquery/runtime/runtime_posix_test.go @@ -39,7 +39,7 @@ func TestOsquerySlowStart(t *testing.T) { rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -57,7 +57,7 @@ func TestOsquerySlowStart(t *testing.T) { k.On("ReadEnrollSecret").Return("", nil).Maybe() setUpMockStores(t, k) - opts = append(opts, WithStartFunc(func(cmd *exec.Cmd) error { + runner := New(k, mockServiceClient(), WithStartFunc(func(cmd *exec.Cmd) error { err := cmd.Start() if err != nil { return fmt.Errorf("unexpected error starting command: %w", err) @@ -71,8 +71,6 @@ func TestOsquerySlowStart(t *testing.T) { }() return nil })) - - runner := New(k, mockServiceClient(), opts...) go runner.Run() waitHealthy(t, runner, logBytes) @@ -88,7 +86,7 @@ func TestExtensionSocketPath(t *testing.T) { rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -107,9 +105,8 @@ func TestExtensionSocketPath(t *testing.T) { setUpMockStores(t, k) extensionSocketPath := filepath.Join(rootDirectory, "sock") - opts = append(opts, WithExtensionSocketPath(extensionSocketPath)) - runner := New(k, mockServiceClient(), opts...) + runner := New(k, mockServiceClient(), WithExtensionSocketPath(extensionSocketPath)) go runner.Run() waitHealthy(t, runner, logBytes) diff --git a/pkg/osquery/runtime/runtime_test.go b/pkg/osquery/runtime/runtime_test.go index 75d981ed6..498cb22c3 100644 --- a/pkg/osquery/runtime/runtime_test.go +++ b/pkg/osquery/runtime/runtime_test.go @@ -25,7 +25,6 @@ import ( "github.com/kolide/launcher/ee/agent/storage/inmemory" "github.com/kolide/launcher/ee/agent/types" typesMocks "github.com/kolide/launcher/ee/agent/types/mocks" - kolidelog "github.com/kolide/launcher/ee/log/osquerylogs" "github.com/kolide/launcher/pkg/backoff" "github.com/kolide/launcher/pkg/log/multislogger" "github.com/kolide/launcher/pkg/osquery/runtime/history" @@ -119,7 +118,7 @@ func TestBadBinaryPath(t *testing.T) { t.Parallel() rootDirectory := t.TempDir() - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -137,7 +136,7 @@ func TestBadBinaryPath(t *testing.T) { k.On("ReadEnrollSecret").Return("", nil).Maybe() setUpMockStores(t, k) - runner := New(k, mockServiceClient(), opts...) + runner := New(k, mockServiceClient()) // The runner will repeatedly try to launch the instance, so `Run` // won't return an error until we shut it down. Kick off `Run`, @@ -156,7 +155,7 @@ func TestWithOsqueryFlags(t *testing.T) { t.Parallel() rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -174,7 +173,7 @@ func TestWithOsqueryFlags(t *testing.T) { k.On("ReadEnrollSecret").Return("", nil).Maybe() setUpMockStores(t, k) - runner := New(k, mockServiceClient(), opts...) + runner := New(k, mockServiceClient()) go runner.Run() waitHealthy(t, runner, logBytes) waitShutdown(t, runner, logBytes) @@ -185,7 +184,7 @@ func TestFlagsChanged(t *testing.T) { rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -209,7 +208,7 @@ func TestFlagsChanged(t *testing.T) { setUpMockStores(t, k) // Start the runner - runner := New(k, mockServiceClient(), opts...) + runner := New(k, mockServiceClient()) go runner.Run() // Wait for the instance to start @@ -321,7 +320,7 @@ func TestSimplePath(t *testing.T) { t.Parallel() rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -339,7 +338,7 @@ func TestSimplePath(t *testing.T) { k.On("ReadEnrollSecret").Return("", nil).Maybe() setUpMockStores(t, k) - runner := New(k, mockServiceClient(), opts...) + runner := New(k, mockServiceClient()) go runner.Run() waitHealthy(t, runner, logBytes) @@ -354,7 +353,7 @@ func TestMultipleInstances(t *testing.T) { t.Parallel() rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() // Add in an extra instance extraRegistrationId := ulid.New() @@ -376,7 +375,7 @@ func TestMultipleInstances(t *testing.T) { setUpMockStores(t, k) serviceClient := mockServiceClient() - runner := New(k, serviceClient, opts...) + runner := New(k, serviceClient) // Start the instance go runner.Run() @@ -416,7 +415,7 @@ func TestRunnerHandlesImmediateShutdownWithMultipleInstances(t *testing.T) { t.Parallel() rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -435,7 +434,7 @@ func TestRunnerHandlesImmediateShutdownWithMultipleInstances(t *testing.T) { setUpMockStores(t, k) serviceClient := mockServiceClient() - runner := New(k, serviceClient, opts...) + runner := New(k, serviceClient) // Add in an extra instance extraRegistrationId := ulid.New() @@ -467,7 +466,7 @@ func TestMultipleShutdowns(t *testing.T) { t.Parallel() rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -485,7 +484,7 @@ func TestMultipleShutdowns(t *testing.T) { k.On("ReadEnrollSecret").Return("", nil).Maybe() setUpMockStores(t, k) - runner := New(k, mockServiceClient(), opts...) + runner := New(k, mockServiceClient()) go runner.Run() waitHealthy(t, runner, logBytes) @@ -499,7 +498,7 @@ func TestOsqueryDies(t *testing.T) { t.Parallel() rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -517,7 +516,7 @@ func TestOsqueryDies(t *testing.T) { k.On("ReadEnrollSecret").Return("", nil).Maybe() setUpMockStores(t, k) - runner := New(k, mockServiceClient(), opts...) + runner := New(k, mockServiceClient()) go runner.Run() waitHealthy(t, runner, logBytes) @@ -598,7 +597,7 @@ func TestExtensionIsCleanedUp(t *testing.T) { func setupOsqueryInstanceForTests(t *testing.T) (runner *Runner, logBytes *threadsafebuffer.ThreadSafeBuffer, teardown func()) { rootDirectory := testRootDirectory(t) - logBytes, slogger, opts := setUpTestSlogger(rootDirectory) + logBytes, slogger := setUpTestSlogger() k := typesMocks.NewKnapsack(t) k.On("RegistrationIDs").Return([]string{types.DefaultRegistrationID}) @@ -619,7 +618,7 @@ func setupOsqueryInstanceForTests(t *testing.T) (runner *Runner, logBytes *threa k.On("ReadEnrollSecret").Return("", nil).Maybe() setUpMockStores(t, k) - runner = New(k, mockServiceClient(), opts...) + runner = New(k, mockServiceClient()) go runner.Run() waitHealthy(t, runner, logBytes) @@ -672,7 +671,7 @@ func mockServiceClient() *servicemock.KolideService { } // setUpTestSlogger sets up a logger that will log to a buffer. -func setUpTestSlogger(rootDirectory string) (*threadsafebuffer.ThreadSafeBuffer, *slog.Logger, []OsqueryInstanceOption) { +func setUpTestSlogger() (*threadsafebuffer.ThreadSafeBuffer, *slog.Logger) { logBytes := &threadsafebuffer.ThreadSafeBuffer{} slogger := slog.New(slog.NewTextHandler(logBytes, &slog.HandlerOptions{ @@ -680,27 +679,7 @@ func setUpTestSlogger(rootDirectory string) (*threadsafebuffer.ThreadSafeBuffer, Level: slog.LevelDebug, })) - // Capture osquery logs too - opts := []OsqueryInstanceOption{ - WithStdout(kolidelog.NewOsqueryLogAdapter( - slogger.With( - "component", "osquery", - "osqlevel", "stdout", - ), - rootDirectory, - kolidelog.WithLevel(slog.LevelDebug), - )), - WithStderr(kolidelog.NewOsqueryLogAdapter( - slogger.With( - "component", "osquery", - "osqlevel", "stderr", - ), - rootDirectory, - kolidelog.WithLevel(slog.LevelDebug), - )), - } - - return logBytes, slogger, opts + return logBytes, slogger } // testRootDirectory returns a temporary directory suitable for use in these tests.