Skip to content
21 changes: 21 additions & 0 deletions log/benchmark_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,21 @@
package log_test

import (
"testing"

"github.com/peterbourgon/gokit/log"
)

func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) {
logger = logger.With("common_key", "common_value")
b.ReportAllocs()
b.ResetTimer()
for i := 0; i < b.N; i++ {
f(logger)
}
}

var (
simpleMessage = func(logger log.Logger) { logger.Log("foo") }
contextualMessage = func(logger log.Logger) { logger.Log("bar", "foo_key", "foo_value") }
)
71 changes: 71 additions & 0 deletions log/json_logger.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,71 @@
package log

import (
"encoding/json"
"fmt"
"io"
)

type jsonLogger struct {
io.Writer
key string
keyvals []interface{}
}

// NewJSONLogger returns a Logger that marshals each log line as a JSON
// object. Because fields are keys in a JSON object, they must be unique, and
// last-writer-wins. The actual log message is placed under the "msg" key. To
// change that, use the NewJSONLoggerWithKey constructor.
func NewJSONLogger(w io.Writer) Logger {
return NewJSONLoggerWithKey(w, "msg")
}

// NewJSONLoggerWithKey is the same as NewJSONLogger but allows the user to
// specify the key under which the actual log message is placed in the JSON
// object.
func NewJSONLoggerWithKey(w io.Writer, messageKey string) Logger {
return &jsonLogger{
Writer: w,
key: messageKey,
}
}

func (l *jsonLogger) With(keyvals ...interface{}) Logger {
if len(keyvals)%2 == 1 {
panic("odd number of keyvals")
}
return &jsonLogger{
Writer: l.Writer,
key: l.key,
keyvals: append(l.keyvals, keyvals...),
}
}

func (l *jsonLogger) Log(message string, keyvals ...interface{}) error {
if len(keyvals)%2 == 1 {
panic("odd number of keyvals")
}
m := make(map[string]interface{}, len(l.keyvals)+len(keyvals)+1)
for i := 0; i < len(l.keyvals); i += 2 {
merge(m, l.keyvals[i], l.keyvals[i+1])
}
for i := 0; i < len(keyvals); i += 2 {
merge(m, keyvals[i], keyvals[i+1])
}
m[l.key] = message
return json.NewEncoder(l.Writer).Encode(m)
}

func merge(dst map[string]interface{}, k, v interface{}) map[string]interface{} {
var key string
switch x := k.(type) {
case string:
key = x
case fmt.Stringer:
key = x.String()
default:
key = fmt.Sprintf("%v", x)
}
dst[key] = v

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

my last comment was lost with the change to varargs: if v is of type error, it will be encoded as an empty {} by the JSON encoder. Ideally it should be special cased to call .Error() if v is of type error.

return dst
}
48 changes: 48 additions & 0 deletions log/json_logger_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,48 @@
package log_test

import (
"bytes"
"io/ioutil"
"testing"
"time"

"github.com/peterbourgon/gokit/log"
)

func TestJSONLogger(t *testing.T) {
buf := &bytes.Buffer{}
logger := log.NewJSONLogger(buf)

logger.Log("a")
if want, have := `{"msg":"a"}`+"\n", buf.String(); want != have {
t.Errorf("want %#v, have %#v", want, have)
}

buf.Reset()
if err := logger.With("level", "INFO").Log("b"); err != nil {

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd try to log With() various types to test that error special case, and other possible special cases =P

It's very frustrating to log.With("err", err) and see an empty object in the logs. =]

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, thank you, that was missed in the update. I'll fix it directly.

t.Fatal(err)
}
if want, have := `{"level":"INFO","msg":"b"}`+"\n", buf.String(); want != have {
t.Errorf("want %#v, have %#v", want, have)
}

buf.Reset()
logger = logger.With("request.size", 1024)
logger = logger.With("response.code", 200)
logger = logger.With("response.duration", 42*time.Millisecond)
logger = logger.With("headers", map[string][]string{"X-Foo": []string{"A", "B"}})
if err := logger.Log("OK"); err != nil {
t.Fatal(err)
}
if want, have := `{"headers":{"X-Foo":["A","B"]},"msg":"OK","request.size":1024,"response.code":200,"response.duration":42000000}`+"\n", buf.String(); want != have {
t.Errorf("want\n\t%#v, have\n\t%#v", want, have)
}
}

func BenchmarkJSONLoggerSimple(b *testing.B) {
benchmarkRunner(b, log.NewJSONLogger(ioutil.Discard), simpleMessage)
}

func BenchmarkJSONLoggerContextual(b *testing.B) {
benchmarkRunner(b, log.NewJSONLogger(ioutil.Discard), contextualMessage)
}
60 changes: 60 additions & 0 deletions log/levels.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,60 @@
package log

// Levels provides a default set of leveled loggers.
type Levels struct {
Debug Logger
Info Logger
Error Logger
}

type levelOptions struct {
levelKey string
debugValue string
infoValue string
errorValue string
}

// LevelOption sets a parameter for leveled loggers.
type LevelOption func(*levelOptions)

// LevelKey sets the key for the field used to indicate log level. By default,
// the key is "level".
func LevelKey(key string) LevelOption {
return func(o *levelOptions) { o.levelKey = key }
}

// DebugLevelValue sets the value for the field used to indicate the debug log
// level. By default, the value is "DEBUG".
func DebugLevelValue(value string) LevelOption {
return func(o *levelOptions) { o.debugValue = value }
}

// InfoLevelValue sets the value for the field used to indicate the debug log
// level. By default, the value is "INFO".
func InfoLevelValue(value string) LevelOption {
return func(o *levelOptions) { o.infoValue = value }
}

