diff --git a/changes/20231010192716.feature b/changes/20231010192716.feature new file mode 100644 index 0000000000..69b4b0c654 --- /dev/null +++ b/changes/20231010192716.feature @@ -0,0 +1 @@ +:sparkles: `[logs]` Added a `PlainStringLogger` to store only logged messages without prefixes or flags diff --git a/changes/20231010195032.feature b/changes/20231010195032.feature new file mode 100644 index 0000000000..f48cdeb8ba --- /dev/null +++ b/changes/20231010195032.feature @@ -0,0 +1 @@ +:sparkles: `[logs]` Added a `CombinedLoggers` to log into multiple loggers diff --git a/changes/20231010200309.feature b/changes/20231010200309.feature new file mode 100644 index 0000000000..1d2088d737 --- /dev/null +++ b/changes/20231010200309.feature @@ -0,0 +1 @@ +:sparkles: `[subprocess]` Added `Output` to store the output of a process into a string diff --git a/utils/logs/multiple_logger.go b/utils/logs/multiple_logger.go index 4306efa563..4aa921382f 100644 --- a/utils/logs/multiple_logger.go +++ b/utils/logs/multiple_logger.go @@ -99,6 +99,17 @@ func (c *MultipleLogger) AppendLogger(l ...logr.Logger) error { } func (c *MultipleLogger) Append(l ...Loggers) error { + c.mu.Lock() + defer c.mu.Unlock() + c.loggers = append(c.loggers, l...) + return nil +} + +type MultipleLoggerWithLoggerSource struct { + MultipleLogger +} + +func (c *MultipleLoggerWithLoggerSource) Append(l ...Loggers) error { c.mu.Lock() defer c.mu.Unlock() c.loggers = append(c.loggers, l...) @@ -107,12 +118,12 @@ func (c *MultipleLogger) Append(l ...Loggers) error { // NewMultipleLoggers returns a logger which abstracts and internally manages a list of loggers. // if no default loggers are provided, the logger will be set to print to the standard output. -func NewMultipleLoggers(loggerSource string, defaultLoggers ...Loggers) (l IMultipleLoggers, err error) { +func NewMultipleLoggers(loggerSource string, loggersList ...Loggers) (l IMultipleLoggers, err error) { if loggerSource == "" { err = commonerrors.ErrNoLoggerSource return } - list := defaultLoggers + list := loggersList if len(list) == 0 { std, err := NewStdLogger(loggerSource) if err != nil { @@ -120,7 +131,7 @@ func NewMultipleLoggers(loggerSource string, defaultLoggers ...Loggers) (l IMult } list = []Loggers{std} } - l = &MultipleLogger{} + l = &MultipleLoggerWithLoggerSource{} err = l.Append(list...) if err != nil { return @@ -128,3 +139,14 @@ func NewMultipleLoggers(loggerSource string, defaultLoggers ...Loggers) (l IMult err = l.SetLoggerSource(loggerSource) return } + +// NewCombinedLoggers returns a logger which logs to a list of logger. If list is empty, it will error. +func NewCombinedLoggers(loggersList ...Loggers) (l IMultipleLoggers, err error) { + if len(loggersList) == 0 { + err = commonerrors.ErrNoLogger + return + } + l = &MultipleLogger{} + err = l.Append(loggersList...) + return +} diff --git a/utils/logs/multiple_logger_test.go b/utils/logs/multiple_logger_test.go index 6b578ac2ca..d1823a3987 100644 --- a/utils/logs/multiple_logger_test.go +++ b/utils/logs/multiple_logger_test.go @@ -10,7 +10,10 @@ import ( "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + "github.com/ARM-software/golang-utils/utils/commonerrors" + "github.com/ARM-software/golang-utils/utils/commonerrors/errortest" "github.com/ARM-software/golang-utils/utils/filesystem" + "github.com/ARM-software/golang-utils/utils/logs/logstest" ) func TestMultipleLogger(t *testing.T) { @@ -19,6 +22,18 @@ func TestMultipleLogger(t *testing.T) { testLog(t, loggers) } +func TestCombinedLogger(t *testing.T) { + _, err := NewCombinedLoggers() + errortest.RequireError(t, err, commonerrors.ErrNoLogger) + testLogger, err := NewLogrLogger(logstest.NewTestLogger(t), "Test") + require.NoError(t, err) + nl, err := NewNoopLogger("Test2") + require.NoError(t, err) + loggers, err := NewCombinedLoggers(testLogger, nl) + require.NoError(t, err) + testLog(t, loggers) +} + func TestMultipleLoggers(t *testing.T) { // With default logger loggers, err := NewMultipleLoggers("Test Multiple") diff --git a/utils/logs/string_logger.go b/utils/logs/string_logger.go index 0ab421c7af..54f06c69e0 100644 --- a/utils/logs/string_logger.go +++ b/utils/logs/string_logger.go @@ -62,6 +62,7 @@ func (l *StringLoggers) Close() (err error) { } // NewStringLogger creates a logger to a string builder. +// All messages (whether they are output or error) are merged together. func NewStringLogger(loggerSource string) (loggers *StringLoggers, err error) { loggers = &StringLoggers{ LogWriter: StringWriter{}, @@ -73,6 +74,19 @@ func NewStringLogger(loggerSource string) (loggers *StringLoggers, err error) { return } +// NewPlainStringLogger creates a logger to a string builder with no extra flag, prefix or tag, just the logged text. +// All messages (whether they are output or error) are merged together. +func NewPlainStringLogger() (loggers *StringLoggers, err error) { + loggers = &StringLoggers{ + LogWriter: StringWriter{}, + } + loggers.GenericLoggers = GenericLoggers{ + Output: log.New(&loggers.LogWriter, "", 0), + Error: log.New(&loggers.LogWriter, "", 0), + } + return +} + // CreateStringLogger creates a logger to a string builder. // // Deprecated: Use NewStringLogger instead diff --git a/utils/logs/string_logger_test.go b/utils/logs/string_logger_test.go index 1290676897..3135a118ed 100644 --- a/utils/logs/string_logger_test.go +++ b/utils/logs/string_logger_test.go @@ -18,7 +18,19 @@ func TestStringLogger(t *testing.T) { loggers.LogError("Test err") loggers.Log("Test1") contents := loggers.GetLogContent() - require.NotZero(t, contents) + require.NotEmpty(t, contents) + require.True(t, strings.Contains(contents, "Test err")) + require.True(t, strings.Contains(contents, "Test1")) +} + +func TestPlainStringLogger(t *testing.T) { + loggers, err := NewPlainStringLogger() + require.NoError(t, err) + testLog(t, loggers) + loggers.LogError("Test err") + loggers.Log("Test1") + contents := loggers.GetLogContent() + require.NotEmpty(t, contents) require.True(t, strings.Contains(contents, "Test err")) require.True(t, strings.Contains(contents, "Test1")) } diff --git a/utils/subprocess/command_wrapper_test.go b/utils/subprocess/command_wrapper_test.go index 3d16fd6f87..c514c357ca 100644 --- a/utils/subprocess/command_wrapper_test.go +++ b/utils/subprocess/command_wrapper_test.go @@ -21,7 +21,7 @@ import ( func TestCmdRun(t *testing.T) { currentDir, err := os.Getwd() - require.Nil(t, err) + require.NoError(t, err) tests := []struct { name string @@ -52,7 +52,7 @@ func TestCmdRun(t *testing.T) { defer goleak.VerifyNone(t) var cmd *command loggers, err := logs.NewLogrLogger(logstest.NewTestLogger(t), "test") - require.Nil(t, err) + require.NoError(t, err) if platform.IsWindows() { cmd = newCommand(loggers, test.cmdWindows, test.argWindows...) } else { @@ -62,20 +62,20 @@ func TestCmdRun(t *testing.T) { defer cancel() wrapper := cmd.GetCmd(ctx) err = wrapper.Run() - require.Nil(t, err) + require.NoError(t, err) err = wrapper.Run() - require.NotNil(t, err) + require.Error(t, err) cmd.Reset() wrapper = cmd.GetCmd(ctx) err = wrapper.Run() - require.Nil(t, err) + require.NoError(t, err) }) } } func TestCmdStartStop(t *testing.T) { currentDir, err := os.Getwd() - require.Nil(t, err) + require.NoError(t, err) tests := []struct { name string @@ -106,7 +106,7 @@ func TestCmdStartStop(t *testing.T) { defer goleak.VerifyNone(t) var cmd *command loggers, err := logs.NewLogrLogger(logstest.NewTestLogger(t), "test") - require.Nil(t, err) + require.NoError(t, err) if platform.IsWindows() { cmd = newCommand(loggers, test.cmdWindows, test.argWindows...) @@ -117,14 +117,14 @@ func TestCmdStartStop(t *testing.T) { defer cancel() wrapper := cmd.GetCmd(ctx) err = wrapper.Start() - require.Nil(t, err) + require.NoError(t, err) pid, err := wrapper.Pid() - require.Nil(t, err) + require.NoError(t, err) assert.NotZero(t, pid) err = wrapper.Start() - require.NotNil(t, err) + require.Error(t, err) err = wrapper.Stop() - require.Nil(t, err) + require.NoError(t, err) }) } } diff --git a/utils/subprocess/executor.go b/utils/subprocess/executor.go index 2fcc4cdf6c..51b8baef15 100644 --- a/utils/subprocess/executor.go +++ b/utils/subprocess/executor.go @@ -2,7 +2,8 @@ * Copyright (C) 2020-2022 Arm Limited or its affiliates and Contributors. All rights reserved. * SPDX-License-Identifier: Apache-2.0 */ -// Package subprocess allows you to spawn new processes, retrieve their output/error pipes, and obtain their return codes. + +// Package subprocess allows you to spawn new processes, log their output/error and obtain their return codes. package subprocess import ( @@ -32,6 +33,12 @@ func New(ctx context.Context, loggers logs.Loggers, messageOnStart string, messa return } +func newPlainSubProcess(ctx context.Context, loggers logs.Loggers, cmd string, args ...string) (p *Subprocess, err error) { + p = new(Subprocess) + err = p.setup(ctx, loggers, false, "", "", "", cmd, args...) + return +} + // Execute executes a command (i.e. spawns a subprocess) func Execute(ctx context.Context, loggers logs.Loggers, messageOnStart string, messageOnSuccess, messageOnFailure string, cmd string, args ...string) (err error) { p, err := New(ctx, loggers, messageOnStart, messageOnSuccess, messageOnFailure, cmd, args...) @@ -41,8 +48,37 @@ func Execute(ctx context.Context, loggers logs.Loggers, messageOnStart string, m return p.Execute() } +// Output executes a command and returns its output (stdOutput and stdErr are merged) as string. +func Output(ctx context.Context, loggers logs.Loggers, cmd string, args ...string) (output string, err error) { + if loggers == nil { + err = commonerrors.ErrNoLogger + return + } + + stringLogger, err := logs.NewPlainStringLogger() + if err != nil { + return + } + mLoggers, err := logs.NewCombinedLoggers(loggers, stringLogger) + if err != nil { + return + } + p, err := newPlainSubProcess(ctx, mLoggers, cmd, args...) + if err != nil { + return + } + err = p.Execute() + output = stringLogger.GetLogContent() + return +} + // Setup sets up a sub-process i.e. defines the command cmd and the messages on start, success and failure. func (s *Subprocess) Setup(ctx context.Context, loggers logs.Loggers, messageOnStart string, messageOnSuccess, messageOnFailure string, cmd string, args ...string) (err error) { + return s.setup(ctx, loggers, true, messageOnStart, messageOnSuccess, messageOnFailure, cmd, args...) +} + +// Setup sets up a sub-process i.e. defines the command cmd and the messages on start, success and failure. +func (s *Subprocess) setup(ctx context.Context, loggers logs.Loggers, withAdditionalMessages bool, messageOnStart string, messageOnSuccess, messageOnFailure string, cmd string, args ...string) (err error) { if s.IsOn() { err = s.Stop() if err != nil { @@ -54,7 +90,7 @@ func (s *Subprocess) Setup(ctx context.Context, loggers logs.Loggers, messageOnS s.isRunning.Store(false) s.processMonitoring = newSubprocessMonitoring(ctx) s.command = newCommand(loggers, cmd, args...) - s.messsaging = newSubprocessMessaging(loggers, messageOnSuccess, messageOnFailure, messageOnStart, s.command.GetPath()) + s.messsaging = newSubprocessMessaging(loggers, withAdditionalMessages, messageOnSuccess, messageOnFailure, messageOnStart, s.command.GetPath()) s.reset() return s.check() } diff --git a/utils/subprocess/executor_test.go b/utils/subprocess/executor_test.go index 4a3fe062e2..b73fa24751 100644 --- a/utils/subprocess/executor_test.go +++ b/utils/subprocess/executor_test.go @@ -88,10 +88,10 @@ test 1 for i := range tests { for j, testInput := range tests[i].Inputs { loggers, err := logs.NewStringLogger("Test") // clean log between each test - require.Nil(t, err) + require.NoError(t, err) err = Execute(context.Background(), loggers, "", "", "", "echo", testInput) - require.Nil(t, err) + require.NoError(t, err) contents := loggers.GetLogContent() require.NotZero(t, contents) @@ -110,7 +110,7 @@ test 1 func TestStartStop(t *testing.T) { currentDir, err := os.Getwd() - require.Nil(t, err) + require.NoError(t, err) tests := []struct { name string cmdWindows string @@ -139,7 +139,7 @@ func TestStartStop(t *testing.T) { t.Run(test.name, func(t *testing.T) { defer goleak.VerifyNone(t) loggers, err := logs.NewLogrLogger(logstest.NewTestLogger(t), "test") - require.Nil(t, err) + require.NoError(t, err) var p *Subprocess if platform.IsWindows() { @@ -147,39 +147,39 @@ func TestStartStop(t *testing.T) { } else { p, err = New(context.Background(), loggers, "", "", "", test.cmdOther, test.argOther...) } - require.Nil(t, err) + require.NoError(t, err) require.NotNil(t, p) assert.False(t, p.IsOn()) err = p.Start() - require.Nil(t, err) + require.NoError(t, err) assert.True(t, p.IsOn()) // Checking idempotence err = p.Start() - require.Nil(t, err) + require.NoError(t, err) err = p.Check() - require.Nil(t, err) + require.NoError(t, err) time.Sleep(200 * time.Millisecond) err = p.Restart() - require.Nil(t, err) + require.NoError(t, err) assert.True(t, p.IsOn()) err = p.Stop() - require.Nil(t, err) + require.NoError(t, err) assert.False(t, p.IsOn()) // Checking idempotence err = p.Stop() - require.Nil(t, err) + require.NoError(t, err) time.Sleep(100 * time.Millisecond) err = p.Execute() - require.Nil(t, err) + require.NoError(t, err) }) } } func TestExecute(t *testing.T) { currentDir, err := os.Getwd() - require.Nil(t, err) + require.NoError(t, err) tests := []struct { name string cmdWindows string @@ -209,19 +209,67 @@ func TestExecute(t *testing.T) { defer goleak.VerifyNone(t) var loggers logs.Loggers = &logs.GenericLoggers{} err := loggers.Check() - assert.NotNil(t, err) + assert.Error(t, err) err = Execute(context.Background(), loggers, "", "", "", "ls") - assert.NotNil(t, err) + assert.Error(t, err) loggers, err = logs.NewLogrLogger(logstest.NewTestLogger(t), "test") - require.Nil(t, err) + require.NoError(t, err) if platform.IsWindows() { err = Execute(context.Background(), loggers, "", "", "", test.cmdWindows, test.argWindows...) } else { err = Execute(context.Background(), loggers, "", "", "", test.cmdOther, test.argOther...) } - require.Nil(t, err) + require.NoError(t, err) + }) + } +} + +func TestOutput(t *testing.T) { + currentDir, err := os.Getwd() + require.NoError(t, err) + tests := []struct { + name string + cmdWindows string + argWindows []string + cmdOther string + argOther []string + expectOutput bool + }{ + { + name: "ShortProcess", + cmdWindows: "cmd", + argWindows: []string{"dir", currentDir}, + cmdOther: "ls", + argOther: []string{"-l", currentDir}, + expectOutput: true, + }, + { + name: "LongProcess", + cmdWindows: "cmd", + argWindows: []string{"SLEEP 1"}, + cmdOther: "sleep", + argOther: []string{"1"}, + }, + } + + for i := range tests { + test := tests[i] + t.Run(test.name, func(t *testing.T) { + defer goleak.VerifyNone(t) + loggers, err := logs.NewLogrLogger(logstest.NewTestLogger(t), "testOutput") + require.NoError(t, err) + var output string + if platform.IsWindows() { + output, err = Output(context.Background(), loggers, test.cmdWindows, test.argWindows...) + } else { + output, err = Output(context.Background(), loggers, test.cmdOther, test.argOther...) + } + require.NoError(t, err) + if test.expectOutput { + assert.NotEmpty(t, output) + } }) } } @@ -248,7 +296,7 @@ func TestCancelledSubprocess(t *testing.T) { t.Run(test.name, func(t *testing.T) { defer goleak.VerifyNone(t) loggers, err := logs.NewLogrLogger(logstest.NewTestLogger(t), "test") - require.Nil(t, err) + require.NoError(t, err) cancellableCtx, cancelFunc := context.WithCancel(context.Background()) var p *Subprocess @@ -257,12 +305,12 @@ func TestCancelledSubprocess(t *testing.T) { } else { p, err = New(cancellableCtx, loggers, "", "", "", test.cmdOther, test.argOther...) } - require.Nil(t, err) + require.NoError(t, err) defer func() { _ = p.Stop() }() assert.False(t, p.IsOn()) err = p.Start() - require.Nil(t, err) + require.NoError(t, err) assert.True(t, p.IsOn()) time.Sleep(10 * time.Millisecond) cancelFunc() @@ -294,7 +342,7 @@ func TestCancelledSubprocess2(t *testing.T) { t.Run(test.name, func(t *testing.T) { defer goleak.VerifyNone(t) loggers, err := logs.NewLogrLogger(logstest.NewTestLogger(t), "test") - require.Nil(t, err) + require.NoError(t, err) ctx, cancelFunc := context.WithCancel(context.Background()) var p *Subprocess if platform.IsWindows() { @@ -302,7 +350,7 @@ func TestCancelledSubprocess2(t *testing.T) { } else { p, err = New(ctx, loggers, "", "", "", test.cmdOther, test.argOther...) } - require.Nil(t, err) + require.NoError(t, err) defer func() { _ = p.Stop() }() ready := make(chan bool) @@ -343,7 +391,7 @@ func TestCancelledSubprocess3(t *testing.T) { t.Run(test.name, func(t *testing.T) { defer goleak.VerifyNone(t) loggers, err := logs.NewLogrLogger(logstest.NewTestLogger(t), "test") - require.Nil(t, err) + require.NoError(t, err) ctx := context.Background() var p *Subprocess if platform.IsWindows() { @@ -351,7 +399,7 @@ func TestCancelledSubprocess3(t *testing.T) { } else { p, err = New(ctx, loggers, "", "", "", test.cmdOther, test.argOther...) } - require.Nil(t, err) + require.NoError(t, err) defer func() { _ = p.Stop() }() ready := make(chan bool) diff --git a/utils/subprocess/messaging.go b/utils/subprocess/messaging.go index 3fbbb944e1..f5c148a886 100644 --- a/utils/subprocess/messaging.go +++ b/utils/subprocess/messaging.go @@ -2,6 +2,7 @@ * Copyright (C) 2020-2022 Arm Limited or its affiliates and Contributors. All rights reserved. * SPDX-License-Identifier: Apache-2.0 */ + package subprocess import ( @@ -17,36 +18,48 @@ import ( // Messages logged // Object in charge of logging subprocess output. type subprocessMessaging struct { - loggers logs.Loggers - commandPath string - messageOnSuccess string - messageOnFailure string - messageOnProcessStart string - pid atomic.Int64 + loggers logs.Loggers + commandPath string + messageOnSuccess string + messageOnFailure string + messageOnProcessStart string + withAdditionalMessages bool + pid atomic.Int64 } // Logs subprocess start. func (s *subprocessMessaging) LogStart() { - s.loggers.Log(s.messageOnProcessStart) + if s.withAdditionalMessages { + s.loggers.Log(s.messageOnProcessStart) + } } // Logs when subprocess failed to start. func (s *subprocessMessaging) LogFailedStart(err error) { - s.loggers.LogError(fmt.Sprintf("Failed starting process `%v`: %v", s.commandPath, err)) + if s.withAdditionalMessages { + s.loggers.LogError(fmt.Sprintf("Failed starting process `%v`: %v", s.commandPath, err)) + } } // Logs when subprocess has started. func (s *subprocessMessaging) LogStarted() { - s.loggers.Log(fmt.Sprintf("Started process [%v]", s.pid.Load())) + if s.withAdditionalMessages { + s.loggers.Log(fmt.Sprintf("Started process [%v]", s.pid.Load())) + } } // Logs when subprocess is asked to stop. func (s *subprocessMessaging) LogStopping() { - s.loggers.Log(fmt.Sprintf("Stopping process [%v]", s.pid.Load())) + if s.withAdditionalMessages { + s.loggers.Log(fmt.Sprintf("Stopping process [%v]", s.pid.Load())) + } } // Logs subprocess end with err if an error occurred. func (s *subprocessMessaging) LogEnd(err error) { + if !s.withAdditionalMessages { + return + } if err == nil { s.loggers.Log(s.messageOnSuccess) } else { @@ -68,13 +81,14 @@ func (s *subprocessMessaging) Check() (err error) { return } -func newSubprocessMessaging(loggers logs.Loggers, messageOnSuccess string, messageOnFailure string, messageOnProcessStart string, commandPath string) *subprocessMessaging { +func newSubprocessMessaging(loggers logs.Loggers, withAdditionalMessages bool, messageOnSuccess string, messageOnFailure string, messageOnProcessStart string, commandPath string) *subprocessMessaging { m := &subprocessMessaging{ - loggers: loggers, - commandPath: commandPath, - messageOnSuccess: messageOnSuccess, - messageOnFailure: messageOnFailure, - messageOnProcessStart: messageOnProcessStart, + loggers: loggers, + commandPath: commandPath, + messageOnSuccess: messageOnSuccess, + messageOnFailure: messageOnFailure, + messageOnProcessStart: messageOnProcessStart, + withAdditionalMessages: withAdditionalMessages, } m.messageOnFailure = messageOnFailure if m.messageOnProcessStart == "" {