Feature/log formatting (#84)

* add json formatter, remove unnecessary custom formatter

* fix errors

* one more issue

* fix global error logger

* pass the app name through error logs

* ensure app name is in context when error handling

* add version info to logger

* try fix for types

* update docs

* fix test

* fix aws test

* switch to t3 instance for test

README.md

@@ -53,20 +53,17 @@ import (
 func main() {
       // Create a new CLI app. This will return a urfave/cli App with some
       // common initialization.
-      app := entrypoint.NewApp()
+      // Set the version number from your app from the Version variable that is passed in at build time in `version` package
+      // for more understanding see github.com/gruntwork-io/go-commons/version
+      app := entrypoint.NewApp("my-app-name", version.GetVersion())
 
-      app.Name = "my-app"
       app.Authors = []*cli.Author{
             {
                 Name: "Gruntwork",
                 Email: "www.gruntwork.io",
             },
       }
 
-      // Set the version number from your app from the Version variable that is passed in at build time in `version` package
-      // for more understanding see github.com/gruntwork-io/go-commons/version
-      app.Version = version.GetVersion()
-
       app.Action = func(cliContext *cli.Context) error {
         // ( fill in your app details)
         return nil
@@ -118,7 +115,7 @@ variety of external systems (e.g. syslog, airbrake, papertrail), and even hooks
 To get a Logger, call the `logging.GetLogger` method:
 
 ```go
-logger := logging.GetLogger("my-app")
+logger := logging.GetLogger("my-app", "v0.0.1")
 logger.Info("Something happened!")
 ```
 
@@ -131,6 +128,13 @@ logging.SetGlobalLogLevel(logrus.DebugLevel)
 Note that this ONLY affects loggers created using the `GetLogger` function **AFTER** you call `SetGlobalLogLevel`, so
 you need to call this as early in the life of your CLI app as possible!
 
+To change the logging format globally, call the `SetGlobalLogFormatter` function:
+
+```go
+//Valid options are "json" or "text"
+logging.SetGlobalLogFormatter("json")
+```
+
 ### shell
 
 This package contains two types of helpers:

awscommons/v2/autoscaling.go

@@ -139,7 +139,7 @@ func waitForCapacity(
 	logger.Infof("Waiting for ASG %s to reach desired capacity.", asgName)
 
 	err := retry.DoWithRetry(
-		logger.Logger,
+		logger,
 		"Waiting for desired capacity to be reached.",
 		maxRetries, sleepBetweenRetries,
 		func() error {

entrypoint/entrypoint.go

@@ -1,7 +1,6 @@
 package entrypoint
 
 import (
-	"fmt"
 	"os"
 
 	"github.com/urfave/cli/v2"
@@ -15,12 +14,14 @@ const defaultErrorExitCode = 1
 const debugEnvironmentVarName = "GRUNTWORK_DEBUG"
 
 // Wrapper around cli.NewApp that sets the help text printer.
-func NewApp() *cli.App {
+func NewApp(name string, version string) *cli.App {
 	cli.HelpPrinter = WrappedHelpPrinter
 	cli.AppHelpTemplate = CLI_APP_HELP_TEMPLATE
 	cli.CommandHelpTemplate = CLI_COMMAND_HELP_TEMPLATE
 	cli.SubcommandHelpTemplate = CLI_APP_HELP_TEMPLATE
 	app := cli.NewApp()
+	app.Name = name
+	app.Version = version
 	return app
 }
 
@@ -30,29 +31,31 @@ func RunApp(app *cli.App) {
 		// Do nothing. We just need to override this function, as the default value calls os.Exit, which
 		// kills the app (or any automated test) dead in its tracks.
 	}
-
-	defer errors.Recover(checkForErrorsAndExit)
+	checkErrs := func(e error) {
+		checkForErrorsAndExit(e, app)
+	}
+	defer errors.Recover(checkErrs)
 	err := app.Run(os.Args)
-	checkForErrorsAndExit(err)
+	checkForErrorsAndExit(err, app)
 }
 
 // If there is an error, display it in the console and exit with a non-zero exit code. Otherwise, exit 0.
 // Note that if the GRUNTWORK_DEBUG environment variable is set, this will print out the stack trace.
-func checkForErrorsAndExit(err error) {
-	logError(err)
+func checkForErrorsAndExit(err error, app *cli.App) {
+	logError(err, app)
 	exitCode := getExitCode(err)
 	os.Exit(exitCode)
 }
 
 // logError will output an error message to stderr. This will output the stack trace if we are in debug mode.
-func logError(err error) {
+func logError(err error, app *cli.App) {
 	isDebugMode := os.Getenv(debugEnvironmentVarName) != ""
 	if err != nil {
 		errWithoutStackTrace := errors.Unwrap(err)
 		if isDebugMode {
-			logging.GetLogger("").WithError(err).Error(errors.PrintErrorWithStackTrace(err))
+			logging.GetLogger(app.Name, app.Version).WithError(err).Error(errors.PrintErrorWithStackTrace(err))
 		} else {
-			fmt.Fprintf(os.Stderr, "ERROR: %s\n", errWithoutStackTrace)
+			logging.GetLogger(app.Name, app.Version).Error(errWithoutStackTrace)
 		}
 	}
 }

entrypoint/entrypoint_test.go

@@ -94,10 +94,8 @@ func TestEntrypointNewAppCommandHelpPrinterHonorsLineWidthVar(t *testing.T) {
 func noop(c *cli.Context) error { return nil }
 
 func createSampleApp() *cli.App {
-	app := NewApp()
-	app.Name = "houston"
+	app := NewApp("houston", "v0.0.6")
 	app.HelpName = "houston"
-	app.Version = "v0.0.6"
 	app.Description = `A CLI tool for interacting with Gruntwork Houston that you can use to authenticate to AWS on the CLI and to SSH to your EC2 Instances.`
 
 	configFlag := cli.StringFlag{

errors/errors.go

@@ -87,7 +87,7 @@ func Recover(onPanic func(cause error)) {
 
 // Use this to wrap every command you add to *cli.App to handle panics by logging them with a stack trace and returning
 // an error up the chain.
-func WithPanicHandling(action func(*cli.Context) error) func(*cli.Context) error {
+func WithPanicHandling(action func(c *cli.Context) error) func(c *cli.Context) error {
 	return func(context *cli.Context) (err error) {
 		defer Recover(func(cause error) {
 			err = cause

git/auth.go

@@ -34,7 +34,7 @@ type CacheCredentialOptions struct {
 
 // ConfigureForceHTTPS configures git to force usage of https endpoints instead of SSH based endpoints for the three
 // primary VCS platforms (GitHub, GitLab, BitBucket).
-func ConfigureForceHTTPS(logger *logrus.Logger) error {
+func ConfigureForceHTTPS(logger *logrus.Entry) error {
 	opts := shell.NewShellOptions()
 	if logger != nil {
 		opts.Logger = logger
@@ -71,7 +71,7 @@ func ConfigureForceHTTPS(logger *logrus.Logger) error {
 // NOTE: this configures the cache credential helper globally, with a default timeout of 1 hour. If you want more
 // control over the configuration, use the ConfigureCacheCredentialsHelper and StoreCacheCredentials functions directly.
 func ConfigureHTTPSAuth(
-	logger *logrus.Logger,
+	logger *logrus.Entry,
 	gitUsername string,
 	gitOauthToken string,
 	vcsHost string,
@@ -92,7 +92,7 @@ func ConfigureHTTPSAuth(
 
 // ConfigureCacheCredentialsHelper configures git globally to use the cache credentials helper for authentication based
 // on the provided options configuration.
-func ConfigureCacheCredentialsHelper(logger *logrus.Logger, options CacheCredentialOptions) error {
+func ConfigureCacheCredentialsHelper(logger *logrus.Entry, options CacheCredentialOptions) error {
 	shellOpts := shell.NewShellOptions()
 	if logger != nil {
 		shellOpts.Logger = logger
@@ -144,7 +144,7 @@ func ConfigureCacheCredentialsHelper(logger *logrus.Logger, options CacheCredent
 // StoreCacheCredentials stores the given git credentials for the vcs host and path pair to the git credential-cache
 // helper.
 func StoreCacheCredentials(
-	logger *logrus.Logger,
+	logger *logrus.Entry,
 	gitUsername string,
 	gitOauthToken string,
 	vcsHost string,

git/git.go

@@ -7,7 +7,7 @@ import (
 )
 
 // Clone runs git clone to clone the specified repository into the given target directory.
-func Clone(logger *logrus.Logger, repo string, targetDir string) error {
+func Clone(logger *logrus.Entry, repo string, targetDir string) error {
 	if !files.IsDir(targetDir) {
 		return TargetDirectoryNotExistsErr{dirPath: targetDir}
 	}
@@ -20,7 +20,7 @@ func Clone(logger *logrus.Logger, repo string, targetDir string) error {
 }
 
 // Checkout checks out the given ref for the repo cloned in the target directory.
-func Checkout(logger *logrus.Logger, ref string, targetDir string) error {
+func Checkout(logger *logrus.Entry, ref string, targetDir string) error {
 	if !files.IsDir(targetDir) {
 		return TargetDirectoryNotExistsErr{dirPath: targetDir}
 	}

git/git_test.go

@@ -16,7 +16,7 @@ func TestGitClone(t *testing.T) {
 
 	tmpDir, err := ioutil.TempDir("", "git-test")
 	require.NoError(t, err)
-	require.NoError(t, Clone(logging.GetLogger(t.Name()), "https://github.com/gruntwork-io/go-commons.git", tmpDir))
+	require.NoError(t, Clone(logging.GetLogger(t.Name(), ""), "https://github.com/gruntwork-io/go-commons.git", tmpDir))
 	assert.True(t, files.FileExists(filepath.Join(tmpDir, "LICENSE.txt")))
 }
 
@@ -25,7 +25,7 @@ func TestGitCheckout(t *testing.T) {
 
 	tmpDir, err := ioutil.TempDir("", "git-test")
 	require.NoError(t, err)
-	require.NoError(t, Clone(logging.GetLogger(t.Name()), "https://github.com/gruntwork-io/go-commons.git", tmpDir))
-	require.NoError(t, Checkout(logging.GetLogger(t.Name()), "v0.10.0", tmpDir))
+	require.NoError(t, Clone(logging.GetLogger(t.Name(), ""), "https://github.com/gruntwork-io/go-commons.git", tmpDir))
+	require.NoError(t, Checkout(logging.GetLogger(t.Name(), ""), "v0.10.0", tmpDir))
 	assert.False(t, files.FileExists(filepath.Join(tmpDir, "git", "git_test.go")))
 }

git/test/auth_test.go

@@ -23,7 +23,7 @@ const (
 )
 
 var (
-	logger = logging.GetLogger("testlogger")
+	logger = logging.GetLogger("testlogger", "")
 )
 
 // NOTE: All these tests should be run in the provided docker environment to avoid polluting the local git configuration

lock/lock.go

@@ -41,7 +41,7 @@ type Options struct {
 	// The value for how long AcquireLock will sleep for between retries to get the lock
 	SleepBetweenRetries time.Duration
 	// The logger to use for the lock
-	Logger *logrus.Logger
+	Logger *logrus.Entry
 
 	// Custom session to use to authenticate to AWS in the SDK. If nil, constructs the session based on the default
 	// authentication chain in the SDK.

lock/lock_test.go

@@ -20,7 +20,7 @@ func TestAcquireLockWithRetries(t *testing.T) {
 		LockString:          "test-dynamodb-lock-string-" + random.UniqueId(),
 		MaxRetries:          2,
 		SleepBetweenRetries: 1 * time.Second,
-		Logger:              logging.GetLogger("TestAcquireLockWithRetries"),
+		Logger:              logging.GetLogger("TestAcquireLockWithRetries", ""),
 	}
 
 	defer assertLockReleased(t, &options)

logging/logging.go

@@ -9,25 +9,30 @@ import (
 var globalLogLevel = logrus.InfoLevel
 var globalLogLevelLock = sync.Mutex{}
 
+var globalLogFormatter = "text"
+var globalLogFormatterLock = sync.Mutex{}
+
 func GetProjectLogger() *logrus.Entry {
-	logger := GetLogger("")
+	logger := GetLogger("", "")
 	return logger.WithField("name", "go-commons")
 }
 
 // Create a new logger with the given name
-func GetLogger(name string) *logrus.Logger {
+func GetLogger(name string, version string) *logrus.Entry {
 	logger := logrus.New()
 
 	logger.Level = globalLogLevel
 
-	logger.Formatter = &TextFormatterWithBinName{
-		Name: name,
-		TextFormatter: logrus.TextFormatter{
+	if globalLogFormatter == "json" {
+		logger.Formatter = &logrus.JSONFormatter{}
+
+	} else {
+		logger.Formatter = &logrus.TextFormatter{
 			FullTimestamp: true,
-		},
+		}
 	}
+	return logger.WithField("binary", name).WithField("version", version)
 
-	return logger
 }
 
 // Set the log level. Note: this ONLY affects loggers created using the GetLogger function AFTER this function has been
@@ -40,3 +45,11 @@ func SetGlobalLogLevel(level logrus.Level) {
 
 	globalLogLevel = level
 }
+
+// Set the log format. Note: this ONLY affects loggers created using the GetLogger function AFTER this function has been
+// called. Therefore, you need to call this as early in the life of your CLI app as possible!
+func SetGlobalLogFormatter(formatter string) {
+	defer globalLogFormatterLock.Unlock()
+	globalLogFormatterLock.Lock()
+	globalLogFormatter = formatter
+}

retry/retry.go

@@ -11,7 +11,7 @@ import (
 // If it returns any other type of error, sleep for sleepBetweenRetries and try again, up to a maximum of
 // maxRetries retries. If maxRetries is exceeded, return a MaxRetriesExceeded error.
 func DoWithRetry(
-	logger *logrus.Logger,
+	logger *logrus.Entry,
 	actionDescription string,
 	maxRetries int,
 	sleepBetweenRetries time.Duration,
@@ -31,7 +31,7 @@ func DoWithRetry(
 // return that error immediately. If it returns any other type of error, sleep for sleepBetweenRetries and try again, up
 // to a maximum of maxRetries retries. If maxRetries is exceeded, return a MaxRetriesExceeded error.
 func DoWithRetryInterface(
-	logger *logrus.Logger,
+	logger *logrus.Entry,
 	actionDescription string,
 	maxRetries int,
 	sleepBetweenRetries time.Duration,

retry/retry_test.go

@@ -49,7 +49,7 @@ func TestDoWithRetry(t *testing.T) {
 			t.Parallel()
 
 			actualOutput, err := DoWithRetryInterface(
-				logging.GetLogger("test"),
+				logging.GetLogger("test", ""),
 				testCase.description,
 				testCase.maxRetries,
 				1*time.Millisecond,

shell/cmd.go

@@ -103,7 +103,7 @@ func runShellCommand(options *ShellOptions, streamOutput bool, command string, a
 	}
 
 	output, err := readStdoutAndStderr(
-		options.Logger,
+		options.Logger.Logger,
 		streamOutput,
 		stdout,
 		stderr,

shell/cmd_test.go

@@ -128,8 +128,8 @@ func TestSensitiveArgsTrueHidesOnRunShellCommand(t *testing.T) {
 	t.Parallel()
 
 	buffer := bytes.NewBufferString("")
-	logger := logging.GetLogger("")
-	logger.Out = buffer
+	logger := logging.GetLogger("", "")
+	logger.Logger.Out = buffer
 	options := NewShellOptions()
 	options.SensitiveArgs = true
 	options.Logger = logger
@@ -144,8 +144,8 @@ func TestSensitiveArgsFalseShowsOnRunShellCommand(t *testing.T) {
 	t.Parallel()
 
 	buffer := bytes.NewBufferString("")
-	logger := logging.GetLogger("")
-	logger.Out = buffer
+	logger := logging.GetLogger("", "")
+	logger.Logger.Out = buffer
 	options := NewShellOptions()
 	options.Logger = logger
 
@@ -159,8 +159,8 @@ func TestSensitiveArgsTrueHidesOnRunShellCommandAndGetOutput(t *testing.T) {
 	t.Parallel()
 
 	buffer := bytes.NewBufferString("")
-	logger := logging.GetLogger("")
-	logger.Out = buffer
+	logger := logging.GetLogger("", "")
+	logger.Logger.Out = buffer
 	options := NewShellOptions()
 	options.SensitiveArgs = true
 	options.Logger = logger
@@ -176,8 +176,8 @@ func TestSensitiveArgsFalseShowsOnRunShellCommandAndGetOutput(t *testing.T) {
 	t.Parallel()
 
 	buffer := bytes.NewBufferString("")
-	logger := logging.GetLogger("")
-	logger.Out = buffer
+	logger := logging.GetLogger("", "")
+	logger.Logger.Out = buffer
 	options := NewShellOptions()
 	options.Logger = logger