diff --git a/logging/gokit.go b/logging/gokit.go index 508fc385..210833b5 100644 --- a/logging/gokit.go +++ b/logging/gokit.go @@ -17,8 +17,13 @@ func NewGoKitFormat(l Level, f Format) Interface { } else { logger = log.NewLogfmtLogger(log.NewSyncWriter(os.Stderr)) } + return addStandardFields(logger, l) +} + +// stand-alone for test purposes +func addStandardFields(logger log.Logger, l Level) Interface { + logger = log.With(logger, "ts", log.DefaultTimestampUTC, "caller", log.Caller(5)) logger = level.NewFilter(logger, l.Gokit) - logger = log.With(logger, "ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller) return gokit{logger} } @@ -36,32 +41,52 @@ type gokit struct { log.Logger } +// Helper to defer sprintf until it is needed. +type sprintf struct { + format string + args []interface{} +} + +func (s *sprintf) String() string { + return fmt.Sprintf(s.format, s.args...) +} + +// Helper to defer sprint until it is needed. +// Note we don't use Sprintln because the output is passed to go-kit as one value among many on a line +type sprint struct { + args []interface{} +} + +func (s *sprint) String() string { + return fmt.Sprint(s.args...) +} + func (g gokit) Debugf(format string, args ...interface{}) { - level.Debug(g.Logger).Log("msg", fmt.Sprintf(format, args...)) + level.Debug(g.Logger).Log("msg", &sprintf{format: format, args: args}) } func (g gokit) Debugln(args ...interface{}) { - level.Debug(g.Logger).Log("msg", fmt.Sprintln(args...)) + level.Debug(g.Logger).Log("msg", &sprint{args: args}) } func (g gokit) Infof(format string, args ...interface{}) { - level.Info(g.Logger).Log("msg", fmt.Sprintf(format, args...)) + level.Info(g.Logger).Log("msg", &sprintf{format: format, args: args}) } func (g gokit) Infoln(args ...interface{}) { - level.Info(g.Logger).Log("msg", fmt.Sprintln(args...)) + level.Info(g.Logger).Log("msg", &sprint{args: args}) } func (g gokit) Warnf(format string, args ...interface{}) { - level.Warn(g.Logger).Log("msg", fmt.Sprintf(format, args...)) + level.Warn(g.Logger).Log("msg", &sprintf{format: format, args: args}) } func (g gokit) Warnln(args ...interface{}) { - level.Warn(g.Logger).Log("msg", fmt.Sprintln(args...)) + level.Warn(g.Logger).Log("msg", &sprint{args: args}) } func (g gokit) Errorf(format string, args ...interface{}) { - level.Error(g.Logger).Log("msg", fmt.Sprintf(format, args...)) + level.Error(g.Logger).Log("msg", &sprintf{format: format, args: args}) } func (g gokit) Errorln(args ...interface{}) { - level.Error(g.Logger).Log("msg", fmt.Sprintln(args...)) + level.Error(g.Logger).Log("msg", &sprint{args: args}) } func (g gokit) WithField(key string, value interface{}) Interface { diff --git a/logging/gokit_test.go b/logging/gokit_test.go new file mode 100644 index 00000000..afcc0c90 --- /dev/null +++ b/logging/gokit_test.go @@ -0,0 +1,25 @@ +package logging + +import ( + "testing" + + "github.com/go-kit/kit/log" + "github.com/go-kit/kit/log/level" +) + +func BenchmarkDebugf(b *testing.B) { + lvl := Level{Gokit: level.AllowInfo()} + g := log.NewNopLogger() + logger := addStandardFields(g, lvl) + // Simulate the parameters used in middleware/logging.go + var ( + method = "method" + uri = "https://example.com/foobar" + statusCode = 404 + duration = 42 + ) + b.ResetTimer() + for i := 0; i < b.N; i++ { + logger.Debugf("%s %s (%d) %s", method, uri, statusCode, duration) + } +}