ctx: store logger in context when missing or different that stored one

Current implementation stores a copy of the logger as a pointer and
update its content, which is now unecessary since the introduction of
WithContext.

The new WithContext now takes the pointer and store it in the context if
none is stored already or if the last one stored is a different pointer.
This way it is still possible to update the context of a logger stored
in the context, but it is also possible to store a copy of the logger in
a sub-context.

Fix #80

README.md

@@ -243,7 +243,7 @@ logger.Info().Str("foo", "bar").Msg("hello world")
 
 ```go
 sublogger := log.With().
-                 Str("component": "foo").
+                 Str("component", "foo").
                  Logger()
 sublogger.Info().Msg("hello world")
 
@@ -293,15 +293,24 @@ log.Info().Msg("hello world")
 log.Logger = log.With().Str("foo", "bar").Logger()
 ```
 
+### Add file and line number to log
+
+```go
+log.Logger = log.With().Caller().Logger()
+log.Info().Msg("hello world")
+
+// Output: {"level": "info", "message": "hello world", "caller": "/go/src/your_project/some_file:21"}
+```
+
+
 ### Thread-safe, lock-free, non-blocking writer
 
 If your writer might be slow or not thread-safe and you need your log producers to never get slowed down by a slow writer, you can use a `diode.Writer` as follow:
 
 ```go
-d := diodes.NewManyToOne(1000, diodes.AlertFunc(func(missed int) {
-    fmt.Printf("Dropped %d messages\n", missed)
-}))
-w := diode.NewWriter(os.Stdout, d, 10*time.Millisecond)
+wr := diode.NewWriter(os.Stdout, 1000, 10*time.Millisecond, func(missed int) {
+		fmt.Printf("Logger Dropped %d messages", missed)
+	})
 log := zerolog.New(w)
 log.Print("test")
 ```

array.go

@@ -71,9 +71,24 @@ func (a *Array) Hex(val []byte) *Array {
 	return a
 }
 
-// Err append append the err as a string to the array.
+// Err serializes and appends the err to the array.
 func (a *Array) Err(err error) *Array {
-	a.buf = enc.AppendError(enc.AppendArrayDelim(a.buf), err)
+	marshaled := ErrorMarshalFunc(err)
+	switch m := marshaled.(type) {
+	case LogObjectMarshaler:
+		e := newEvent(nil, 0)
+		e.buf = e.buf[:0]
+		e.appendObject(m)
+		a.buf = append(enc.AppendArrayDelim(a.buf), e.buf...)
+		eventPool.Put(e)
+	case error:
+		a.buf = enc.AppendString(enc.AppendArrayDelim(a.buf), m.Error())
+	case string:
+		a.buf = enc.AppendString(enc.AppendArrayDelim(a.buf), m)
+	default:
+		a.buf = enc.AppendInterface(enc.AppendArrayDelim(a.buf), m)
+	}
+
 	return a
 }
 

context.go

@@ -101,27 +101,47 @@ func (c Context) RawJSON(key string, b []byte) Context {
 	return c
 }
 
