Remove time, level, and message keys in logger provider

changelog/@unreleased/pr-123.v2.yml

@@ -0,0 +1,8 @@
+type: improvement
+improvement:
+  description: |
+    Removes the time, level and message keys from the loggers returned by implementations of the LoggerProvider interface.
+    Previously, wlog.Logger instances returned by the LoggerProvider interface set "time" as a top-level key and wlog.LeveledLogger instances returned by the LoggerProvider interface set "time", "level" and "message" as top-level keys. After this change, these top-level keys are no longer set. This allows the underlying logger interfaces to be used by logger implementations that may not set these top-level keys in their output.
+    Log type implementations that use these loggers may no longer assume that these keys are set and must set them themselves if they are desired in the output. Existing implementations have all been updated to do so, so there should be no behavioral changes.
+  links:
+  - https://github.com/palantir/witchcraft-go-logging/pull/123

wlog-glog/internal/logger.go

@@ -51,16 +51,10 @@ func (*gLogger) SetLevel(level wlog.LogLevel) {
 
 func createGLogMsg(msg string, params []wlog.Param) string {
 	entry := wlog.NewMapLogEntry()
-	wlog.ApplyParams(entry, params)
-
-	var parts []string
-	if msg != "" {
-		parts = append(parts, msg)
-	}
-	parts = append(parts, paramsToLog(entry)...)
+	wlog.ApplyParams(entry, wlog.ParamsWithMessage(msg, params))
 
 	// TODO: ignore/omit unsafe params?
-	return strings.Join(parts, ", ")
+	return strings.Join(paramsToLog(entry), ", ")
 }
 
 // paramsToLog returns the parameters to log as strings of the form "<key>: <value>".

wlog-zap/internal/logger.go

@@ -147,8 +147,9 @@ func (l *zapLogger) SetLevel(level wlog.LogLevel) {
 
 func logOutput(logFn func(string, ...zap.Field), msg string, params []wlog.Param) {
 	entry := newZapLogEntry()
-	wlog.ApplyParams(entry, params)
-	logFn(msg, entry.Fields()...)
+	wlog.ApplyParams(entry, wlog.ParamsWithMessage(msg, params))
+	// Empty string is used for the "message" because the message is added to params above if present
+	logFn("", entry.Fields()...)
 }
 
 func encodeField(key string, value interface{}, enc zapcore.ObjectEncoder) error {

wlog-zap/internal/provider.go

@@ -20,7 +20,6 @@ import (
 	"time"
 
 	"github.com/palantir/witchcraft-go-logging/wlog"
-	"github.com/palantir/witchcraft-go-logging/wlog/svclog/svc1log"
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
 )
@@ -33,7 +32,6 @@ type loggerProvider struct{}
 
 func (lp *loggerProvider) NewLogger(w io.Writer) wlog.Logger {
 	logger, atomicLevel := newZapLogger(w, wlog.InfoLevel, zapcore.EncoderConfig{
-		TimeKey:        wlog.TimeKey,
 		EncodeTime:     rfc3339NanoTimeEncoder,
 		EncodeDuration: zapcore.NanosDurationEncoder,
 	})
@@ -45,12 +43,9 @@ func (lp *loggerProvider) NewLogger(w io.Writer) wlog.Logger {
 
 func (lp *loggerProvider) NewLeveledLogger(w io.Writer, level wlog.LogLevel) wlog.LeveledLogger {
 	logger, atomicLevel := newZapLogger(w, level, zapcore.EncoderConfig{
-		TimeKey:        wlog.TimeKey,
 		EncodeTime:     rfc3339NanoTimeEncoder,
 		EncodeDuration: zapcore.NanosDurationEncoder,
-		LevelKey:       svc1log.LevelKey,
 		EncodeLevel:    zapcore.CapitalLevelEncoder,
-		MessageKey:     svc1log.MessageKey,
 	})
 	return &zapLogger{
 		logger: logger,

wlog-zerolog/internal/logger.go

@@ -16,11 +16,9 @@ package zeroimpl
 
 import (
 	"reflect"
-	"time"
 
 	"github.com/palantir/witchcraft-go-logging/wlog"
 	"github.com/palantir/witchcraft-go-logging/wlog-zerolog/internal/marshalers"
-	"github.com/palantir/witchcraft-go-logging/wlog/svclog/svc1log"
 	"github.com/rs/zerolog"
 )
 
@@ -178,35 +176,35 @@ func (l *zeroLogger) Log(params ...wlog.Param) {
 	if !l.should(zerolog.NoLevel) {
 		return
 	}
-	logOutput(l.logger.Log, "", "", params)
+	logOutput(l.logger.Log, "", params)
 }
 
 func (l *zeroLogger) Debug(msg string, params ...wlog.Param) {
 	if !l.should(zerolog.DebugLevel) {
 		return
 	}
-	logOutput(l.logger.Log, msg, svc1log.LevelDebugValue, params)
+	logOutput(l.logger.Log, msg, params)
 }
 
 func (l *zeroLogger) Info(msg string, params ...wlog.Param) {
 	if !l.should(zerolog.InfoLevel) {
 		return
 	}
-	logOutput(l.logger.Log, msg, svc1log.LevelInfoValue, params)
+	logOutput(l.logger.Log, msg, params)
 }
 
 func (l *zeroLogger) Warn(msg string, params ...wlog.Param) {
 	if !l.should(zerolog.WarnLevel) {
 		return
 	}
-	logOutput(l.logger.Log, msg, svc1log.LevelWarnValue, params)
+	logOutput(l.logger.Log, msg, params)
 }
 
 func (l *zeroLogger) Error(msg string, params ...wlog.Param) {
 	if !l.should(zerolog.ErrorLevel) {
 		return
 	}
-	logOutput(l.logger.Log, msg, svc1log.LevelErrorValue, params)
+	logOutput(l.logger.Log, msg, params)
 }
 
 func (l *zeroLogger) SetLevel(level wlog.LogLevel) {
@@ -220,18 +218,14 @@ func reverseParams(params []wlog.Param) {
 	}
 }
 
-func logOutput(newEvt func() *zerolog.Event, msg, levelVal string, params []wlog.Param) {
+func logOutput(newEvt func() *zerolog.Event, msg string, params []wlog.Param) {
 	entry := &zeroLogEntry{
 		evt:  newEvt(),
 		keys: make(map[string]struct{}),
 	}
 	if !entry.evt.Enabled() {
 		return
 	}
-	entry.evt = entry.evt.Str(wlog.TimeKey, time.Now().Format(time.RFC3339Nano))
-	if levelVal != "" {
-		entry.evt = entry.evt.Str(svc1log.LevelKey, levelVal)
-	}
 	reverseParams(params)
 	wlog.ApplyParams(entry, params)
 	entry.Evt().Msg(msg)

wlog/auditlog/audit2log/logger_default.go

@@ -15,6 +15,8 @@
 package audit2log
 
 import (
+	"time"
+
 	"github.com/palantir/witchcraft-go-logging/wlog"
 )
 
@@ -39,5 +41,6 @@ func toParams(name string, result AuditResultType, inParams []Param) []wlog.Para
 var defaultTypeParam = []wlog.Param{
 	wlog.NewParam(func(entry wlog.LogEntry) {
 		entry.StringValue(wlog.TypeKey, TypeValue)
+		entry.StringValue(wlog.TimeKey, time.Now().Format(time.RFC3339Nano))
 	}),
 }

wlog/diaglog/diag1log/logger_default.go

@@ -15,6 +15,8 @@
 package diag1log
 
 import (
+	"time"
+
 	"github.com/palantir/witchcraft-go-logging/conjure/witchcraft/api/logging"
 	"github.com/palantir/witchcraft-go-logging/wlog"
 )
@@ -40,5 +42,6 @@ func toParams(diagnostic logging.Diagnostic, inParams []Param) []wlog.Param {
 var defaultTypeParam = []wlog.Param{
 	wlog.NewParam(func(entry wlog.LogEntry) {
 		entry.StringValue(wlog.TypeKey, TypeValue)
+		entry.StringValue(wlog.TimeKey, time.Now().Format(time.RFC3339Nano))
 	}),
 }

wlog/evtlog/evt2log/logger_default.go

@@ -15,6 +15,8 @@
 package evt2log
 
 import (
+	"time"
+
 	"github.com/palantir/witchcraft-go-logging/wlog"
 )
 
@@ -39,5 +41,6 @@ func toParams(evtName string, inParams []Param) []wlog.Param {
 var defaultTypeParam = []wlog.Param{
 	wlog.NewParam(func(entry wlog.LogEntry) {
 		entry.StringValue(wlog.TypeKey, TypeValue)
+		entry.StringValue(wlog.TimeKey, time.Now().Format(time.RFC3339Nano))
 	}),
 }

wlog/logger_provider_jsonmarshal.go

@@ -41,28 +41,28 @@ func (l *jsonMapLogger) Log(params ...Param) {
 func (l *jsonMapLogger) Debug(msg string, params ...Param) {
 	switch l.level {
 	case DebugLevel:
-		l.logOutput(append(params, StringParam("message", msg), StringParam("level", "DEBUG")))
+		l.logOutput(ParamsWithMessage(msg, params))
 	}
 }
 
 func (l *jsonMapLogger) Info(msg string, params ...Param) {
 	switch l.level {
 	case DebugLevel, InfoLevel:
-		l.logOutput(append(params, StringParam("message", msg), StringParam("level", "INFO")))
+		l.logOutput(ParamsWithMessage(msg, params))
 	}
 }
 
 func (l *jsonMapLogger) Warn(msg string, params ...Param) {
 	switch l.level {
 	case DebugLevel, InfoLevel, WarnLevel:
-		l.logOutput(append(params, StringParam("message", msg), StringParam("level", "WARN")))
+		l.logOutput(ParamsWithMessage(msg, params))
 	}
 }
 
 func (l *jsonMapLogger) Error(msg string, params ...Param) {
 	switch l.level {
 	case DebugLevel, InfoLevel, WarnLevel, ErrorLevel:
-		l.logOutput(append(params, StringParam("message", msg), StringParam("level", "ERROR")))
+		l.logOutput(ParamsWithMessage(msg, params))
 	}
 }
 

wlog/metriclog/metric1log/logger_default.go

@@ -15,6 +15,8 @@
 package metric1log
 
 import (
+	"time"
+
 	"github.com/palantir/witchcraft-go-logging/wlog"
 )
 
@@ -39,5 +41,6 @@ func toParams(metricName, metricType string, inParams []Param) []wlog.Param {
 var defaultTypeParam = []wlog.Param{
 	wlog.NewParam(func(entry wlog.LogEntry) {
 		entry.StringValue(wlog.TypeKey, TypeValue)
+		entry.StringValue(wlog.TimeKey, time.Now().Format(time.RFC3339Nano))
 	}),
 }

wlog/params.go

@@ -55,6 +55,16 @@ func ApplyParams(logger LogEntry, params []Param) {
 	}
 }
 
+// ParamsWithMessage returns a new slice that appends a StringParam with the key "message" and
+// value of the provided msg parameter if it is non-empty. If msg is empty, returns the provided slice
+// without modification.
+func ParamsWithMessage(msg string, params []Param) []Param {
+	if msg != "" {
+		return append(params, StringParam("message", msg))
+	}
+	return params
+}
+
 type paramFunc func(logger LogEntry)
 
 func (f paramFunc) apply(logger LogEntry) {

wlog/reqlog/req2log/logger_default.go

@@ -16,6 +16,7 @@ package req2log
 
 import (
 	"strings"
+	"time"
 
 	"github.com/palantir/witchcraft-go-logging/wlog"
 	"github.com/palantir/witchcraft-go-logging/wlog/extractor"
@@ -43,6 +44,7 @@ func (l *defaultLogger) Request(r Request) {
 
 	l.logger.Log(
 		wlog.StringParam(wlog.TypeKey, TypeValue),
+		wlog.StringParam(wlog.TimeKey, time.Now().Format(time.RFC3339Nano)),
 		wlog.OptionalStringParam(methodKey, r.Request.Method),
 		wlog.StringParam(protocolKey, r.Request.Proto),
 		wlog.StringParam(pathKey, reqPath),

wlog/svclog/svc1log/logger_default.go

@@ -15,9 +15,40 @@
 package svc1log
 
 import (
+	"time"
+
 	"github.com/palantir/witchcraft-go-logging/wlog"
 )
 
+var (
+	// Level params declared as variables so that they are only allocated once
+	debugLevelParam = wlog.NewParam(func(entry wlog.LogEntry) {
+		entry.StringValue(LevelKey, LevelDebugValue)
+	})
+	infoLevelParam = wlog.NewParam(func(entry wlog.LogEntry) {
+		entry.StringValue(LevelKey, LevelInfoValue)
+	})
+	warnLevelParam = wlog.NewParam(func(entry wlog.LogEntry) {
+		entry.StringValue(LevelKey, LevelWarnValue)
+	})
+	errorLevelParam = wlog.NewParam(func(entry wlog.LogEntry) {
+		entry.StringValue(LevelKey, LevelErrorValue)
+	})
+)
+
+func DebugLevelParam() wlog.Param {
+	return debugLevelParam
+}
+func InfoLevelParam() wlog.Param {
+	return infoLevelParam
+}
+func WarnLevelParam() wlog.Param {
+	return warnLevelParam
+}
+func ErrorLevelParam() wlog.Param {
+	return errorLevelParam
+}
+
 type defaultLogger struct {
 	loggerCreator func(level wlog.LogLevel) wlog.LeveledLogger
 
@@ -26,39 +57,39 @@ type defaultLogger struct {
 }
 
 func (l *defaultLogger) Debug(msg string, params ...Param) {
-	l.logger.Debug(msg, l.toParams(params)...)
+	l.logger.Debug(msg, toParams(DebugLevelParam(), params)...)
 }
 
 func (l *defaultLogger) Info(msg string, params ...Param) {
-	l.logger.Info(msg, l.toParams(params)...)
+	l.logger.Info(msg, toParams(InfoLevelParam(), params)...)
+
 }
 
 func (l *defaultLogger) Warn(msg string, params ...Param) {
-	l.logger.Warn(msg, l.toParams(params)...)
+	l.logger.Warn(msg, toParams(WarnLevelParam(), params)...)
 }
 
 func (l *defaultLogger) Error(msg string, params ...Param) {
-	l.logger.Error(msg, l.toParams(params)...)
+	l.logger.Error(msg, toParams(ErrorLevelParam(), params)...)
 }
 
 func (l *defaultLogger) SetLevel(level wlog.LogLevel) {
 	l.logger.SetLevel(level)
 }
 
-func (l *defaultLogger) toParams(inParams []Param) []wlog.Param {
-	if len(inParams) == 0 {
-		return defaultTypeParam
-	}
-	outParams := make([]wlog.Param, len(defaultTypeParam)+len(inParams))
+func toParams(level wlog.Param, inParams []Param) []wlog.Param {
+	outParams := make([]wlog.Param, len(defaultTypeParam)+1+len(inParams))
 	copy(outParams, defaultTypeParam)
+	outParams[len(defaultTypeParam)] = level
 	for idx := range inParams {
-		outParams[len(defaultTypeParam)+idx] = wlog.NewParam(inParams[idx].apply)
+		outParams[len(defaultTypeParam)+1+idx] = wlog.NewParam(inParams[idx].apply)
 	}
 	return outParams
 }
 
 var defaultTypeParam = []wlog.Param{
 	wlog.NewParam(func(entry wlog.LogEntry) {
 		entry.StringValue(wlog.TypeKey, TypeValue)
+		entry.StringValue(wlog.TimeKey, time.Now().Format(time.RFC3339Nano))
 	}),
 }

wlog/trclog/trc1log/logger_default.go

@@ -16,6 +16,7 @@ package trc1log
 
 import (
 	"reflect"
+	"time"
 
 	"github.com/palantir/witchcraft-go-logging/wlog"
 	"github.com/palantir/witchcraft-go-tracing/wtracing"
@@ -32,6 +33,7 @@ func (l *defaultLogger) Log(span wtracing.SpanModel, params ...Param) {
 		append([]wlog.Param{
 			wlog.NewParam(func(entry wlog.LogEntry) {
 				entry.StringValue(wlog.TypeKey, TypeValue)
+				entry.StringValue(wlog.TimeKey, time.Now().Format(time.RFC3339Nano))
 				entry.ObjectValue(SpanKey, span, spanType)
 			}),
 		}, l.toParams(params)...)...,