Change Logger.Log specification to "should not actually panic or exit" (

uber-go#168)

* CheckedMessage.Write: call specific methods when possible

* Shift Logger.Log contract to "should not actually exit or panic"

* logger_test: use test cases for json logger fatal and panic logs

checked_message.go

@@ -45,6 +45,10 @@ func NewCheckedMessage(logger Logger, lvl Level, msg string) *CheckedMessage {
 // Write logs the pre-checked message with the supplied fields. It should only
 // be used once; if a CheckedMessage is re-used, it also logs an error message
 // with the underlying logger's DFatal method.
+//
+// Write will call the underlying level method (Debug, Info, Warn, Error,
+// Panic, and Fatal) for the defined levels; the Log method is only called for
+// unknown logging levels.
 func (m *CheckedMessage) Write(fields ...Field) {
 	if n := m.used.Inc(); n > 1 {
 		if n == 2 {
@@ -54,7 +58,22 @@ func (m *CheckedMessage) Write(fields ...Field) {
 		}
 		return
 	}
-	m.logger.Log(m.lvl, m.msg, fields...)
+	switch m.lvl {
+	case DebugLevel:
+		m.logger.Debug(m.msg, fields...)
+	case InfoLevel:
+		m.logger.Info(m.msg, fields...)
+	case WarnLevel:
+		m.logger.Warn(m.msg, fields...)
+	case ErrorLevel:
+		m.logger.Error(m.msg, fields...)
+	case PanicLevel:
+		m.logger.Panic(m.msg, fields...)
+	case FatalLevel:
+		m.logger.Fatal(m.msg, fields...)
+	default:
+		m.logger.Log(m.lvl, m.msg, fields...)
+	}
 }
 
 // OK checks whether it's safe to call Write.

logger.go

@@ -50,6 +50,11 @@ type Logger interface {
 
 	// Log a message at the given level. Messages include any context that's
 	// accumulated on the logger, as well as any fields added at the log site.
+	//
+	// Calling Panic should panic() and calling Fatal should terminate the
+	// process, but calling Log(PanicLevel, ...) or Log(FatalLevel, ...) should
+	// not. It may not be possible for compatibility wrappers to comply with
+	// this last part (e.g. the bark wrapper).
 	Log(Level, string, ...Field)
 	Debug(string, ...Field)
 	Info(string, ...Field)
@@ -99,14 +104,7 @@ func (log *logger) Check(lvl Level, msg string) *CheckedMessage {
 }
 
 func (log *logger) Log(lvl Level, msg string, fields ...Field) {
-	switch lvl {
-	case PanicLevel:
-		log.Panic(msg, fields...)
-	case FatalLevel:
-		log.Fatal(msg, fields...)
-	default:
-		log.log(lvl, msg, fields)
-	}
+	log.log(lvl, msg, fields)
 }
 
 func (log *logger) Debug(msg string, fields ...Field) {

logger_test.go

@@ -184,19 +184,52 @@ func TestJSONLoggerLog(t *testing.T) {
 		logger.Log(DebugLevel, "foo")
 		assert.Equal(t, `{"level":"debug","msg":"foo"}`, buf.Stripped(), "Unexpected output from Log.")
 	})
+}
 
-	withJSONLogger(t, nil, func(logger Logger, buf *testBuffer) {
-		assert.Panics(t, func() { logger.Log(PanicLevel, "foo") }, "Expected logging at Panic level to panic.")
-		assert.Equal(t, `{"level":"panic","msg":"foo"}`, buf.Stripped(), "Unexpected output from panic-level Log.")
-	})
+func TestJSONLoggerLogPanic(t *testing.T) {
+	for _, tc := range []struct {
+		do       func(Logger)
+		should   bool
+		expected string
+	}{
+		{func(logger Logger) { logger.Log(PanicLevel, "foo") }, false, `{"level":"panic","msg":"foo"}`},
+		{func(logger Logger) { logger.Check(PanicLevel, "bar").Write() }, true, `{"level":"panic","msg":"bar"}`},
+		{func(logger Logger) { logger.Panic("baz") }, true, `{"level":"panic","msg":"baz"}`},
+	} {
+		withJSONLogger(t, nil, func(logger Logger, buf *testBuffer) {
+			if tc.should {
+				assert.Panics(t, func() { tc.do(logger) }, "Expected panic")
+			} else {
+				assert.NotPanics(t, func() { tc.do(logger) }, "Expected no panic")
+			}
+			assert.Equal(t, tc.expected, buf.Stripped(), "Unexpected output from fatal-level Log.")
+		})
+	}
+}
 
-	stub := stubExit()
-	defer stub.Unstub()
-	withJSONLogger(t, nil, func(logger Logger, buf *testBuffer) {
-		logger.Log(FatalLevel, "foo")
-		assert.Equal(t, `{"level":"fatal","msg":"foo"}`, buf.Stripped(), "Unexpected output from fatal-level Log.")
-		stub.AssertStatus(t, 1)
-	})
+func TestJSONLoggerLogFatal(t *testing.T) {
+	for _, tc := range []struct {
+		do       func(Logger)
+		should   bool
+		status   int
+		expected string
+	}{
+		{func(logger Logger) { logger.Log(FatalLevel, "foo") }, false, 0, `{"level":"fatal","msg":"foo"}`},
+		{func(logger Logger) { logger.Check(FatalLevel, "bar").Write() }, true, 1, `{"level":"fatal","msg":"bar"}`},
+		{func(logger Logger) { logger.Fatal("baz") }, true, 1, `{"level":"fatal","msg":"baz"}`},
+	} {
+		withJSONLogger(t, nil, func(logger Logger, buf *testBuffer) {
+			stub := stubExit()
+			defer stub.Unstub()
+			tc.do(logger)
+			if tc.should {
+				stub.AssertStatus(t, tc.status)
+			} else {
+				stub.AssertNoExit(t)
+			}
+			assert.Equal(t, tc.expected, buf.Stripped(), "Unexpected output from fatal-level Log.")
+		})
+	}
 }
 
 func TestJSONLoggerLeveledMethods(t *testing.T) {

zbark/debark.go

@@ -53,6 +53,8 @@ func (z *zapper) DFatal(msg string, fields ...zap.Field) {
 }
 
 func (z *zapper) Log(l zap.Level, msg string, fields ...zap.Field) {
+	// NOTE: logging at panic and fatal level actually panic and exit the
+	// process, meaning that bark loggers cannot compose well.
 	switch l {
 	case zap.PanicLevel, zap.FatalLevel:
 	default: