Skip to content
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
2 changes: 1 addition & 1 deletion test/e2e/fixture/applicationsets/utils/cmd.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@ import (
"os/exec"
"strings"

argoexec "github.com/argoproj/pkg/exec"
argoexec "github.com/argoproj/argo-cd/v3/util/exec"
)

func Run(workDir, name string, args ...string) (string, error) {
Expand Down
2 changes: 1 addition & 1 deletion test/e2e/fixture/cmd.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@ import (
"os/exec"
"strings"

argoexec "github.com/argoproj/pkg/exec"
argoexec "github.com/argoproj/argo-cd/v3/util/exec"
)

func Run(workDir, name string, args ...string) (string, error) {
Expand Down
3 changes: 1 addition & 2 deletions test/fixture/revision_metadata/author.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,9 +4,8 @@ import (
"fmt"
"strings"

argoexec "github.com/argoproj/pkg/exec"

"github.com/argoproj/argo-cd/v3/util/errors"
argoexec "github.com/argoproj/argo-cd/v3/util/exec"
)

var Author string
Expand Down
2 changes: 1 addition & 1 deletion test/manifests_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,11 +6,11 @@ import (
"path/filepath"
"testing"

argoexec "github.com/argoproj/pkg/exec"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"

"github.com/argoproj/argo-cd/v3/test/fixture/test"
argoexec "github.com/argoproj/argo-cd/v3/util/exec"
)

func TestKustomizeVersion(t *testing.T) {
Expand Down
170 changes: 165 additions & 5 deletions util/exec/exec.go
Original file line number Diff line number Diff line change
@@ -1,27 +1,34 @@
package exec

import (
"bytes"
"errors"
"fmt"
"os"
"os/exec"
"strconv"
"strings"
"syscall"
"time"
"unicode"

"github.com/argoproj/gitops-engine/pkg/utils/tracing"
argoexec "github.com/argoproj/pkg/exec"
"github.com/sirupsen/logrus"

"github.com/argoproj/argo-cd/v3/util/log"
"github.com/argoproj/argo-cd/v3/util/rand"
)

var timeout time.Duration
var (
timeout time.Duration
Unredacted = Redact(nil)
)

type ExecRunOpts struct {
// Redactor redacts tokens from the output
Redactor func(text string) string
// TimeoutBehavior configures what to do in case of timeout
TimeoutBehavior argoexec.TimeoutBehavior
TimeoutBehavior TimeoutBehavior
// SkipErrorLogging determines whether to skip logging of execution errors (rc > 0)
SkipErrorLogging bool
// CaptureStderr determines whether to capture stderr in addition to stdout
Expand Down Expand Up @@ -50,7 +57,7 @@ func RunWithRedactor(cmd *exec.Cmd, redactor func(text string) string) (string,
}

func RunWithExecRunOpts(cmd *exec.Cmd, opts ExecRunOpts) (string, error) {
cmdOpts := argoexec.CmdOpts{Timeout: timeout, Redactor: opts.Redactor, TimeoutBehavior: opts.TimeoutBehavior, SkipErrorLogging: opts.SkipErrorLogging}
cmdOpts := CmdOpts{Timeout: timeout, Redactor: opts.Redactor, TimeoutBehavior: opts.TimeoutBehavior, SkipErrorLogging: opts.SkipErrorLogging}
span := tracing.NewLoggingTracer(log.NewLogrusLogger(log.NewWithCurrentConfig())).StartSpan(fmt.Sprintf("exec %v", cmd.Args[0]))
span.SetBaggageItem("dir", cmd.Dir)
if cmdOpts.Redactor != nil {
Expand All @@ -59,7 +66,7 @@ func RunWithExecRunOpts(cmd *exec.Cmd, opts ExecRunOpts) (string, error) {
span.SetBaggageItem("args", fmt.Sprintf("%v", cmd.Args))
}
defer span.Finish()
return argoexec.RunCommandExt(cmd, cmdOpts)
return RunCommandExt(cmd, cmdOpts)
}

// GetCommandArgsToLog represents the given command in a way that we can copy-and-paste into a terminal
Expand Down Expand Up @@ -88,3 +95,156 @@ func GetCommandArgsToLog(cmd *exec.Cmd) string {
args := strings.Join(argsToLog, " ")
return args
}

type CmdError struct {
Args string
Stderr string
Cause error
}

func (ce *CmdError) Error() string {
res := fmt.Sprintf("`%v` failed %v", ce.Args, ce.Cause)
if ce.Stderr != "" {
res = fmt.Sprintf("%s: %s", res, ce.Stderr)
}
return res
}

func (ce *CmdError) String() string {
return ce.Error()
}

func newCmdError(args string, cause error, stderr string) *CmdError {
return &CmdError{Args: args, Stderr: stderr, Cause: cause}
}

// TimeoutBehavior defines behavior for when the command takes longer than the passed in timeout to exit
// By default, SIGKILL is sent to the process and it is not waited upon
type TimeoutBehavior struct {
// Signal determines the signal to send to the process
Signal syscall.Signal
// ShouldWait determines whether to wait for the command to exit once timeout is reached
ShouldWait bool
}

type CmdOpts struct {
// Timeout determines how long to wait for the command to exit
Timeout time.Duration
// Redactor redacts tokens from the output
Redactor func(text string) string
// TimeoutBehavior configures what to do in case of timeout
TimeoutBehavior TimeoutBehavior
// SkipErrorLogging defines whether to skip logging of execution errors (rc > 0)
SkipErrorLogging bool
// CaptureStderr defines whether to capture stderr in addition to stdout
CaptureStderr bool
}

var DefaultCmdOpts = CmdOpts{
Timeout: time.Duration(0),
Redactor: Unredacted,
TimeoutBehavior: TimeoutBehavior{syscall.SIGKILL, false},
SkipErrorLogging: false,
CaptureStderr: false,
}

func Redact(items []string) func(text string) string {
return func(text string) string {
for _, item := range items {
text = strings.ReplaceAll(text, item, "******")
}
return text
}
}

// RunCommandExt is a convenience function to run/log a command and return/log stderr in an error upon
// failure.
func RunCommandExt(cmd *exec.Cmd, opts CmdOpts) (string, error) {
execId, err := rand.RandHex(5)
if err != nil {
return "", err
}
logCtx := logrus.WithFields(logrus.Fields{"execID": execId})

redactor := DefaultCmdOpts.Redactor
if opts.Redactor != nil {
redactor = opts.Redactor
}

// log in a way we can copy-and-paste into a terminal
args := strings.Join(cmd.Args, " ")
logCtx.WithFields(logrus.Fields{"dir": cmd.Dir}).Info(redactor(args))

var stdout bytes.Buffer
var stderr bytes.Buffer
cmd.Stdout = &stdout
cmd.Stderr = &stderr

start := time.Now()
err = cmd.Start()
if err != nil {
return "", err
}

done := make(chan error)
go func() { done <- cmd.Wait() }()

// Start a timer
timeout := DefaultCmdOpts.Timeout

if opts.Timeout != time.Duration(0) {
timeout = opts.Timeout
}

var timoutCh <-chan time.Time
if timeout != 0 {
timoutCh = time.NewTimer(timeout).C
}

timeoutBehavior := DefaultCmdOpts.TimeoutBehavior
if opts.TimeoutBehavior.Signal != syscall.Signal(0) {
timeoutBehavior = opts.TimeoutBehavior
}

select {
// noinspection ALL
case <-timoutCh:
_ = cmd.Process.Signal(timeoutBehavior.Signal)
if timeoutBehavior.ShouldWait {
<-done
}
output := stdout.String()
if opts.CaptureStderr {
output += stderr.String()
}
logCtx.WithFields(logrus.Fields{"duration": time.Since(start)}).Debug(redactor(output))
err = newCmdError(redactor(args), fmt.Errorf("timeout after %v", timeout), "")
logCtx.Error(err.Error())
return strings.TrimSuffix(output, "\n"), err
case err := <-done:
if err != nil {
output := stdout.String()
if opts.CaptureStderr {
output += stderr.String()
}
logCtx.WithFields(logrus.Fields{"duration": time.Since(start)}).Debug(redactor(output))
err := newCmdError(redactor(args), errors.New(redactor(err.Error())), strings.TrimSpace(redactor(stderr.String())))
if !opts.SkipErrorLogging {
logCtx.Error(err.Error())
}
return strings.TrimSuffix(output, "\n"), err
}
}

output := stdout.String()
if opts.CaptureStderr {
output += stderr.String()
}
logCtx.WithFields(logrus.Fields{"duration": time.Since(start)}).Debug(redactor(output))

return strings.TrimSuffix(output, "\n"), nil
}

func RunCommand(name string, opts CmdOpts, arg ...string) (string, error) {
return RunCommandExt(exec.Command(name, arg...), opts)
}
44 changes: 44 additions & 0 deletions util/exec/exec_norace_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,44 @@
//go:build !race

package exec

import (
"testing"
"time"

log "github.com/sirupsen/logrus"
"github.com/sirupsen/logrus/hooks/test"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)

// FIXME: there's a race in RunCommand that causes the test to fail when -race is enabled. The race is in the timeout
// handling, which shares bytes buffers between the exec goroutine and the timeout handler code.
func TestRunCommandTimeout(t *testing.T) {
hook := test.NewGlobal()
log.SetLevel(log.DebugLevel)
defer log.SetLevel(log.InfoLevel)

output, err := RunCommand("sh", CmdOpts{Timeout: 500 * time.Millisecond}, "-c", "echo hello world && echo my-error >&2 && sleep 2")
assert.Equal(t, "hello world", output)
require.EqualError(t, err, "`sh -c echo hello world && echo my-error >&2 && sleep 2` failed timeout after 500ms")

assert.Len(t, hook.Entries, 3)

entry := hook.Entries[0]
assert.Equal(t, log.InfoLevel, entry.Level)
assert.Equal(t, "sh -c echo hello world && echo my-error >&2 && sleep 2", entry.Message)
assert.Contains(t, entry.Data, "dir")
assert.Contains(t, entry.Data, "execID")

entry = hook.Entries[1]
assert.Equal(t, log.DebugLevel, entry.Level)
assert.Equal(t, "hello world\n", entry.Message)
assert.Contains(t, entry.Data, "duration")
assert.Contains(t, entry.Data, "execID")

entry = hook.Entries[2]
assert.Equal(t, log.ErrorLevel, entry.Level)
assert.Equal(t, "`sh -c echo hello world && echo my-error >&2 && sleep 2` failed timeout after 500ms", entry.Message)
assert.Contains(t, entry.Data, "execID")
}
Loading
Loading