Adds DPanic and Panic level logging (writes log, then panics) (#3689)

Author: paulnpdev

Makefile

@@ -11,7 +11,7 @@ all: update-tools clean proto bins check test
 # Used by Buildkite.
 ci-build: bins build-tests update-tools shell-check check proto go-generate gomodtidy ensure-no-changes
 
-# Delete all build artefacts.
+# Delete all build artifacts
 clean: clean-bins clean-test-results
 
 # Recompile proto files.

common/log/config.go

@@ -27,15 +27,19 @@ package log
 type (
 	// Config contains the config items for logger
 	Config struct {
-		// Stdout is true if the output needs to goto standard out
+		// Stdout is true if the output needs to goto standard out; default is stderr
 		Stdout bool `yaml:"stdout"`
-		// Level is the desired log level
+		// Level is the desired log level; see colocated zap_logger.go::parseZapLevel()
 		Level string `yaml:"level"`
 		// OutputFile is the path to the log output file
 		OutputFile string `yaml:"outputFile"`
 		// Format determines the format of each log file printed to the output.
 		// Acceptable values are "json" or "console". The default is "json".
 		// Use "console" if you want stack traces to appear on multiple lines.
 		Format string `yaml:"format"`
+		// Development determines whether the logger is run in Development (== Test) or in
+		// Production mode.  Default is Production.  Production-stage disables panics from
+		// DPanic logging.
+		Development bool `yaml:"development"`
 	}
 )

common/log/interface.go

@@ -44,6 +44,8 @@ type (
 		Info(msg string, tags ...tag.Tag)
 		Warn(msg string, tags ...tag.Tag)
 		Error(msg string, tags ...tag.Tag)
+		DPanic(msg string, tags ...tag.Tag)
+		Panic(msg string, tags ...tag.Tag)
 		Fatal(msg string, tags ...tag.Tag)
 	}
 

common/log/interface_mock.go

@@ -68,6 +68,16 @@ func (l *lazyLogger) Error(msg string, tags ...tag.Tag) {
 	l.logger.Error(msg, tags...)
 }
 
+func (l *lazyLogger) DPanic(msg string, tags ...tag.Tag) {
+	l.once.Do(l.tagLogger)
+	l.logger.DPanic(msg, tags...)
+}
+
+func (l *lazyLogger) Panic(msg string, tags ...tag.Tag) {
+	l.once.Do(l.tagLogger)
+	l.logger.Panic(msg, tags...)
+}
+
 func (l *lazyLogger) Fatal(msg string, tags ...tag.Tag) {
 	l.once.Do(l.tagLogger)
 	l.logger.Fatal(msg, tags...)

common/log/lazy_logger.go

@@ -37,11 +37,13 @@ func NewNoopLogger() *noopLogger {
 	return &noopLogger{}
 }
 
-func (n *noopLogger) Debug(string, ...tag.Tag) {}
-func (n *noopLogger) Info(string, ...tag.Tag)  {}
-func (n *noopLogger) Warn(string, ...tag.Tag)  {}
-func (n *noopLogger) Error(string, ...tag.Tag) {}
-func (n *noopLogger) Fatal(string, ...tag.Tag) {}
+func (n *noopLogger) Debug(string, ...tag.Tag)  {}
+func (n *noopLogger) Info(string, ...tag.Tag)   {}
+func (n *noopLogger) Warn(string, ...tag.Tag)   {}
+func (n *noopLogger) Error(string, ...tag.Tag)  {}
+func (n *noopLogger) DPanic(string, ...tag.Tag) {}
+func (n *noopLogger) Panic(string, ...tag.Tag)  {}
+func (n *noopLogger) Fatal(string, ...tag.Tag)  {}
 func (n *noopLogger) With(...tag.Tag) Logger {
 	return n
 }

common/log/noop_logger.go

@@ -82,6 +82,20 @@ func (r *replayLogger) Error(msg string, tags ...tag.Tag) {
 	r.logger.Error(msg, tags...)
 }
 
+func (r *replayLogger) DPanic(msg string, tags ...tag.Tag) {
+	if workflow.IsReplaying(r.ctx) && !r.enableLogInReplay {
+		return
+	}
+	r.logger.DPanic(msg, tags...)
+}
+
+func (r *replayLogger) Panic(msg string, tags ...tag.Tag) {
+	if workflow.IsReplaying(r.ctx) && !r.enableLogInReplay {
+		return
+	}
+	r.logger.Panic(msg, tags...)
+}
+
 func (r *replayLogger) Fatal(msg string, tags ...tag.Tag) {
 	if workflow.IsReplaying(r.ctx) && !r.enableLogInReplay {
 		return

common/log/replay_logger.go

@@ -80,6 +80,18 @@ func (tl *throttledLogger) Error(msg string, tags ...tag.Tag) {
 	})
 }
 
+func (tl *throttledLogger) DPanic(msg string, tags ...tag.Tag) {
+	tl.rateLimit(func() {
+		tl.logger.DPanic(msg, tags...)
+	})
+}
+
+func (tl *throttledLogger) Panic(msg string, tags ...tag.Tag) {
+	tl.rateLimit(func() {
+		tl.logger.Panic(msg, tags...)
+	})
+}
+
 func (tl *throttledLogger) Fatal(msg string, tags ...tag.Tag) {
 	tl.rateLimit(func() {
 		tl.logger.Fatal(msg, tags...)

common/log/throttle_logger.go

@@ -35,12 +35,12 @@ type withLogger struct {
 
 var _ Logger = (*withLogger)(nil)
 
-// With returns Logger instance that prepend every log entry with tags. If logger implements WithLogger it is used, otherwise every log call will be intercepted.
+// With returns Logger instance that prepend every log entry with tags. If logger implements
+// WithLogger it is used, otherwise every log call will be intercepted.
 func With(logger Logger, tags ...tag.Tag) Logger {
 	if wl, ok := logger.(WithLogger); ok {
 		return wl.With(tags...)
 	}
-
 	return newWithLogger(logger, tags...)
 }
 
@@ -52,27 +52,37 @@ func (l *withLogger) prependTags(tags []tag.Tag) []tag.Tag {
 	return append(l.tags, tags...)
 }
 
-// Debug writes message to the log.
+// Debug writes message to the log (if enabled).
 func (l *withLogger) Debug(msg string, tags ...tag.Tag) {
 	l.logger.Debug(msg, l.prependTags(tags)...)
 }
 
-// Info writes message to the log.
+// Info writes message to the log (if enabled).
 func (l *withLogger) Info(msg string, tags ...tag.Tag) {
 	l.logger.Info(msg, l.prependTags(tags)...)
 }
 
-// Warn writes message to the log.
+// Warn writes message to the log (if enabled).
 func (l *withLogger) Warn(msg string, tags ...tag.Tag) {
 	l.logger.Warn(msg, l.prependTags(tags)...)
 }
 
-// Error writes message to the log.
+// Error writes message to the log (if enabled).
 func (l *withLogger) Error(msg string, tags ...tag.Tag) {
 	l.logger.Error(msg, l.prependTags(tags)...)
 }
 
-// Error writes message to the log.
+// DPanic writes message to the log (if enabled), then calls panic() in development mode
+func (l *withLogger) DPanic(msg string, tags ...tag.Tag) {
+	l.logger.DPanic(msg, l.prependTags(tags)...)
+}
+
+// Panic writes message to the log (if enabled), then calls panic() no matter what
+func (l *withLogger) Panic(msg string, tags ...tag.Tag) {
+	l.logger.Panic(msg, l.prependTags(tags)...)
+}
+
+// Fatal writes message to the log no matter what, then terminates the process
 func (l *withLogger) Fatal(msg string, tags ...tag.Tag) {
 	l.logger.Fatal(msg, l.prependTags(tags)...)
 }

common/log/with_logger.go

@@ -58,7 +58,8 @@ func NewTestLogger() *zapLogger {
 	return NewZapLogger(BuildZapLogger(Config{
 		// Uncomment next line if you need debug level logging in tests.
 		// Level: "debug",
-		Format: "console",
+		Format:      "console",
+		Development: true,
 	}))
 }
 
@@ -145,6 +146,22 @@ func (l *zapLogger) Error(msg string, tags ...tag.Tag) {
 	}
 }
 
+func (l *zapLogger) DPanic(msg string, tags ...tag.Tag) {
+	if l.zl.Core().Enabled(zap.DPanicLevel) {
+		msg = setDefaultMsg(msg)
+		fields := l.buildFieldsWithCallAt(tags)
+		l.zl.DPanic(msg, fields...)
+	}
+}
+
+func (l *zapLogger) Panic(msg string, tags ...tag.Tag) {
+	if l.zl.Core().Enabled(zap.PanicLevel) {
+		msg = setDefaultMsg(msg)
+		fields := l.buildFieldsWithCallAt(tags)
+		l.zl.Panic(msg, fields...)
+	}
+}
+
 func (l *zapLogger) Fatal(msg string, tags ...tag.Tag) {
 	if l.zl.Core().Enabled(zap.FatalLevel) {
 		msg = setDefaultMsg(msg)
@@ -197,15 +214,13 @@ func buildZapLogger(cfg Config, disableCaller bool) *zap.Logger {
 	if cfg.Stdout {
 		outputPath = "stdout"
 	}
-
 	encoding := "json"
 	if cfg.Format == "console" {
 		encoding = "console"
 	}
-
 	config := zap.Config{
 		Level:            zap.NewAtomicLevelAt(parseZapLevel(cfg.Level)),
-		Development:      false,
+		Development:      cfg.Development,
 		Sampling:         nil,
 		Encoding:         encoding,
 		EncoderConfig:    encodeConfig,
@@ -258,6 +273,10 @@ func parseZapLevel(level string) zapcore.Level {
 		return zap.WarnLevel
 	case "error":
 		return zap.ErrorLevel
+	case "dpanic":
+		return zap.DPanicLevel
+	case "panic":
+		return zap.PanicLevel
 	case "fatal":
 		return zap.FatalLevel
 	default:

common/log/zap_logger.go

@@ -62,6 +62,8 @@ func (s *LogSuite) TestParseLogLevel() {
 	s.Equal(zap.WarnLevel, parseZapLevel("warn"))
 	s.Equal(zap.ErrorLevel, parseZapLevel("error"))
 	s.Equal(zap.FatalLevel, parseZapLevel("fatal"))
+	s.Equal(zap.DPanicLevel, parseZapLevel("dpanic"))
+	s.Equal(zap.PanicLevel, parseZapLevel("panic"))
 	s.Equal(zap.InfoLevel, parseZapLevel("unknown"))
 }
 
@@ -77,6 +79,27 @@ func (s *LogSuite) TestNewLogger() {
 	s.NotNil(log)
 	_, err := os.Stat(dir + "/test.log")
 	s.Nil(err)
+	log.DPanic("Development default is false; should not panic here!")
+	s.Panics(nil, func() {
+		log.Panic("Must Panic")
+	})
+
+	cfg = Config{
+		Level:       "info",
+		OutputFile:  dir + "/test.log",
+		Development: true,
+	}
+	log = BuildZapLogger(cfg)
+	s.NotNil(log)
+	_, err = os.Stat(dir + "/test.log")
+	s.Nil(err)
+	s.Panics(nil, func() {
+		log.DPanic("Must panic!")
+	})
+	s.Panics(nil, func() {
+		log.Panic("Must panic!")
+	})
+
 }
 
 func TestDefaultLogger(t *testing.T) {