// ErrorLevelValue sets the value for the field used to indicate the debug log
// level. By default, the value is "ERROR".
func ErrorLevelValue(value string) LevelOption {
return func(o *levelOptions) { o.errorValue = value }
}

// NewLevels returns a new set of leveled loggers based on the base logger.
func NewLevels(base Logger, options ...LevelOption) Levels {
opts := &levelOptions{
levelKey: "level",
debugValue: "DEBUG",
infoValue: "INFO",
errorValue: "ERROR",
}
for _, option := range options {
option(opts)
}
return Levels{
Debug: base.With(opts.levelKey, opts.debugValue),
Info: base.With(opts.levelKey, opts.infoValue),
Error: base.With(opts.levelKey, opts.errorValue),
}
}
46 changes: 46 additions & 0 deletions log/levels_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,46 @@
package log_test

import (
"bytes"
"testing"

"github.com/peterbourgon/gokit/log"
)

func TestBasicLevels(t *testing.T) {
buf := bytes.Buffer{}
levels := log.NewLevels(log.NewPrefixLogger(&buf))

levels.Debug.Log("👨") // of course you'd want to do this
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks like me.

if want, have := "level=DEBUG 👨\n", buf.String(); want != have {
t.Errorf("want %#v, have %#v", want, have)
}

buf.Reset()
levels.Info.Log("🚀")
if want, have := "level=INFO 🚀\n", buf.String(); want != have {
t.Errorf("want %#v, have %#v", want, have)
}

buf.Reset()
levels.Error.Log("🍵")
if want, have := "level=ERROR 🍵\n", buf.String(); want != have {
t.Errorf("want %#v, have %#v", want, have)
}
}

func TestModifiedLevels(t *testing.T) {
buf := bytes.Buffer{}
levels := log.NewLevels(
log.NewJSONLogger(&buf),
log.LevelKey("l"),
log.DebugLevelValue("⛄"),
log.InfoLevelValue("🌜"),
log.ErrorLevelValue("🌊"),
)

levels.Debug.With("easter_island", "🗿").Log("💃💃💃")
if want, have := `{"easter_island":"🗿","l":"⛄","msg":"💃💃💃"}`+"\n", buf.String(); want != have {
t.Errorf("want %#v, have %#v", want, have)
}
}
7 changes: 7 additions & 0 deletions log/log.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,7 @@
package log

// Logger is the least-common-denominator interface for all log operations.
type Logger interface {
With(keyvals ...interface{}) Logger
Log(message string, keyvals ...interface{}) error
}
63 changes: 63 additions & 0 deletions log/prefix_logger.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,63 @@
package log

import (
"fmt"
"io"
)

type prefixLogger struct {
io.Writer
keyvals []interface{}
}

// NewPrefixLogger returns a basic logger that encodes all keyvals as simple
// "k=v" pairs prefixed on each log line.
func NewPrefixLogger(w io.Writer) Logger {
return &prefixLogger{
Writer: w,
}
}

func (l *prefixLogger) With(keyvals ...interface{}) Logger {
if len(keyvals)%2 == 1 {
panic("odd number of keyvals")
}
return &prefixLogger{
Writer: l.Writer,
keyvals: append(l.keyvals, keyvals...),
}
}

func (l *prefixLogger) Log(message string, keyvals ...interface{}) error {
if len(keyvals)%2 == 1 {
panic("odd number of keyvals")
}
if err := encodeMany(l.Writer, l.keyvals...); err != nil {
return err
}
if err := encodeMany(l.Writer, keyvals...); err != nil {
return err
}
if _, err := fmt.Fprint(l.Writer, message); err != nil {
return err
}
if message[len(message)-1] != '\n' {
if _, err := fmt.Fprintln(l.Writer); err != nil {
return err
}
}
return nil
}

func encodeMany(w io.Writer, keyvals ...interface{}) error {
if len(keyvals)%2 == 1 {
panic("odd number of keyvals")
}
for i := 0; i < len(keyvals); i += 2 {
_, err := fmt.Fprintf(w, "%s=%v ", keyvals[i], keyvals[i+1])
if err != nil {
return err
}
}
return nil
}
46 changes: 46 additions & 0 deletions log/prefix_logger_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,46 @@
package log_test

import (
"bytes"
"errors"
"io/ioutil"
"testing"

"github.com/peterbourgon/gokit/log"
)

func TestPrefixLogger(t *testing.T) {
buf := &bytes.Buffer{}
logger := log.NewPrefixLogger(buf)

if err := logger.Log("hello"); err != nil {
t.Fatal(err)
}
if want, have := "hello\n", buf.String(); want != have {
t.Errorf("want %#v, have %#v", want, have)
}

buf.Reset()
if err := logger.Log("world", "k", "v"); err != nil {
t.Fatal(err)
}
if want, have := "k=v world\n", buf.String(); want != have {
t.Errorf("want %#v, have %#v", want, have)
}

buf.Reset()
if err := logger.With("z", 1, "a", 2).Log("🐰", "m", errors.New("n")); err != nil {
t.Fatal(err)
}
if want, have := "z=1 a=2 m=n 🐰\n", buf.String(); want != have {
t.Errorf("want %#v, have %#v", want, have)
}
}

func BenchmarkPrefixLoggerSimple(b *testing.B) {
benchmarkRunner(b, log.NewPrefixLogger(ioutil.Discard), simpleMessage)
}

func BenchmarkPrefixLoggerContextual(b *testing.B) {
benchmarkRunner(b, log.NewPrefixLogger(ioutil.Discard), contextualMessage)
}