logging improvements #122

skriss · 2017-10-05T22:10:56Z

Fixes #116
Fixes #118
Fixes #120

jrnt30 · 2017-10-06T13:20:51Z

docs/cli-reference/ark_server.md

@@ -14,7 +14,8 @@ ark server [flags]
 ### Options

 ```
-  -h, --help   help for server
+  -h, --help             help for server
+      --log-level enum   the logrus level at which to log (default info)


Can we spell out the options?

--log-level <level> the logrus level at which to log (..list of options)

I don't enum is self explanatory for new users.

good idea, will do this.

jrnt30 · 2017-10-06T13:23:09Z

pkg/cmd/server/server.go

-			logger.Hooks.Add(&logging.ErrorLocationHook{})
+			logLevel, err := logrus.ParseLevel(logLevelFlag.String())
+			if err != nil {
+				logLevel = logrus.InfoLevel


Should we log (funny enough...) that the log level is invalid? Should it be an error?

I had the same thought. Probably a good idea.

Will do, although logically this case should never happen, since the enum flag will not allow an invalid value to be set.

jrnt30 · 2017-10-06T13:36:02Z

pkg/util/logging/error_location_hook.go

@@ -14,7 +30,7 @@ const (

 // ErrorLocationHook is a logrus hook that attaches error location information
 // to log entries if an error is being logged and it has stack-trace information
-// (i.e. if it originates from or is wrapped by github.com/pkg/errors)
+// (i.e. if it originates from or is wrapped by github.com/pkg/errors).


Sorry for the out of context question, but wanted to validate an assumption I am making reading the code. If a user uses logger.Error("some error message") but not the logger.WithError(error) then the if errObj, exists = entry.Data[logrus.ErrorKey]; !exists will return true and short circuit, correct?

Nope, that case should be fine -- logger.Error(...) will set the msg and level fields, but not the error field so that check will return false. the error field is set either by calling .WithError or .WithField("error", err)

ncdc · 2017-10-06T16:32:16Z

pkg/util/logging/log_location_hook.go

+	"github.com/sirupsen/logrus"
+)
+
+const logLocationField = "location"


Probably should call this something a bit more descriptive (sourceFile, logSource, messageSource, etc)

skriss · 2017-10-06T18:31:04Z

@jrnt30 @ncdc I addressed your feedback, PTAL at the last 2 commits.

jrnt30 · 2017-10-10T03:10:38Z

pkg/cmd/server/server.go

+			// never happen assuming the enum flag is constructed correctly because the
+			// enum flag will not allow an invalid value to be set.
+			if err != nil {
+				logAtMinLevel(logger, "log-level flag has invalid value %s; setting log-level to %s", strings.ToUpper(logLevelFlag.String()), strings.ToUpper(logLevel.String()))


This is clever but can we just assume that this is an error and log it as such but let execution continue? Especially given your context around it not really being possible in the first place.

+1, no need for logAtMinLevel. Also, as a follow-up to my comment above, I would just put this in an else block when parsing, and just do logrus.Errorf

ncdc · 2017-10-10T15:25:32Z

pkg/cmd/server/server.go

-			logger.Hooks.Add(&logging.ErrorLocationHook{})
+			var (
+				logLevel = logrus.InfoLevel
+				parsed   logrus.Level


I wouldn't declare this; it's only used by the ParseLevel call, so I'd recommend

if parsed, err := logrus.ParseLevel(logLevelFlag.String()); err == nil { logLevel = parsed }

ncdc · 2017-10-10T15:34:02Z

pkg/cmd/server/server.go

+			// never happen assuming the enum flag is constructed correctly because the
+			// enum flag will not allow an invalid value to be set.
+			if err != nil {
+				logAtMinLevel(logger, "log-level flag has invalid value %s; setting log-level to %s", strings.ToUpper(logLevelFlag.String()), strings.ToUpper(logLevel.String()))


+1, no need for logAtMinLevel. Also, as a follow-up to my comment above, I would just put this in an else block when parsing, and just do logrus.Errorf

ncdc · 2017-10-10T15:35:22Z

pkg/cmd/server/server.go

+	}
+
+	return flag.NewEnum(logrus.InfoLevel.String(), logLevelsStrings...).
+		WithUsage(fmt.Sprintf("the logrus level at which to log (options %s)", strings.Join(logLevelsStrings, " | ")))


Don't need to mention logrus in the usage text

ncdc · 2017-10-10T15:37:33Z

pkg/util/logging/log_location_hook.go

+			continue
+		}
+
+		entry.Data[logLocationField] = fmt.Sprintf("%s:%d", path.Base(frame.File), frame.Line)


Do you want just the basename or the full path?

skriss · 2017-10-10T17:46:35Z

@ncdc @jrnt30 updated PTAL.

ncdc · 2017-10-10T18:21:53Z

pkg/cmd/server/server.go

+	}
+
+	return flag.NewEnum(logrus.InfoLevel.String(), logLevelsStrings...).
+		WithUsage(fmt.Sprintf("the level at which to log (options %s)", strings.Join(logLevelsStrings, " | ")))


I'd do "the level at which to log. Valid values are %s" followed by strings.Join(logLevelsStrings, ", ")

I'm tempted to suggest that instead of doing WithUsage, just make a helper that can retrieve a []string of sorted log levels, and use that inside of NewCommand, like this:

func NewCommand() *cobra.Command { sortedLogLevels := getSortedLogLevels() logLevelFlag := flag.NewEnum(logrus.InfoLevel.String(), sortedLogLevels...) // ... command.Flags().Var(logLevelFlag, "log-level", fmt.Sprintf("the level at which to log....."))

OK, that's reasonable.

ncdc · 2017-10-10T18:53:21Z

pkg/cmd/server/server.go

@@ -95,7 +96,7 @@ func NewCommand() *cobra.Command {
 		},
 	}

-	command.Flags().Var(logLevelFlag, "log-level", logLevelFlag.Usage)
+	command.Flags().Var(logLevelFlag, "log-level", fmt.Sprintf("the level at which to log. Valid values are %s", strings.Join(sortedLogLevels, ", ")))


Add a period to the valid values sentence please

ncdc · 2017-10-10T18:53:53Z

Squash & let's roll

Signed-off-by: Steve Kriss <steve@heptio.com>

skriss · 2017-10-10T20:08:54Z

ready to go

Signed-off-by: Steve Kriss <steve@heptio.com>

skriss added this to the v0.5.0 milestone Oct 5, 2017

skriss changed the title ~~[WIP] logging improvements~~ logging improvements Oct 5, 2017

skriss requested review from ncdc and jrnt30 October 5, 2017 22:14

skriss force-pushed the logging-fixes branch 2 times, most recently from 9c7d0be to 9cd6001 Compare October 5, 2017 23:12

skriss mentioned this pull request Oct 5, 2017

switch per-backup/restore logs to use logrus #123

Merged

jrnt30 reviewed Oct 6, 2017

View reviewed changes

ncdc reviewed Oct 6, 2017

View reviewed changes

skriss force-pushed the logging-fixes branch 2 times, most recently from 65ed673 to c422c19 Compare October 6, 2017 18:27

jrnt30 reviewed Oct 10, 2017

View reviewed changes

ncdc suggested changes Oct 10, 2017

View reviewed changes

skriss force-pushed the logging-fixes branch from c422c19 to 2332ec8 Compare October 10, 2017 17:45

ncdc reviewed Oct 10, 2017

View reviewed changes

remove verbose/stderr glog flags

6cf60e5

Signed-off-by: Steve Kriss <steve@heptio.com>

skriss force-pushed the logging-fixes branch from c694152 to a92493e Compare October 10, 2017 20:01

skriss added 3 commits October 10, 2017 13:14

add log-level flag to server command

9f3ce8a

Signed-off-by: Steve Kriss <steve@heptio.com>

add file/line numbers to logs

e7c62b5

Signed-off-by: Steve Kriss <steve@heptio.com>

add missing licenses

7c0d9dc

Signed-off-by: Steve Kriss <steve@heptio.com>

skriss force-pushed the logging-fixes branch from a92493e to 7c0d9dc Compare October 10, 2017 20:14

ncdc approved these changes Oct 10, 2017

View reviewed changes

ncdc merged commit df3c514 into vmware-tanzu:master Oct 10, 2017

skriss deleted the logging-fixes branch October 10, 2017 20:25

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

logging improvements #122

logging improvements #122

skriss commented Oct 5, 2017

jrnt30 Oct 6, 2017

skriss Oct 6, 2017

jrnt30 Oct 6, 2017

ncdc Oct 6, 2017

skriss Oct 6, 2017

jrnt30 Oct 6, 2017

skriss Oct 6, 2017

ncdc Oct 6, 2017

skriss commented Oct 6, 2017

jrnt30 Oct 10, 2017 •

edited

Loading

ncdc Oct 10, 2017

ncdc Oct 10, 2017

ncdc Oct 10, 2017

ncdc Oct 10, 2017

ncdc Oct 10, 2017

skriss commented Oct 10, 2017

ncdc Oct 10, 2017

ncdc Oct 10, 2017

skriss Oct 10, 2017

ncdc Oct 10, 2017

ncdc commented Oct 10, 2017

skriss commented Oct 10, 2017

logging improvements #122

logging improvements #122

Conversation

skriss commented Oct 5, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

skriss commented Oct 6, 2017

jrnt30 Oct 10, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

skriss commented Oct 10, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ncdc commented Oct 10, 2017

skriss commented Oct 10, 2017

jrnt30 Oct 10, 2017 •

edited

Loading