- Refactored runtime for better error handling with exit codes.

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
+}

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,

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
 }
 

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

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=

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()
 

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

test/data/commands/command_test.sh

@@ -27,3 +27,7 @@ commandtest:options:args() {
 commandtest:options:printenv() {
   env | sort
 }
+
+commandtest:exitcode() {
+  exit 111
+}