-// AnErr adds the field key with err as a string to the logger context.
+// AnErr adds the field key with serialized err to the logger context.
 func (c Context) AnErr(key string, err error) Context {
-	if err != nil {
-		c.l.context = enc.AppendError(enc.AppendKey(c.l.context, key), err)
+	marshaled := ErrorMarshalFunc(err)
+	switch m := marshaled.(type) {
+	case nil:
+		return c
+	case LogObjectMarshaler:
+		return c.Object(key,m)
+	case error:
+		return c.Str(key, m.Error())
+	case string:
+		return c.Str(key, m)
+	default:
+		return c.Interface(key, m)
 	}
-	return c
 }
 
-// Errs adds the field key with errs as an array of strings to the logger context.
+// Errs adds the field key with errs as an array of serialized errors to the
+// logger context.
 func (c Context) Errs(key string, errs []error) Context {
-	c.l.context = enc.AppendErrors(enc.AppendKey(c.l.context, key), errs)
-	return c
+	arr := Arr()
+	for _, err := range errs {
+		marshaled := ErrorMarshalFunc(err)
+		switch m := marshaled.(type) {
+		case LogObjectMarshaler:
+			arr = arr.Object(m)
+		case error:
+			arr = arr.Str(m.Error())
+		case string:
+			arr = arr.Str(m)
+		default:
+			arr = arr.Interface(m)
+		}
+	}
+
+	return c.Array(key, arr)
 }
 
-// Err adds the field "error" with err as a string to the logger context.
-// To customize the key name, change zerolog.ErrorFieldName.
+// Err adds the field "error" with serialized err to the logger context.
 func (c Context) Err(err error) Context {
-	if err != nil {
-		c.l.context = enc.AppendError(enc.AppendKey(c.l.context, ErrorFieldName), err)
-	}
-	return c
+	return c.AnErr(ErrorFieldName, err)
 }
 
 // Bool adds the field key with val as a bool to the logger context.

ctx.go

@@ -2,38 +2,39 @@ package zerolog
 
 import (
 	"context"
-	"io/ioutil"
 )
 
 var disabledLogger *Logger
 
 func init() {
-	l := New(ioutil.Discard).Level(Disabled)
+	l := Nop()
 	disabledLogger = &l
 }
 
 type ctxKey struct{}
 
 // WithContext returns a copy of ctx with l associated. If an instance of Logger
-// is already in the context, the pointer to this logger is updated with l.
+// is already in the context, the context is not updated.
 //
 // For instance, to add a field to an existing logger in the context, use this
 // notation:
 //
 //     ctx := r.Context()
 //     l := zerolog.Ctx(ctx)
-//     ctx = l.With().Str("foo", "bar").WithContext(ctx)
-func (l Logger) WithContext(ctx context.Context) context.Context {
+//     l.UpdateContext(func(c Context) Context {
+//         return c.Str("bar", "baz")
+//     })
+func (l *Logger) WithContext(ctx context.Context) context.Context {
 	if lp, ok := ctx.Value(ctxKey{}).(*Logger); ok {
-		// Update existing pointer.
-		*lp = l
-		return ctx
-	}
-	if l.level == Disabled {
+		if lp == l {
+			// Do not store same logger.
+			return ctx
+		}
+	} else if l.level == Disabled {
 		// Do not store disabled logger.
 		return ctx
 	}
-	return context.WithValue(ctx, ctxKey{}, &l)
+	return context.WithValue(ctx, ctxKey{}, l)
 }
 
 // Ctx returns the Logger associated with the ctx. If no logger

ctx_test.go

@@ -30,18 +30,34 @@ func TestCtx(t *testing.T) {
 }
 
 func TestCtxDisabled(t *testing.T) {
-	ctx := disabledLogger.WithContext(context.Background())
+	dl := New(ioutil.Discard).Level(Disabled)
+	ctx := dl.WithContext(context.Background())
 	if ctx != context.Background() {
 		t.Error("WithContext stored a disabled logger")
 	}
 
-	ctx = New(ioutil.Discard).WithContext(ctx)
-	if reflect.DeepEqual(Ctx(ctx), disabledLogger) {
+	l := New(ioutil.Discard).With().Str("foo", "bar").Logger()
+	ctx = l.WithContext(ctx)
+	if Ctx(ctx) != &l {
 		t.Error("WithContext did not store logger")
 	}
 
-	ctx = disabledLogger.WithContext(ctx)
-	if !reflect.DeepEqual(Ctx(ctx), disabledLogger) {
-		t.Error("WithContext did not update logger pointer with disabled logger")
+	l.UpdateContext(func(c Context) Context {
+		return c.Str("bar", "baz")
+	})
+	ctx = l.WithContext(ctx)
+	if Ctx(ctx) != &l {
+		t.Error("WithContext did not store updated logger")
+	}
+
+	l = l.Level(DebugLevel)
+	ctx = l.WithContext(ctx)
+	if Ctx(ctx) != &l {
+		t.Error("WithContext did not store copied logger")
+	}
+
+	ctx = dl.WithContext(ctx)
+	if Ctx(ctx) != &dl {
+		t.Error("WithContext did not overide logger with a disabled logger")
 	}
 }

diode/diode.go

@@ -35,10 +35,11 @@ type Writer struct {
 //
 // Use a diode.Writer when
 //
-//     w := diode.NewWriter(w, 1000, 10 * time.Millisecond, func(missed int) {
+//     wr := diode.NewWriter(w, 1000, 10 * time.Millisecond, func(missed int) {
 //         log.Printf("Dropped %d messages", missed)
 //     })
-//     log := zerolog.New(w)
+//     log := zerolog.New(wr)
+//
 //
 // See code.cloudfoundry.org/go-diodes for more info on diode.
 func NewWriter(w io.Writer, size int, poolInterval time.Duration, f Alerter) Writer {

encoder.go

@@ -16,8 +16,6 @@ type encoder interface {
 	AppendDuration(dst []byte, d time.Duration, unit time.Duration, useInt bool) []byte
 	AppendDurations(dst []byte, vals []time.Duration, unit time.Duration, useInt bool) []byte
 	AppendEndMarker(dst []byte) []byte
-	AppendError(dst []byte, err error) []byte
-	AppendErrors(dst []byte, errs []error) []byte
 	AppendFloat32(dst []byte, val float32) []byte
 	AppendFloat64(dst []byte, val float64) []byte
 	AppendFloats32(dst []byte, vals []float32) []byte

event.go

@@ -18,6 +18,11 @@ var eventPool = &sync.Pool{
 	},
 }
 
+// ErrorMarshalFunc allows customization of global error marshaling
+var ErrorMarshalFunc = func (err error) interface{} {
+	return err
+}
+
 // Event represents a log event. It is instanced by one of the level method of
 // Logger and finalized by the Msg or Msgf method.
 type Event struct {
@@ -239,39 +244,53 @@ func (e *Event) RawJSON(key string, b []byte) *Event {
 	return e
 }
 
-// AnErr adds the field key with err as a string to the *Event context.
+// AnErr adds the field key with serialized err to the *Event context.
 // If err is nil, no field is added.
 func (e *Event) AnErr(key string, err error) *Event {
-	if e == nil {
+	marshaled := ErrorMarshalFunc(err)
+	switch m := marshaled.(type) {
+	case nil:
 		return e
+	case LogObjectMarshaler:
+		return e.Object(key, m)
+	case error:
+		return e.Str(key, m.Error())
+	case string:
+		return e.Str(key, m)
+	default:
+		return e.Interface(key, m)
 	}
-	if err != nil {
-		e.buf = enc.AppendError(enc.AppendKey(e.buf, key), err)
-	}
-	return e
 }
-
-// Errs adds the field key with errs as an array of strings to the *Event context.
-// If err is nil, no field is added.
+// Errs adds the field key with errs as an array of serialized errors to the
+// *Event context.
 func (e *Event) Errs(key string, errs []error) *Event {
 	if e == nil {
 		return e
 	}
-	e.buf = enc.AppendErrors(enc.AppendKey(e.buf, key), errs)
-	return e
+
+	arr := Arr()
+	for _, err := range errs {
+		marshaled := ErrorMarshalFunc(err)
+		switch m := marshaled.(type) {
+		case LogObjectMarshaler:
+			arr = arr.Object(m)
+		case error:
+			arr = arr.Err(m)
+		case string:
+			arr = arr.Str(m)
+		default:
+			arr = arr.Interface(m)
+		}
+	}
+
+	return e.Array(key, arr)
 }
 
-// Err adds the field "error" with err as a string to the *Event context.
+// Err adds the field "error" with serialized err to the *Event context.
 // If err is nil, no field is added.
 // To customize the key name, change zerolog.ErrorFieldName.
 func (e *Event) Err(err error) *Event {
-	if e == nil {
-		return e
-	}
-	if err != nil {
-		e.buf = enc.AppendError(enc.AppendKey(e.buf, ErrorFieldName), err)
-	}
-	return e
+	return e.AnErr(ErrorFieldName, err)
 }
 
 // Bool adds the field key with val as a bool to the *Event context.

fields.go

@@ -29,9 +29,45 @@ func appendFields(dst []byte, fields map[string]interface{}) []byte {
 		case []byte:
 			dst = enc.AppendBytes(dst, val)
 		case error:
-			dst = enc.AppendError(dst, val)
+			marshaled := ErrorMarshalFunc(val)
+			switch m := marshaled.(type) {
+			case LogObjectMarshaler:
+				e := newEvent(nil, 0)
+				e.buf = e.buf[:0]
+				e.appendObject(m)
+				dst = append(dst, e.buf...)
+				eventPool.Put(e)
+			case error:
+				dst = enc.AppendString(dst, m.Error())
+			case string:
+				dst = enc.AppendString(dst, m)
+			default:
+				dst = enc.AppendInterface(dst, m)
+			}
 		case []error:
-			dst = enc.AppendErrors(dst, val)
+			dst = enc.AppendArrayStart(dst)
+			for i, err := range val {
+				marshaled := ErrorMarshalFunc(err)
+				switch m := marshaled.(type) {
+				case LogObjectMarshaler:
+					e := newEvent(nil, 0)
+					e.buf = e.buf[:0]
+					e.appendObject(m)
+					dst = append(dst, e.buf...)
+					eventPool.Put(e)
+				case error:
+					dst = enc.AppendString(dst, m.Error())
+				case string:
+					dst = enc.AppendString(dst, m)
+				default:
+					dst = enc.AppendInterface(dst, m)
+				}
+
+				if i < (len(val) - 1) {
+					enc.AppendArrayDelim(dst)
+				}
+			}
+			dst = enc.AppendArrayEnd(dst)
 		case bool:
 			dst = enc.AppendBool(dst, val)
 		case int:

internal/cbor/base.go

@@ -8,38 +8,4 @@ func (e Encoder) AppendKey(dst []byte, key string) []byte {
 		dst = e.AppendBeginMarker(dst)
 	}
 	return e.AppendString(dst, key)
-}
-
-// AppendError adds the Error to the log message if error is NOT nil
-func (e Encoder) AppendError(dst []byte, err error) []byte {
-	if err == nil {
-		return append(dst, `null`...)
-	}
-	return e.AppendString(dst, err.Error())
-}
-
-// AppendErrors when given an array of errors,
-// adds them to the log message if a specific error is nil, then
-// Nil is added, or else the error string is added.
-func (e Encoder) AppendErrors(dst []byte, errs []error) []byte {
-	if len(errs) == 0 {
-		return e.AppendArrayEnd(e.AppendArrayStart(dst))
-	}
-	dst = e.AppendArrayStart(dst)
-	if errs[0] != nil {
-		dst = e.AppendString(dst, errs[0].Error())
-	} else {
-		dst = e.AppendNil(dst)
-	}
-	if len(errs) > 1 {
-		for _, err := range errs[1:] {
-			if err == nil {
-				dst = e.AppendNil(dst)
-				continue
-			}
-			dst = e.AppendString(dst, err.Error())
-		}
-	}
-	dst = e.AppendArrayEnd(dst)
-	return dst
-}
+}

internal/json/base.go

@@ -9,38 +9,4 @@ func (e Encoder) AppendKey(dst []byte, key string) []byte {
 	}
 	dst = e.AppendString(dst, key)
 	return append(dst, ':')
-}
-
-// AppendError encodes the error string to json and appends
-// the encoded string to the input byte slice.
-func (e Encoder) AppendError(dst []byte, err error) []byte {
-	if err == nil {
-		return append(dst, `null`...)
-	}
-	return e.AppendString(dst, err.Error())
-}
-
-// AppendErrors encodes the error strings to json and
-// appends the encoded string list to the input byte slice.
-func (e Encoder) AppendErrors(dst []byte, errs []error) []byte {
-	if len(errs) == 0 {
-		return append(dst, '[', ']')
-	}
-	dst = append(dst, '[')
-	if errs[0] != nil {
-		dst = e.AppendString(dst, errs[0].Error())
-	} else {
-		dst = append(dst, "null"...)
-	}
-	if len(errs) > 1 {
-		for _, err := range errs[1:] {
-			if err == nil {
-				dst = append(dst, ",null"...)
-				continue
-			}
-			dst = e.AppendString(append(dst, ','), err.Error())
-		}
-	}
-	dst = append(dst, ']')
-	return dst
-}
+}

log_test.go

@@ -521,3 +521,61 @@ func TestOutputWithTimestamp(t *testing.T) {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
 }
+
+type loggableError struct {
+	error
+}
+
+func (l loggableError) MarshalZerologObject(e *Event) {
+	e.Str("message", l.error.Error() + ": loggableError")
+}
+
+func TestErrorMarshalFunc(t *testing.T) {
+	out := &bytes.Buffer{}
+	log := New(out)
+
+	// test default behaviour
+	log.Log().Err(errors.New("err")).Msg("msg")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"error":"err","message":"msg"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	log.Log().Err(loggableError{errors.New("err")}).Msg("msg")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"error":{"message":"err: loggableError"},"message":"msg"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	// test overriding the ErrorMarshalFunc
+	originalErrorMarshalFunc := ErrorMarshalFunc
+	defer func(){
+		ErrorMarshalFunc = originalErrorMarshalFunc
+	}()
+
+	ErrorMarshalFunc = func(err error) interface{} {
+		return err.Error() + ": marshaled string"
+	}
+	log.Log().Err(errors.New("err")).Msg("msg")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"error":"err: marshaled string","message":"msg"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+
+	out.Reset()
+	ErrorMarshalFunc = func(err error) interface{} {
+		return errors.New(err.Error() + ": new error")
+	}
+	log.Log().Err(errors.New("err")).Msg("msg")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"error":"err: new error","message":"msg"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+
+	out.Reset()
+	ErrorMarshalFunc = func(err error) interface{} {
+		return loggableError{err}
+	}
+	log.Log().Err(errors.New("err")).Msg("msg")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"error":{"message":"err: loggableError"},"message":"msg"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+}