Merge pull request go-kit#76 from go-kit/gophercon-log-api

New API for package log (post-GopherCon)

Fixes go-kit#63 and some usability concerns.

addsvc/main.go

@@ -62,7 +62,7 @@ func main() {
 	// `package log` domain
 	var logger kitlog.Logger
 	logger = kitlog.NewLogfmtLogger(os.Stderr)
-	logger = kitlog.With(logger, "ts", kitlog.DefaultTimestampUTC)
+	logger = kitlog.NewContext(logger).With("ts", kitlog.DefaultTimestampUTC)
 	stdlog.SetOutput(kitlog.NewStdlibAdapter(logger)) // redirect stdlib logging to us
 	stdlog.SetFlags(0)                                // flags are handled in our logger
 

log/benchmark_test.go

@@ -7,15 +7,15 @@ import (
 )
 
 func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) {
-	logger = log.With(logger, "common_key", "common_value")
+	lc := log.NewContext(logger).With("common_key", "common_value")
 	b.ReportAllocs()
 	b.ResetTimer()
 	for i := 0; i < b.N; i++ {
-		f(logger)
+		f(lc)
 	}
 }
 
 var (
 	baseMessage = func(logger log.Logger) { logger.Log("foo_key", "foo_value") }
-	withMessage = func(logger log.Logger) { log.With(logger, "a", "b").Log("c", "d") }
+	withMessage = func(logger log.Logger) { log.NewContext(logger).With("a", "b").Log("c", "d") }
 )

log/example_test.go

@@ -0,0 +1,23 @@
+package log_test
+
+import (
+	"os"
+
+	"github.com/go-kit/kit/log"
+)
+
+func ExampleContext() {
+	logger := log.NewLogfmtLogger(os.Stdout)
+	logger.Log("foo", 123)
+	ctx := log.NewContext(logger).With("level", "info")
+	ctx.Log()
+	ctx = ctx.With("msg", "hello")
+	ctx.Log()
+	ctx.With("a", 1).Log("b", 2)
+
+	// Output:
+	// foo=123
+	// level=info
+	// level=info msg=hello
+	// level=info msg=hello a=1 b=2
+}

log/levels/levels.go

