From b542c86bb768fc03610985a28f7e00414536c251 Mon Sep 17 00:00:00 2001 From: Kristoffer Ahl Date: Thu, 9 Apr 2020 19:17:18 +0200 Subject: [PATCH] - Refactored runtime for better error handling with exit codes. --- cmd/centry/runtime.go | 120 +++++++++++++++++++++++++---- cmd/centry/runtime_test.go | 20 ++++- cmd/centry/script.go | 6 +- go.mod | 1 + go.sum | 2 + internal/pkg/test/output.go | 20 ++++- internal/pkg/test/strings.go | 25 ------ test/data/commands/command_test.sh | 4 + 8 files changed, 151 insertions(+), 47 deletions(-) diff --git a/cmd/centry/runtime.go b/cmd/centry/runtime.go index 233b64e..ef63d05 100644 --- a/cmd/centry/runtime.go +++ b/cmd/centry/runtime.go @@ -3,9 +3,12 @@ package main import ( "github.com/kristofferahl/go-centry/internal/pkg/config" "github.com/kristofferahl/go-centry/internal/pkg/log" + "github.com/sirupsen/logrus" "github.com/urfave/cli/v2" ) +const metadataExitCode string = "exitcode" + // Runtime defines the runtime type Runtime struct { cli *cli.App @@ -66,20 +69,13 @@ func NewRuntime(inputArgs []string, context *Context) (*Runtime, error) { ErrWriter: context.io.Stderr, Before: func(c *cli.Context) error { - // Override the current log level from options - logLevel := c.String("config.log.level") - if c.Bool("quiet") { - logLevel = "panic" - } - context.log.TrySetLogLevel(logLevel) - - // Print runtime events - logger := context.log.GetLogger() - for _, e := range runtime.events { - logger.Debugf(e) - } - - return nil + return handleBefore(runtime, c) + }, + CommandNotFound: func(c *cli.Context, command string) { + handleCommandNotFound(runtime, c, command) + }, + ExitErrHandler: func(c *cli.Context, err error) { + handleExitErr(runtime, c, err) }, } @@ -102,9 +98,101 @@ func (runtime *Runtime) Execute() int { // Run cli err := runtime.cli.Run(args) if err != nil { - logger := runtime.context.log.GetLogger() - logger.Error(err) + runtime.context.log.GetLogger().Error(err) + } + + // Return exitcode defined in metadata + if runtime.cli.Metadata[metadataExitCode] != nil { + switch runtime.cli.Metadata[metadataExitCode].(type) { + case int: + return runtime.cli.Metadata[metadataExitCode].(int) + } + return 128 } return 0 } + +func handleBefore(runtime *Runtime, c *cli.Context) error { + // Override the current log level from options + logLevel := c.String("config.log.level") + if c.Bool("quiet") { + logLevel = "panic" + } + runtime.context.log.TrySetLogLevel(logLevel) + + // Print runtime events + logger := runtime.context.log.GetLogger() + for _, e := range runtime.events { + logger.Debugf(e) + } + + return nil +} + +func handleCommandNotFound(runtime *Runtime, c *cli.Context, command string) { + logger := runtime.context.log.GetLogger() + logger.WithFields(logrus.Fields{ + "command": command, + }).Warnf("Command not found!") + c.App.Metadata[metadataExitCode] = 127 +} + +// Handles errors implementing ExitCoder by printing their +// message and calling OsExiter with the given exit code. +// If the given error instead implements MultiError, each error will be checked +// for the ExitCoder interface, and OsExiter will be called with the last exit +// code found, or exit code 1 if no ExitCoder is found. +func handleExitErr(runtime *Runtime, context *cli.Context, err error) { + if err == nil { + return + } + + logger := runtime.context.log.GetLogger() + + if exitErr, ok := err.(cli.ExitCoder); ok { + if err.Error() != "" { + if _, ok := exitErr.(cli.ErrorFormatter); ok { + logger.WithFields(logrus.Fields{ + "command": context.Command.Name, + "code": exitErr.ExitCode(), + }).Errorf("%+v\n", err) + } else { + logger.WithFields(logrus.Fields{ + "command": context.Command.Name, + "code": exitErr.ExitCode(), + }).Error(err) + } + } + cli.OsExiter(exitErr.ExitCode()) + return + } + + if multiErr, ok := err.(cli.MultiError); ok { + code := handleMultiError(runtime, context, multiErr) + cli.OsExiter(code) + return + } +} + +func handleMultiError(runtime *Runtime, context *cli.Context, multiErr cli.MultiError) int { + code := 1 + for _, merr := range multiErr.Errors() { + if multiErr2, ok := merr.(cli.MultiError); ok { + code = handleMultiError(runtime, context, multiErr2) + } else if merr != nil { + if exitErr, ok := merr.(cli.ExitCoder); ok { + code = exitErr.ExitCode() + runtime.context.log.GetLogger().WithFields(logrus.Fields{ + "command": context.Command.Name, + "code": code, + }).Error(merr) + } else { + runtime.context.log.GetLogger().WithFields(logrus.Fields{ + "command": context.Command.Name, + }).Error(merr) + } + } + } + return code +} diff --git a/cmd/centry/runtime_test.go b/cmd/centry/runtime_test.go index 8e5a879..2e7fa7e 100644 --- a/cmd/centry/runtime_test.go +++ b/cmd/centry/runtime_test.go @@ -38,6 +38,20 @@ func TestMain(t *testing.T) { }) g.Describe("commands", func() { + g.Describe("invoking invalid command", func() { + g.It("should exit with status code 127", func() { + out := execQuiet("commandnotdefined") + g.Assert(out.ExitCode).Equal(127) + }) + }) + + g.Describe("invoking command that exits with a status code", func() { + g.It("should exit with exit code from command", func() { + out := execQuiet("commandtest exitcode") + g.Assert(out.ExitCode).Equal(111) + }) + }) + g.Describe("invoking command", func() { g.Describe("with arguments", func() { g.It("should have arguments passed", func() { @@ -100,9 +114,9 @@ func TestMain(t *testing.T) { test.AssertStringContains(g, out.Stdout, expected) }) - // TODO: Add assertions for all default values? g.It("should have default value for environment variable set", func() { out := execQuiet("optiontest printenv") + test.AssertStringHasKeyValue(g, out.Stdout, "BOOLOPT", "false") test.AssertStringHasKeyValue(g, out.Stdout, "STRINGOPT", "foobar") }) }) @@ -375,6 +389,10 @@ func execCentry(source string, quiet bool) *execResult { } }) + if out.ExitCode > 0 { + exitCode = out.ExitCode + } + return &execResult{ Source: source, ExitCode: exitCode, diff --git a/cmd/centry/script.go b/cmd/centry/script.go index f011989..9f7f39b 100644 --- a/cmd/centry/script.go +++ b/cmd/centry/script.go @@ -45,7 +45,7 @@ func (sc *ScriptCommand) ToCLICommand() *cli.Command { Action: func(c *cli.Context) error { ec := sc.Run(c, c.Args().Slice()) if ec > 0 { - return cli.Exit("command exited with non zero exit code", ec) + return cli.Exit("Command exited with non zero exit code", ec) } return nil }, @@ -77,11 +77,11 @@ func (sc *ScriptCommand) Run(c *cli.Context, args []string) int { } } - sc.Log.Errorf("Command %v exited with error! %v", sc.Function.Name, err) + sc.Log.Debugf("Script exited with error, %v", err) return exitCode } - sc.Log.Debugf("Finished executing command %v...", sc.Function.Name) + sc.Log.Debugf("Finished executing command %s...", sc.Function.Name) return 0 } diff --git a/go.mod b/go.mod index b21a960..798691b 100644 --- a/go.mod +++ b/go.mod @@ -3,6 +3,7 @@ module github.com/kristofferahl/go-centry go 1.13 require ( + bou.ke/monkey v1.0.2 github.com/franela/goblin v0.0.0-20200105215937-c9ffbefa60db github.com/ghodss/yaml v1.0.0 github.com/gorilla/mux v1.7.3 diff --git a/go.sum b/go.sum index 4076e2c..361e0cd 100644 --- a/go.sum +++ b/go.sum @@ -1,3 +1,5 @@ +bou.ke/monkey v1.0.2 h1:kWcnsrCNUatbxncxR/ThdYqbytgOIArtYWqcQLQzKLI= +bou.ke/monkey v1.0.2/go.mod h1:OqickVX3tNx6t33n1xvtTtu85YN5s6cKwVug+oHMaIA= github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU= github.com/cpuguy83/go-md2man/v2 v2.0.0-20190314233015-f79a8a8ca69d h1:U+s90UTSYgptZMwQh2aRr3LuazLJIa+Pg3Kc1ylSYVY= github.com/cpuguy83/go-md2man/v2 v2.0.0-20190314233015-f79a8a8ca69d/go.mod h1:maD7wRr/U5Z6m/iR4s+kqSMx2CaBsrgA7czyZG/E6dU= diff --git a/internal/pkg/test/output.go b/internal/pkg/test/output.go index d2ef84d..0689633 100644 --- a/internal/pkg/test/output.go +++ b/internal/pkg/test/output.go @@ -4,6 +4,8 @@ import ( "bytes" "io" "os" + + "bou.ke/monkey" ) // Output represents config for capturing stdout and or stderr. @@ -14,8 +16,9 @@ type Output struct { // OutputCapture contains the result of the capture opreation. type OutputCapture struct { - Stdout string - Stderr string + Stdout string + Stderr string + ExitCode int } // CaptureOutput captures stdout and stderr. @@ -25,6 +28,13 @@ func CaptureOutput(f func()) *OutputCapture { } func (output *Output) capture(f func()) *OutputCapture { + capturedExitCode := 0 + patchedOsExit := func(exitCode int) { + capturedExitCode = exitCode + } + patch := monkey.Patch(os.Exit, patchedOsExit) + defer patch.Unpatch() + rOut, wOut, errOut := os.Pipe() if errOut != nil { panic(errOut) @@ -53,6 +63,12 @@ func (output *Output) capture(f func()) *OutputCapture { f() + if capturedExitCode > 0 { + return &OutputCapture{ + ExitCode: capturedExitCode, + } + } + wOut.Close() wErr.Close() diff --git a/internal/pkg/test/strings.go b/internal/pkg/test/strings.go index 81b0aa7..6eeb3ec 100644 --- a/internal/pkg/test/strings.go +++ b/internal/pkg/test/strings.go @@ -28,31 +28,6 @@ TO BE FOUND IN const tmplExpectedValue string = `expected value "%s" for key "%s" but found "%s"` -// TODO: Remove -// AssertKeyValueExists asserts the given key and value is present on one of the lines given as input -func AssertKeyValueExists(g *goblin.G, key, value, input string) { - found := false - lines := strings.Split(input, "\n") - for _, l := range lines { - parts := strings.Split(l, "=") - k := parts[0] - - var v string - if len(parts) > 1 { - v = parts[1] - } - - if k == key { - found = true - g.Assert(v == value).IsTrue(fmt.Sprintf("wrong expected value for key \"%s\" expected=%s actual=%s", key, value, v)) - } - } - - if !found { - g.Fail(fmt.Sprintf("\"%s\" key not found in input:\n\n%s", key, input)) - } -} - // AssertStringHasKeyValue asserts the expected string is found in within the input func AssertStringHasKeyValue(g *goblin.G, s, key, value string) { found := false diff --git a/test/data/commands/command_test.sh b/test/data/commands/command_test.sh index d956c61..0c6278e 100644 --- a/test/data/commands/command_test.sh +++ b/test/data/commands/command_test.sh @@ -27,3 +27,7 @@ commandtest:options:args() { commandtest:options:printenv() { env | sort } + +commandtest:exitcode() { + exit 111 +}