From 30ec4499184a69ffb12dabb80cd3d2ab98e612e2 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Wed, 6 Sep 2023 12:45:47 -0400 Subject: [PATCH 01/16] allow users to specify files for child process stdout/stderr --- command/agent.go | 7 +++- command/agent/config/config.go | 2 ++ command/agent/exec/exec.go | 65 ++++++++++++++++++++++++++++------ 3 files changed, 62 insertions(+), 12 deletions(-) diff --git a/command/agent.go b/command/agent.go index eb6adaccebb8..c59a852f1e28 100644 --- a/command/agent.go +++ b/command/agent.go @@ -729,13 +729,17 @@ func (c *AgentCommand) Run(args []string) int { ExitAfterAuth: config.ExitAfterAuth, }) - es := exec.NewServer(&exec.ServerConfig{ + es, err := exec.NewServer(&exec.ServerConfig{ AgentConfig: c.config, Namespace: templateNamespace, Logger: c.logger.Named("exec.server"), LogLevel: c.logger.GetLevel(), LogWriter: c.logWriter, }) + if err != nil { + c.logger.Error("could not create exec server", "error", err) + return 1 + } g.Add(func() error { return ah.Run(ctx, method) @@ -800,6 +804,7 @@ func (c *AgentCommand) Run(args []string) int { leaseCache.SetShuttingDown(true) } cancelFunc() + es.Close() }) } diff --git a/command/agent/config/config.go b/command/agent/config/config.go index a6dd769b071c..e2ccdd1f073c 100644 --- a/command/agent/config/config.go +++ b/command/agent/config/config.go @@ -171,6 +171,8 @@ type ExecConfig struct { Command []string `hcl:"command,attr" mapstructure:"command"` RestartOnSecretChanges string `hcl:"restart_on_secret_changes,optional" mapstructure:"restart_on_secret_changes"` RestartStopSignal os.Signal `hcl:"-" mapstructure:"restart_stop_signal"` + ChildProcessStdout string `mapstructure:"child_process_stdout"` + ChildProcessStderr string `mapstructure:"child_process_stderr"` } func NewConfig() *Config { diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 7ff3a92eda28..1e5585e6764d 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -65,9 +65,13 @@ type Server struct { logger hclog.Logger - childProcess *child.Child - childProcessState childProcessState - childProcessLock sync.Mutex + childProcess *child.Child + childProcessState childProcessState + childProcessLock sync.Mutex + childProcessStdout *os.File + childProcessStderr *os.File + childProcessCloseStdOut bool + childProcessCloseStderr bool // exit channel of the child process childProcessExitCh chan int @@ -85,15 +89,41 @@ func (e *ProcessExitError) Error() string { return fmt.Sprintf("process exited with %d", e.ExitCode) } -func NewServer(cfg *ServerConfig) *Server { +func NewServer(cfg *ServerConfig) (*Server, error) { + var err error + + childProcessCloseStdout := false + childProcessStdout := os.Stdout + if cfg.AgentConfig.Exec.ChildProcessStdout != "" { + childProcessStdout, err = os.OpenFile(cfg.AgentConfig.Exec.ChildProcessStdout, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) + if err != nil { + return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) + } + childProcessCloseStdout = true + } + + childProcessCloseStderr := false + childProcessStderr := os.Stderr + if cfg.AgentConfig.Exec.ChildProcessStderr != "" { + childProcessStderr, err = os.OpenFile(cfg.AgentConfig.Exec.ChildProcessStderr, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) + if err != nil { + return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) + } + childProcessCloseStderr = true + } + server := Server{ - logger: cfg.Logger, - config: cfg, - childProcessState: childProcessStateNotStarted, - childProcessExitCh: make(chan int), + logger: cfg.Logger, + config: cfg, + childProcessState: childProcessStateNotStarted, + childProcessExitCh: make(chan int), + childProcessStdout: childProcessStdout, + childProcessStderr: childProcessStderr, + childProcessCloseStdOut: childProcessCloseStdout, + childProcessCloseStderr: childProcessCloseStderr, } - return &server + return &server, nil } func (s *Server) Run(ctx context.Context, incomingVaultToken chan string) error { @@ -291,8 +321,8 @@ func (s *Server) restartChildProcess(newEnvVars []string) error { childInput := &child.NewInput{ Stdin: os.Stdin, - Stdout: os.Stdout, - Stderr: os.Stderr, + Stdout: s.childProcessStdout, + Stderr: s.childProcessStderr, Command: args[0], Args: args[1:], Timeout: 0, // let it run forever @@ -333,3 +363,16 @@ func (s *Server) restartChildProcess(newEnvVars []string) error { return nil } + +func (s *Server) Close() { + s.childProcessLock.Lock() + defer s.childProcessLock.Unlock() + + if s.childProcessCloseStdOut { + _ = s.childProcessStdout.Close() + } + + if s.childProcessCloseStderr { + _ = s.childProcessStderr.Close() + } +} From 4f5f7df8c94701ed4a0695c3c74666f2ac4586a2 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Wed, 6 Sep 2023 14:32:46 -0400 Subject: [PATCH 02/16] added changelog --- changelog/22812.txt | 3 +++ 1 file changed, 3 insertions(+) create mode 100644 changelog/22812.txt diff --git a/changelog/22812.txt b/changelog/22812.txt new file mode 100644 index 000000000000..a0161af8068f --- /dev/null +++ b/changelog/22812.txt @@ -0,0 +1,3 @@ +```release-note:improvement +agent: allow users to specify files for child process stdout/stderr +``` From e1a7af0247f895681f44f641558db8f136a153d4 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Fri, 8 Sep 2023 14:46:08 -0400 Subject: [PATCH 03/16] check if exec config is nil --- command/agent/exec/exec.go | 29 ++++++++++++++++------------- vault/seal/seal.go | 6 ++++-- 2 files changed, 20 insertions(+), 15 deletions(-) diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 1e5585e6764d..10105a5c513d 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -94,22 +94,25 @@ func NewServer(cfg *ServerConfig) (*Server, error) { childProcessCloseStdout := false childProcessStdout := os.Stdout - if cfg.AgentConfig.Exec.ChildProcessStdout != "" { - childProcessStdout, err = os.OpenFile(cfg.AgentConfig.Exec.ChildProcessStdout, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) - if err != nil { - return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) - } - childProcessCloseStdout = true - } - childProcessCloseStderr := false childProcessStderr := os.Stderr - if cfg.AgentConfig.Exec.ChildProcessStderr != "" { - childProcessStderr, err = os.OpenFile(cfg.AgentConfig.Exec.ChildProcessStderr, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) - if err != nil { - return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) + + if cfg.AgentConfig.Exec != nil { + if cfg.AgentConfig.Exec.ChildProcessStdout != "" { + childProcessStdout, err = os.OpenFile(cfg.AgentConfig.Exec.ChildProcessStdout, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644) + if err != nil { + return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) + } + childProcessCloseStdout = true + } + + if cfg.AgentConfig.Exec.ChildProcessStderr != "" { + childProcessStderr, err = os.OpenFile(cfg.AgentConfig.Exec.ChildProcessStderr, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644) + if err != nil { + return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) + } + childProcessCloseStderr = true } - childProcessCloseStderr = true } server := Server{ diff --git a/vault/seal/seal.go b/vault/seal/seal.go index 7935200a9dac..4c843e3b5273 100644 --- a/vault/seal/seal.go +++ b/vault/seal/seal.go @@ -291,8 +291,10 @@ func (a *access) AllSealWrappersHealthy() bool { return len(a.wrappersByPriority) == len(a.filterSealWrappers(enabledAndDisabled, healthyOnly)) } -type enabledFilter bool -type healthyFilter bool +type ( + enabledFilter bool + healthyFilter bool +) const ( enabledOnly = enabledFilter(true) From 13e87150a6fe3cea885935c0dd6541ef86c33854 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Fri, 8 Sep 2023 15:29:20 -0400 Subject: [PATCH 04/16] fix test --- command/agent/exec/exec_test.go | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/command/agent/exec/exec_test.go b/command/agent/exec/exec_test.go index d5f9eed6b00c..6177181f7b0c 100644 --- a/command/agent/exec/exec_test.go +++ b/command/agent/exec/exec_test.go @@ -257,7 +257,7 @@ func TestExecServer_Run(t *testing.T) { strconv.Itoa(testCase.testAppPort), } - execServer := NewServer(&ServerConfig{ + execServer, err := NewServer(&ServerConfig{ Logger: logging.NewVaultLogger(hclog.Trace), AgentConfig: &config.Config{ Vault: &config.Vault{ @@ -280,6 +280,9 @@ func TestExecServer_Run(t *testing.T) { LogLevel: hclog.Trace, LogWriter: hclog.DefaultOutput, }) + if err != nil { + t.Fatalf("could not create exec server: %q", err) + } // start the exec server var ( From 791ca7c1a68763eb6c4872428ff4cab20ad62a60 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Mon, 11 Sep 2023 13:46:47 -0400 Subject: [PATCH 05/16] first attempt at a test --- command/agent/exec/exec_test.go | 151 ++++++++++++++++++++++++++++++++ 1 file changed, 151 insertions(+) diff --git a/command/agent/exec/exec_test.go b/command/agent/exec/exec_test.go index 6177181f7b0c..4352b4eea8d7 100644 --- a/command/agent/exec/exec_test.go +++ b/command/agent/exec/exec_test.go @@ -8,6 +8,7 @@ import ( "encoding/json" "errors" "fmt" + "io" "net/http" "net/http/httptest" "os" @@ -383,3 +384,153 @@ func TestExecServer_Run(t *testing.T) { }) } } + +func TestExecServer_LogFiles(t *testing.T) { + goBinary, err := exec.LookPath("go") + if err != nil { + t.Fatalf("could not find go binary on path: %s", err) + } + + testAppBinary := filepath.Join(os.TempDir(), "test-app") + + if err := exec.Command(goBinary, "build", "-o", testAppBinary, "./test-app").Run(); err != nil { + t.Fatalf("could not build the test application: %s", err) + } + t.Cleanup(func() { + if err := os.Remove(testAppBinary); err != nil { + t.Fatalf("could not remove %q test application: %s", testAppBinary, err) + } + }) + + tempStdout := os.TempDir() + "/vault-exec-test.stdout.log" + t.Cleanup(func() { + _ = os.Remove(tempStdout) + }) + + testCases := map[string]struct { + testAppPort int + stdoutFile string + expectedError error + }{ + "can_log_to_file": { + testAppPort: 34001, + stdoutFile: tempStdout, + }, + } + + for tcName, testCase := range testCases { + t.Run(tcName, func(t *testing.T) { + fakeVault := fakeVaultServer(t) + defer fakeVault.Close() + + testAppCommand := []string{ + testAppBinary, + "--port", + strconv.Itoa(testCase.testAppPort), + "--stop-after", + "5s", + } + + execServer, err := NewServer(&ServerConfig{ + Logger: logging.NewVaultLogger(hclog.Trace), + AgentConfig: &config.Config{ + Vault: &config.Vault{ + Address: fakeVault.URL, + Retry: &config.Retry{ + NumRetries: 3, + }, + }, + Exec: &config.ExecConfig{ + RestartOnSecretChanges: "always", + Command: testAppCommand, + ChildProcessStdout: testCase.stdoutFile, + }, + EnvTemplates: []*ctconfig.TemplateConfig{{ + Contents: pointerutil.StringPtr(`{{ with secret "kv/my-app/creds" }}{{ .Data.data.user }}{{ end }}`), + MapToEnvironmentVariable: pointerutil.StringPtr("MY_USER"), + }}, + TemplateConfig: &config.TemplateConfig{ + ExitOnRetryFailure: true, + StaticSecretRenderInt: 5 * time.Second, + }, + }, + }) + if err != nil { + if testCase.expectedError != nil { + if errors.Is(err, testCase.expectedError) { + t.Log("test passes! caught expected err") + return + } else { + t.Fatalf("caught error %q did not match expected error %q", err, testCase.expectedError) + } + } + t.Fatalf("could not create exec server: %q", err) + } + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + // start the exec server + var ( + execServerErrCh = make(chan error) + execServerTokenCh = make(chan string, 1) + ) + go func() { + execServerErrCh <- execServer.Run(ctx, execServerTokenCh) + }() + + // send a dummy token to kick off the server + execServerTokenCh <- "my-token" + + // ensure the test app is running after 3 seconds + var ( + testAppAddr = fmt.Sprintf("http://localhost:%d", testCase.testAppPort) + testAppStartedCh = make(chan error) + ) + time.AfterFunc(500*time.Millisecond, func() { + _, err := retryablehttp.Head(testAppAddr) + testAppStartedCh <- err + }) + + select { + case <-ctx.Done(): + t.Fatal("timeout reached before templates were rendered") + + case err := <-execServerErrCh: + if testCase.expectedError == nil && err != nil { + t.Fatalf("exec server did not expect an error, got: %v", err) + } + + if errors.Is(err, testCase.expectedError) { + t.Fatalf("exec server expected error %v; got %v", testCase.expectedError, err) + } + + t.Log("exec server exited without an error") + + return + + case <-testAppStartedCh: + t.Log("test app started successfully") + } + + // stop the app + cancel() + + // does the stdlog file have content? + stdoutFile, err := os.Open(testCase.stdoutFile) + if err != nil { + t.Fatalf("could not open stdout file %q", err) + } + defer stdoutFile.Close() + + data, err := io.ReadAll(stdoutFile) + if err != nil { + t.Fatalf("could not read data from stdout file: %q", err) + } + + if len(data) == 0 { + t.Fatalf("stdout log file does not have any data!") + } + }) + } +} From 31b916556f31f8e2db1c6a6e0733d6478b2d221e Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Mon, 11 Sep 2023 14:21:43 -0400 Subject: [PATCH 06/16] revise test --- command/agent/exec/exec.go | 4 ++++ command/agent/exec/exec_test.go | 12 +++++++++--- 2 files changed, 13 insertions(+), 3 deletions(-) diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 10105a5c513d..3769f757efbe 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -185,6 +185,7 @@ func (s *Server) Run(ctx context.Context, incomingVaultToken chan string) error s.childProcess.Stop() } s.childProcessState = childProcessStateStopped + s.close() s.childProcessLock.Unlock() return nil @@ -370,7 +371,10 @@ func (s *Server) restartChildProcess(newEnvVars []string) error { func (s *Server) Close() { s.childProcessLock.Lock() defer s.childProcessLock.Unlock() + s.close() +} +func (s *Server) close() { if s.childProcessCloseStdOut { _ = s.childProcessStdout.Close() } diff --git a/command/agent/exec/exec_test.go b/command/agent/exec/exec_test.go index 4352b4eea8d7..2510d1858f86 100644 --- a/command/agent/exec/exec_test.go +++ b/command/agent/exec/exec_test.go @@ -402,7 +402,7 @@ func TestExecServer_LogFiles(t *testing.T) { } }) - tempStdout := os.TempDir() + "/vault-exec-test.stdout.log" + tempStdout := os.TempDir() + "vault-exec-test.stdout.log" t.Cleanup(func() { _ = os.Remove(tempStdout) }) @@ -428,7 +428,7 @@ func TestExecServer_LogFiles(t *testing.T) { "--port", strconv.Itoa(testCase.testAppPort), "--stop-after", - "5s", + "60s", } execServer, err := NewServer(&ServerConfig{ @@ -454,6 +454,8 @@ func TestExecServer_LogFiles(t *testing.T) { StaticSecretRenderInt: 5 * time.Second, }, }, + LogLevel: hclog.Trace, + LogWriter: hclog.DefaultOutput, }) if err != nil { if testCase.expectedError != nil { @@ -467,7 +469,7 @@ func TestExecServer_LogFiles(t *testing.T) { t.Fatalf("could not create exec server: %q", err) } - ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + ctx, cancel := context.WithCancel(context.Background()) defer cancel() // start the exec server @@ -513,8 +515,12 @@ func TestExecServer_LogFiles(t *testing.T) { t.Log("test app started successfully") } + // let the app run a bit + time.Sleep(5 * time.Second) // stop the app cancel() + // wait for app to stop + time.Sleep(5 * time.Second) // does the stdlog file have content? stdoutFile, err := os.Open(testCase.stdoutFile) From b01f929b4ff1c9eef117de0bf79100bdac85bfb6 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Mon, 11 Sep 2023 14:51:28 -0400 Subject: [PATCH 07/16] passing test --- command/agent/exec/exec.go | 4 ++-- command/agent/exec/exec_test.go | 37 +++++++++++++++++---------------- 2 files changed, 21 insertions(+), 20 deletions(-) diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 3769f757efbe..127651eded15 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -68,8 +68,8 @@ type Server struct { childProcess *child.Child childProcessState childProcessState childProcessLock sync.Mutex - childProcessStdout *os.File - childProcessStderr *os.File + childProcessStdout io.WriteCloser + childProcessStderr io.WriteCloser childProcessCloseStdOut bool childProcessCloseStderr bool diff --git a/command/agent/exec/exec_test.go b/command/agent/exec/exec_test.go index 2510d1858f86..2e0f317b4363 100644 --- a/command/agent/exec/exec_test.go +++ b/command/agent/exec/exec_test.go @@ -4,6 +4,7 @@ package exec import ( + "bytes" "context" "encoding/json" "errors" @@ -402,19 +403,19 @@ func TestExecServer_LogFiles(t *testing.T) { } }) - tempStdout := os.TempDir() + "vault-exec-test.stdout.log" + tempStderr := filepath.Join(os.TempDir(), "vault-exec-test.stderr.log") t.Cleanup(func() { - _ = os.Remove(tempStdout) + _ = os.Remove(tempStderr) }) testCases := map[string]struct { testAppPort int - stdoutFile string + stderrFile string expectedError error }{ "can_log_to_file": { testAppPort: 34001, - stdoutFile: tempStdout, + stderrFile: tempStderr, }, } @@ -443,7 +444,7 @@ func TestExecServer_LogFiles(t *testing.T) { Exec: &config.ExecConfig{ RestartOnSecretChanges: "always", Command: testAppCommand, - ChildProcessStdout: testCase.stdoutFile, + ChildProcessStderr: testCase.stderrFile, }, EnvTemplates: []*ctconfig.TemplateConfig{{ Contents: pointerutil.StringPtr(`{{ with secret "kv/my-app/creds" }}{{ .Data.data.user }}{{ end }}`), @@ -469,6 +470,10 @@ func TestExecServer_LogFiles(t *testing.T) { t.Fatalf("could not create exec server: %q", err) } + // replace the tempfile created with one owned by this test + var stdoutBuffer bytes.Buffer + execServer.childProcessStderr = noopCloser{&stdoutBuffer} + ctx, cancel := context.WithCancel(context.Background()) defer cancel() @@ -522,21 +527,17 @@ func TestExecServer_LogFiles(t *testing.T) { // wait for app to stop time.Sleep(5 * time.Second) - // does the stdlog file have content? - stdoutFile, err := os.Open(testCase.stdoutFile) - if err != nil { - t.Fatalf("could not open stdout file %q", err) - } - defer stdoutFile.Close() - - data, err := io.ReadAll(stdoutFile) - if err != nil { - t.Fatalf("could not read data from stdout file: %q", err) - } - - if len(data) == 0 { + if stdoutBuffer.Len() == 0 { t.Fatalf("stdout log file does not have any data!") } }) } } + +type noopCloser struct { + io.Writer +} + +func (_ noopCloser) Close() error { + return nil +} From e24d1ef771a46130997e9b77a32e0b12182ba6a1 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Mon, 11 Sep 2023 14:56:10 -0400 Subject: [PATCH 08/16] added failing test --- command/agent/exec/exec_test.go | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/command/agent/exec/exec_test.go b/command/agent/exec/exec_test.go index 2e0f317b4363..443978338811 100644 --- a/command/agent/exec/exec_test.go +++ b/command/agent/exec/exec_test.go @@ -417,6 +417,11 @@ func TestExecServer_LogFiles(t *testing.T) { testAppPort: 34001, stderrFile: tempStderr, }, + "cant_open_file": { + testAppPort: 34002, + stderrFile: "/file/does/not/exist", + expectedError: os.ErrNotExist, + }, } for tcName, testCase := range testCases { From 6d4e92d48d79b12d36afc6d035e36527c27379dd Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Tue, 12 Sep 2023 10:54:56 -0400 Subject: [PATCH 09/16] Apply suggestions from code review Co-authored-by: Anton Averchenkov <84287187+averche@users.noreply.github.com> --- command/agent/exec/exec.go | 2 +- command/agent/exec/exec_test.go | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 127651eded15..9d3398478c0d 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -70,7 +70,7 @@ type Server struct { childProcessLock sync.Mutex childProcessStdout io.WriteCloser childProcessStderr io.WriteCloser - childProcessCloseStdOut bool + childProcessCloseStdout bool childProcessCloseStderr bool // exit channel of the child process diff --git a/command/agent/exec/exec_test.go b/command/agent/exec/exec_test.go index 443978338811..562b004dc9ae 100644 --- a/command/agent/exec/exec_test.go +++ b/command/agent/exec/exec_test.go @@ -494,7 +494,7 @@ func TestExecServer_LogFiles(t *testing.T) { // send a dummy token to kick off the server execServerTokenCh <- "my-token" - // ensure the test app is running after 3 seconds + // ensure the test app is running after 500ms var ( testAppAddr = fmt.Sprintf("http://localhost:%d", testCase.testAppPort) testAppStartedCh = make(chan error) From 16c12b2c20348fe8d6030fa1457561589bf7ba80 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Tue, 12 Sep 2023 10:58:39 -0400 Subject: [PATCH 10/16] code review suggestions --- command/agent/exec/exec.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 9d3398478c0d..524e9ddef657 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -122,7 +122,7 @@ func NewServer(cfg *ServerConfig) (*Server, error) { childProcessExitCh: make(chan int), childProcessStdout: childProcessStdout, childProcessStderr: childProcessStderr, - childProcessCloseStdOut: childProcessCloseStdout, + childProcessCloseStdout: childProcessCloseStdout, childProcessCloseStderr: childProcessCloseStderr, } @@ -375,7 +375,7 @@ func (s *Server) Close() { } func (s *Server) close() { - if s.childProcessCloseStdOut { + if s.childProcessCloseStdout { _ = s.childProcessStdout.Close() } From 3ba1c92b99d9ff1bd10a5db21bfe2490a0b5e9a3 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Tue, 12 Sep 2023 11:16:45 -0400 Subject: [PATCH 11/16] always close log files --- command/agent/exec/exec.go | 39 +++++++++++++------------------------- 1 file changed, 13 insertions(+), 26 deletions(-) diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 524e9ddef657..80fa2d44d74b 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -65,13 +65,11 @@ type Server struct { logger hclog.Logger - childProcess *child.Child - childProcessState childProcessState - childProcessLock sync.Mutex - childProcessStdout io.WriteCloser - childProcessStderr io.WriteCloser - childProcessCloseStdout bool - childProcessCloseStderr bool + childProcess *child.Child + childProcessState childProcessState + childProcessLock sync.Mutex + childProcessStdout io.WriteCloser + childProcessStderr io.WriteCloser // exit channel of the child process childProcessExitCh chan int @@ -92,9 +90,7 @@ func (e *ProcessExitError) Error() string { func NewServer(cfg *ServerConfig) (*Server, error) { var err error - childProcessCloseStdout := false childProcessStdout := os.Stdout - childProcessCloseStderr := false childProcessStderr := os.Stderr if cfg.AgentConfig.Exec != nil { @@ -103,7 +99,6 @@ func NewServer(cfg *ServerConfig) (*Server, error) { if err != nil { return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) } - childProcessCloseStdout = true } if cfg.AgentConfig.Exec.ChildProcessStderr != "" { @@ -111,19 +106,16 @@ func NewServer(cfg *ServerConfig) (*Server, error) { if err != nil { return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) } - childProcessCloseStderr = true } } server := Server{ - logger: cfg.Logger, - config: cfg, - childProcessState: childProcessStateNotStarted, - childProcessExitCh: make(chan int), - childProcessStdout: childProcessStdout, - childProcessStderr: childProcessStderr, - childProcessCloseStdout: childProcessCloseStdout, - childProcessCloseStderr: childProcessCloseStderr, + logger: cfg.Logger, + config: cfg, + childProcessState: childProcessStateNotStarted, + childProcessExitCh: make(chan int), + childProcessStdout: childProcessStdout, + childProcessStderr: childProcessStderr, } return &server, nil @@ -375,11 +367,6 @@ func (s *Server) Close() { } func (s *Server) close() { - if s.childProcessCloseStdout { - _ = s.childProcessStdout.Close() - } - - if s.childProcessCloseStderr { - _ = s.childProcessStderr.Close() - } + _ = s.childProcessStdout.Close() + _ = s.childProcessStderr.Close() } From 8f9d2c285f72d69a9182997d2f3e972e96dd0388 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Tue, 12 Sep 2023 11:46:18 -0400 Subject: [PATCH 12/16] refactor to use real files --- command/agent/exec/exec_test.go | 81 ++++++++++++++++++----------- command/agent/exec/test-app/main.go | 9 +++- 2 files changed, 58 insertions(+), 32 deletions(-) diff --git a/command/agent/exec/exec_test.go b/command/agent/exec/exec_test.go index 562b004dc9ae..dc1bd394c7a5 100644 --- a/command/agent/exec/exec_test.go +++ b/command/agent/exec/exec_test.go @@ -4,12 +4,10 @@ package exec import ( - "bytes" "context" "encoding/json" "errors" "fmt" - "io" "net/http" "net/http/httptest" "os" @@ -403,19 +401,22 @@ func TestExecServer_LogFiles(t *testing.T) { } }) - tempStderr := filepath.Join(os.TempDir(), "vault-exec-test.stderr.log") - t.Cleanup(func() { - _ = os.Remove(tempStderr) - }) - testCases := map[string]struct { - testAppPort int - stderrFile string + testAppPort int + testAppArgs []string + stderrFile string + stdoutFile string + expectedError error }{ - "can_log_to_file": { + "can_log_stderr_to_file": { testAppPort: 34001, - stderrFile: tempStderr, + stderrFile: "vault-exec-test.stderr.log", + }, + "can_log_stdout_to_file": { + testAppPort: 34001, + stdoutFile: "vault-exec-test.stdout.log", + testAppArgs: []string{"-log-to-stdout"}, }, "cant_open_file": { testAppPort: 34002, @@ -437,6 +438,25 @@ func TestExecServer_LogFiles(t *testing.T) { "60s", } + execConfig := &config.ExecConfig{ + RestartOnSecretChanges: "always", + Command: append(testAppCommand, testCase.testAppArgs...), + } + + if testCase.stdoutFile != "" { + execConfig.ChildProcessStdout = filepath.Join(os.TempDir(), "vault-agent-exec.stdout.log") + t.Cleanup(func() { + _ = os.Remove(execConfig.ChildProcessStdout) + }) + } + + if testCase.stderrFile != "" { + execConfig.ChildProcessStderr = filepath.Join(os.TempDir(), "vault-agent-exec.stderr.log") + t.Cleanup(func() { + _ = os.Remove(execConfig.ChildProcessStderr) + }) + } + execServer, err := NewServer(&ServerConfig{ Logger: logging.NewVaultLogger(hclog.Trace), AgentConfig: &config.Config{ @@ -446,11 +466,7 @@ func TestExecServer_LogFiles(t *testing.T) { NumRetries: 3, }, }, - Exec: &config.ExecConfig{ - RestartOnSecretChanges: "always", - Command: testAppCommand, - ChildProcessStderr: testCase.stderrFile, - }, + Exec: execConfig, EnvTemplates: []*ctconfig.TemplateConfig{{ Contents: pointerutil.StringPtr(`{{ with secret "kv/my-app/creds" }}{{ .Data.data.user }}{{ end }}`), MapToEnvironmentVariable: pointerutil.StringPtr("MY_USER"), @@ -475,10 +491,6 @@ func TestExecServer_LogFiles(t *testing.T) { t.Fatalf("could not create exec server: %q", err) } - // replace the tempfile created with one owned by this test - var stdoutBuffer bytes.Buffer - execServer.childProcessStderr = noopCloser{&stdoutBuffer} - ctx, cancel := context.WithCancel(context.Background()) defer cancel() @@ -532,17 +544,26 @@ func TestExecServer_LogFiles(t *testing.T) { // wait for app to stop time.Sleep(5 * time.Second) - if stdoutBuffer.Len() == 0 { - t.Fatalf("stdout log file does not have any data!") + // check if the files have content + if testCase.stdoutFile != "" { + stdoutInfo, err := os.Stat(execConfig.ChildProcessStdout) + if err != nil { + t.Fatalf("error calling stat on stdout file: %q", err) + } + if stdoutInfo.Size() == 0 { + t.Fatalf("stdout log file does not haev any data!") + } + } + + if testCase.stderrFile != "" { + stderrInfo, err := os.Stat(execConfig.ChildProcessStderr) + if err != nil { + t.Fatalf("error calling stat on stdout file: %q", err) + } + if stderrInfo.Size() == 0 { + t.Fatalf("stdout log file does not haev any data!") + } } }) } } - -type noopCloser struct { - io.Writer -} - -func (_ noopCloser) Close() error { - return nil -} diff --git a/command/agent/exec/test-app/main.go b/command/agent/exec/test-app/main.go index 5c42cf71c337..a310e9c435c8 100644 --- a/command/agent/exec/test-app/main.go +++ b/command/agent/exec/test-app/main.go @@ -29,11 +29,11 @@ import ( var ( port uint - ignoreStopSignal bool sleepAfterStopSignal time.Duration useSigusr1StopSignal bool stopAfter time.Duration exitCode int + logToStdout bool ) func init() { @@ -42,6 +42,7 @@ func init() { flag.BoolVar(&useSigusr1StopSignal, "use-sigusr1", false, "use SIGUSR1 as the stop signal, instead of the default SIGTERM") flag.DurationVar(&stopAfter, "stop-after", 0, "stop the process after duration (overrides all other flags if set)") flag.IntVar(&exitCode, "exit-code", 0, "exit code to return when this script exits") + flag.BoolVar(&logToStdout, "log-to-stdout", false, "log to stdout instead of stderr") } type Response struct { @@ -78,7 +79,11 @@ func handler(w http.ResponseWriter, r *http.Request) { } func main() { - logger := log.New(os.Stderr, "test-app: ", log.LstdFlags) + logOut := os.Stderr + if logToStdout { + logOut = os.Stdout + } + logger := log.New(logOut, "test-app: ", log.LstdFlags) if err := run(logger); err != nil { log.Fatalf("error: %v\n", err) From ae81328dbd56b6b6fffbc40f09567bb0c33bf395 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Tue, 12 Sep 2023 12:05:12 -0400 Subject: [PATCH 13/16] hopefully fixed tests --- command/agent/exec/exec_test.go | 10 +++++----- command/agent/exec/test-app/main.go | 5 +++-- 2 files changed, 8 insertions(+), 7 deletions(-) diff --git a/command/agent/exec/exec_test.go b/command/agent/exec/exec_test.go index dc1bd394c7a5..feeded482348 100644 --- a/command/agent/exec/exec_test.go +++ b/command/agent/exec/exec_test.go @@ -414,12 +414,12 @@ func TestExecServer_LogFiles(t *testing.T) { stderrFile: "vault-exec-test.stderr.log", }, "can_log_stdout_to_file": { - testAppPort: 34001, + testAppPort: 34002, stdoutFile: "vault-exec-test.stdout.log", testAppArgs: []string{"-log-to-stdout"}, }, "cant_open_file": { - testAppPort: 34002, + testAppPort: 34003, stderrFile: "/file/does/not/exist", expectedError: os.ErrNotExist, }, @@ -551,17 +551,17 @@ func TestExecServer_LogFiles(t *testing.T) { t.Fatalf("error calling stat on stdout file: %q", err) } if stdoutInfo.Size() == 0 { - t.Fatalf("stdout log file does not haev any data!") + t.Fatalf("stdout log file does not have any data!") } } if testCase.stderrFile != "" { stderrInfo, err := os.Stat(execConfig.ChildProcessStderr) if err != nil { - t.Fatalf("error calling stat on stdout file: %q", err) + t.Fatalf("error calling stat on stderr file: %q", err) } if stderrInfo.Size() == 0 { - t.Fatalf("stdout log file does not haev any data!") + t.Fatalf("stderr log file does not have any data!") } } }) diff --git a/command/agent/exec/test-app/main.go b/command/agent/exec/test-app/main.go index a310e9c435c8..db8845aa6055 100644 --- a/command/agent/exec/test-app/main.go +++ b/command/agent/exec/test-app/main.go @@ -79,12 +79,15 @@ func handler(w http.ResponseWriter, r *http.Request) { } func main() { + flag.Parse() + logOut := os.Stderr if logToStdout { logOut = os.Stdout } logger := log.New(logOut, "test-app: ", log.LstdFlags) + logger.Printf("running on port %d", port) if err := run(logger); err != nil { log.Fatalf("error: %v\n", err) } @@ -101,8 +104,6 @@ func run(logger *log.Logger) error { ctx, cancelContextFunc := context.WithTimeout(context.Background(), 60*time.Second) defer cancelContextFunc() - flag.Parse() - server := http.Server{ Addr: fmt.Sprintf(":%d", port), Handler: http.HandlerFunc(handler), From 7e93456d3c55cd8a46e51b1d84829759af8caf1c Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Tue, 12 Sep 2023 13:02:08 -0400 Subject: [PATCH 14/16] add back bool gates so we don't close global stdout/stderr --- command/agent/exec/exec.go | 38 +++++++++++++++++++++++++------------- 1 file changed, 25 insertions(+), 13 deletions(-) diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 80fa2d44d74b..2cb4b52c29c4 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -65,11 +65,13 @@ type Server struct { logger hclog.Logger - childProcess *child.Child - childProcessState childProcessState - childProcessLock sync.Mutex - childProcessStdout io.WriteCloser - childProcessStderr io.WriteCloser + childProcess *child.Child + childProcessState childProcessState + childProcessLock sync.Mutex + childProcessStdout io.WriteCloser + childProcessStderr io.WriteCloser + childProcessCloseStdout bool + childProcessCloseStderr bool // exit channel of the child process childProcessExitCh chan int @@ -92,6 +94,8 @@ func NewServer(cfg *ServerConfig) (*Server, error) { childProcessStdout := os.Stdout childProcessStderr := os.Stderr + childProcessCloseStdout := false + childProcessCloseStderr := false if cfg.AgentConfig.Exec != nil { if cfg.AgentConfig.Exec.ChildProcessStdout != "" { @@ -99,6 +103,7 @@ func NewServer(cfg *ServerConfig) (*Server, error) { if err != nil { return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) } + childProcessCloseStdout = true } if cfg.AgentConfig.Exec.ChildProcessStderr != "" { @@ -106,16 +111,19 @@ func NewServer(cfg *ServerConfig) (*Server, error) { if err != nil { return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) } + childProcessCloseStderr = true } } server := Server{ - logger: cfg.Logger, - config: cfg, - childProcessState: childProcessStateNotStarted, - childProcessExitCh: make(chan int), - childProcessStdout: childProcessStdout, - childProcessStderr: childProcessStderr, + logger: cfg.Logger, + config: cfg, + childProcessState: childProcessStateNotStarted, + childProcessExitCh: make(chan int), + childProcessStdout: childProcessStdout, + childProcessStderr: childProcessStderr, + childProcessCloseStdout: childProcessCloseStdout, + childProcessCloseStderr: childProcessCloseStderr, } return &server, nil @@ -367,6 +375,10 @@ func (s *Server) Close() { } func (s *Server) close() { - _ = s.childProcessStdout.Close() - _ = s.childProcessStderr.Close() + if s.childProcessCloseStdout { + _ = s.childProcessStdout.Close() + } + if s.childProcessCloseStderr { + _ = s.childProcessStderr.Close() + } } From 24c85de182578e0bce3f94134515376d6e870f69 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Tue, 12 Sep 2023 13:04:47 -0400 Subject: [PATCH 15/16] compare to os.Stdout/os.Stderr --- command/agent/exec/exec.go | 22 ++++++++-------------- 1 file changed, 8 insertions(+), 14 deletions(-) diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 2cb4b52c29c4..3f44126171df 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -94,8 +94,6 @@ func NewServer(cfg *ServerConfig) (*Server, error) { childProcessStdout := os.Stdout childProcessStderr := os.Stderr - childProcessCloseStdout := false - childProcessCloseStderr := false if cfg.AgentConfig.Exec != nil { if cfg.AgentConfig.Exec.ChildProcessStdout != "" { @@ -103,7 +101,6 @@ func NewServer(cfg *ServerConfig) (*Server, error) { if err != nil { return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) } - childProcessCloseStdout = true } if cfg.AgentConfig.Exec.ChildProcessStderr != "" { @@ -111,19 +108,16 @@ func NewServer(cfg *ServerConfig) (*Server, error) { if err != nil { return nil, fmt.Errorf("could not open %q, %w", cfg.AgentConfig.Exec.ChildProcessStdout, err) } - childProcessCloseStderr = true } } server := Server{ - logger: cfg.Logger, - config: cfg, - childProcessState: childProcessStateNotStarted, - childProcessExitCh: make(chan int), - childProcessStdout: childProcessStdout, - childProcessStderr: childProcessStderr, - childProcessCloseStdout: childProcessCloseStdout, - childProcessCloseStderr: childProcessCloseStderr, + logger: cfg.Logger, + config: cfg, + childProcessState: childProcessStateNotStarted, + childProcessExitCh: make(chan int), + childProcessStdout: childProcessStdout, + childProcessStderr: childProcessStderr, } return &server, nil @@ -375,10 +369,10 @@ func (s *Server) Close() { } func (s *Server) close() { - if s.childProcessCloseStdout { + if s.childProcessStdout != os.Stdout { _ = s.childProcessStdout.Close() } - if s.childProcessCloseStderr { + if s.childProcessStderr != os.Stderr { _ = s.childProcessStderr.Close() } } From ab3a406b16c4d9240da3d36ecd777454c32a6033 Mon Sep 17 00:00:00 2001 From: Daniel Huckins Date: Tue, 12 Sep 2023 13:26:05 -0400 Subject: [PATCH 16/16] remove unused --- command/agent/exec/exec.go | 12 +++++------- 1 file changed, 5 insertions(+), 7 deletions(-) diff --git a/command/agent/exec/exec.go b/command/agent/exec/exec.go index 3f44126171df..456b1d8ffccf 100644 --- a/command/agent/exec/exec.go +++ b/command/agent/exec/exec.go @@ -65,13 +65,11 @@ type Server struct { logger hclog.Logger - childProcess *child.Child - childProcessState childProcessState - childProcessLock sync.Mutex - childProcessStdout io.WriteCloser - childProcessStderr io.WriteCloser - childProcessCloseStdout bool - childProcessCloseStderr bool + childProcess *child.Child + childProcessState childProcessState + childProcessLock sync.Mutex + childProcessStdout io.WriteCloser + childProcessStderr io.WriteCloser // exit channel of the child process childProcessExitCh chan int