@@ -0,0 +1,127 @@
+package levels
+
+import "github.com/go-kit/kit/log"
+
+// Levels provides a leveled logging wrapper around a logger. It has five
+// levels: debug, info, warning (warn), error, and critical (crit). If you
+// want a different set of levels, you can create your own levels type very
+// easily, and you can elide the configuration.
+type Levels struct {
+	ctx      log.Context
+	levelKey string
+
+	// We have a choice between storing level values in string fields or
+	// making a separate context for each level. When using string fields the
+	// Log method must combine the base context, the level data, and the
+	// logged keyvals; but the With method only requires updating one context.
+	// If we instead keep a separate context for each level the Log method
+	// must only append the new keyvals; but the With method would have to
+	// update all five contexts.
+
+	// Roughly speaking, storing multiple contexts breaks even if the ratio of
+	// Log/With calls is more than the number of levels. We have chosen to
+	// make the With method cheap and the Log method a bit more costly because
+	// we do not expect most applications to Log more than five times for each
+	// call to With.
+
+	debugValue string
+	infoValue  string
+	warnValue  string
+	errorValue string
+	critValue  string
+}
+
+// New creates a new leveled logger, wrapping the passed logger.
+func New(logger log.Logger, options ...Option) Levels {
+	l := Levels{
+		ctx:      log.NewContext(logger),
+		levelKey: "level",
+
+		debugValue: "debug",
+		infoValue:  "info",
+		warnValue:  "warn",
+		errorValue: "error",
+		critValue:  "crit",
+	}
+	for _, option := range options {
+		option(&l)
+	}
+	return l
+}
+
+// With returns a new leveled logger that includes keyvals in all log events.
+func (l Levels) With(keyvals ...interface{}) Levels {
+	return Levels{
+		ctx:        l.ctx.With(keyvals...),
+		levelKey:   l.levelKey,
+		debugValue: l.debugValue,
+		infoValue:  l.infoValue,
+		warnValue:  l.warnValue,
+		errorValue: l.errorValue,
+		critValue:  l.critValue,
+	}
+}
+
+// Debug logs a debug event along with keyvals.
+func (l Levels) Debug(keyvals ...interface{}) error {
+	return l.ctx.WithPrefix(l.levelKey, l.debugValue).Log(keyvals...)
+}
+
+// Info logs an info event along with keyvals.
+func (l Levels) Info(keyvals ...interface{}) error {
+	return l.ctx.WithPrefix(l.levelKey, l.infoValue).Log(keyvals...)
+}
+
+// Warn logs a warn event along with keyvals.
+func (l Levels) Warn(keyvals ...interface{}) error {
+	return l.ctx.WithPrefix(l.levelKey, l.warnValue).Log(keyvals...)
+}
+
+// Error logs an error event along with keyvals.
+func (l Levels) Error(keyvals ...interface{}) error {
+	return l.ctx.WithPrefix(l.levelKey, l.errorValue).Log(keyvals...)
+}
+
+// Crit logs a crit event along with keyvals.
+func (l Levels) Crit(keyvals ...interface{}) error {
+	return l.ctx.WithPrefix(l.levelKey, l.critValue).Log(keyvals...)
+}
+
+// Option sets a parameter for leveled loggers.
+type Option func(*Levels)
+
+// Key sets the key for the field used to indicate log level. By default,
+// the key is "level".
+func Key(key string) Option {
+	return func(l *Levels) { l.levelKey = key }
+}
+
+// DebugValue sets the value for the field used to indicate the debug log
+// level. By default, the value is "debug".
+func DebugValue(value string) Option {
+	return func(l *Levels) { l.debugValue = value }
+}
+
+// InfoValue sets the value for the field used to indicate the info log level.
+// By default, the value is "info".
+func InfoValue(value string) Option {
+	return func(l *Levels) { l.infoValue = value }
+}
+
+// WarnValue sets the value for the field used to indicate the warning log
+// level. By default, the value is "warn".
+func WarnValue(value string) Option {
+	return func(l *Levels) { l.warnValue = value }
+}
+
+// ErrorValue sets the value for the field used to indicate the error log
+// level. By default, the value is "error".
+func ErrorValue(value string) Option {
+	return func(l *Levels) { l.errorValue = value }
+}
+
+// CritValue sets the value for the field used to indicate the critical log
+// level. By default, the value is "crit".
+func CritValue(value string) Option {
+	return func(l *Levels) { l.critValue = value }
+}

log/levels/levels_test.go

@@ -0,0 +1,55 @@
+package levels_test
+
+import (
+	"bytes"
+	"os"
+	"testing"
+
+	"github.com/go-kit/kit/log"
+	"github.com/go-kit/kit/log/levels"
+)
+
+func TestDefaultLevels(t *testing.T) {
+	buf := bytes.Buffer{}
+	logger := levels.New(log.NewLogfmtLogger(&buf))
+
+	logger.Debug("msg", "résumé") // of course you'd want to do this
+	if want, have := "level=debug msg=résumé\n", buf.String(); want != have {
+		t.Errorf("want %#v, have %#v", want, have)
+	}
+
+	buf.Reset()
+	logger.Info("msg", "Åhus")
+	if want, have := "level=info msg=Åhus\n", buf.String(); want != have {
+		t.Errorf("want %#v, have %#v", want, have)
+	}
+
+	buf.Reset()
+	logger.Error("msg", "© violation")
+	if want, have := "level=error msg=\"© violation\"\n", buf.String(); want != have {
+		t.Errorf("want %#v, have %#v", want, have)
+	}
+}
+
+func TestModifiedLevels(t *testing.T) {
+	buf := bytes.Buffer{}
+	logger := levels.New(
+		log.NewJSONLogger(&buf),
+		levels.Key("l"),
+		levels.DebugValue("dbg"),
+	)
+	logger.With("easter_island", "176°").Debug("msg", "moai")
+	if want, have := `{"easter_island":"176°","l":"dbg","msg":"moai"}`+"\n", buf.String(); want != have {
+		t.Errorf("want %#v, have %#v", want, have)
+	}
+}
+
+func ExampleLevels() {
+	logger := levels.New(log.NewLogfmtLogger(os.Stdout))
+	logger.Debug("msg", "hello")
+	logger.With("context", "foo").Warn("err", "error")
+
+	// Output:
+	// level=debug msg=hello
+	// level=warn context=foo err=error
+}