Fix usage of sync.Pool

The current usage of sync.Pool is leaky because it stores an arbitrary
sized buffer into the pool. However, sync.Pool assumes that all items in the
pool are interchangeable from a memory cost perspective. Due to the unbounded
size of a buffer that may be added, it is possible for the pool to eventually
pin arbitrarily large amounts of memory in a live-lock situation.

As a simple fix, we just set a maximum size that we permit back into the pool.

CNAME

@@ -0,0 +1 @@
+zerolog.io

README.md

@@ -60,7 +60,7 @@ func main() {
 
 // Output: {"time":1516134303,"level":"debug","message":"hello world"}
 ```
-
+> Note: By default log writes to `os.Stderr`  
 > Note: The default log level for `log.Print` is *debug*
 
 ### Contextual Logging
@@ -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")
 ```
@@ -355,7 +364,7 @@ hooked.Warn().Msg("")
 ### Pass a sub-logger by context
 
 ```go
-ctx := log.With("component", "module").Logger().WithContext(ctx)
+ctx := log.With().Str("component", "module").Logger().WithContext(ctx)
 
 log.Ctx(ctx).Info().Msg("hello world")
 
@@ -435,7 +444,7 @@ if err := http.ListenAndServe(":8080", nil); err != nil {
 Some settings can be changed and will by applied to all loggers:
 
 * `log.Logger`: You can set this value to customize the global logger (the one used by package level methods).
-* `zerolog.SetGlobalLevel`: Can raise the minimum level of all loggers. Set this to `zerolog.Disable` to disable logging altogether (quiet mode).
+* `zerolog.SetGlobalLevel`: Can raise the minimum level of all loggers. Set this to `zerolog.Disabled` to disable logging altogether (quiet mode).
 * `zerolog.DisableSampling`: If argument is `true`, all sampled loggers will stop sampling and issue 100% of their log events.
 * `zerolog.TimestampFieldName`: Can be set to customize `Timestamp` field name.
 * `zerolog.LevelFieldName`: Can be set to customize level field name.
@@ -483,6 +492,8 @@ with zerolog library is [CSD](https://github.com/toravir/csd/).
 
 ## Benchmarks
 
+See [logbench](http://hackemist.com/logbench/) for more comprehensive and up-to-date benchmarks.
+
 All operations are allocation free (those numbers *include* JSON encoding):
 
 ```text

_config.yml

@@ -0,0 +1 @@
+remote_theme: rs/gh-readme

array.go

@@ -20,6 +20,20 @@ type Array struct {
 	buf []byte
 }
 
+func putArray(a *Array) {
+	// Proper usage of a sync.Pool requires each entry to have approximately
+	// the same memory cost. To obtain this property when the stored type
+	// contains a variably-sized buffer, we add a hard limit on the maximum buffer
+	// to place back in the pool.
+	//
+	// See https://golang.org/issue/23199
+	const maxSize = 1 << 16 // 64KiB
+	if cap(a.buf) > maxSize {
+		return
+	}
+	arrayPool.Put(a)
+}
+
 // Arr creates an array to be added to an Event or Context.
 func Arr() *Array {
 	a := arrayPool.Get().(*Array)
@@ -38,7 +52,7 @@ func (a *Array) write(dst []byte) []byte {
 		dst = append(append(dst, a.buf...))
 	}
 	dst = enc.AppendArrayEnd(dst)
-	arrayPool.Put(a)
+	putArray(a)
 	return dst
 }
 
@@ -49,7 +63,7 @@ func (a *Array) Object(obj LogObjectMarshaler) *Array {
 	obj.MarshalZerologObject(e)
 	e.buf = enc.AppendEndMarker(e.buf)
 	a.buf = append(enc.AppendArrayDelim(a.buf), e.buf...)
-	eventPool.Put(e)
+	putEvent(e)
 	return a
 }
 
@@ -71,9 +85,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...)
+		putEvent(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
 }
 

binary_test.go

@@ -6,6 +6,7 @@ import (
 	"bytes"
 	"errors"
 	"fmt"
+
 	//	"io/ioutil"
 	stdlog "log"
 	"time"
@@ -54,8 +55,8 @@ func ExampleLogger_Sample() {
 	log.Info().Msg("message 4")
 
 	fmt.Println(decodeIfBinaryToString(dst.Bytes()))
-	// Output: {"level":"info","message":"message 2"}
-	// {"level":"info","message":"message 4"}
+	// Output: {"level":"info","message":"message 1"}
+	// {"level":"info","message":"message 3"}
 }
 
 type LevelNameHook1 struct{}

cmd/lint/lint.go

@@ -0,0 +1,175 @@
+package main
+
+import (
+	"flag"
+	"fmt"
+	"go/ast"
+	"go/token"
+	"go/types"
+	"os"
+	"path/filepath"
+	"strings"
+
+	"golang.org/x/tools/go/loader"
+)
+
+var (
+	recursivelyIgnoredPkgs arrayFlag
+	ignoredPkgs            arrayFlag
+	ignoredFiles           arrayFlag
+	allowedFinishers       arrayFlag = []string{"Msg", "Msgf"}
+	rootPkg                string
+)
+
+// parse input flags and args
+func init() {
+	flag.Var(&recursivelyIgnoredPkgs, "ignorePkgRecursively", "ignore the specified package and all subpackages recursively")
+	flag.Var(&ignoredPkgs, "ignorePkg", "ignore the specified package")
+	flag.Var(&ignoredFiles, "ignoreFile", "ignore the specified file by its path and/or go path (package/file.go)")
+	flag.Var(&allowedFinishers, "finisher", "allowed finisher for the event chain")
+	flag.Parse()
+
+	// add zerolog to recursively ignored packages
+	recursivelyIgnoredPkgs = append(recursivelyIgnoredPkgs, "github.com/rs/zerolog")
+	args := flag.Args()
+	if len(args) != 1 {
+		fmt.Fprintln(os.Stderr, "you must provide exactly one package path")
+		os.Exit(1)
+	}
+	rootPkg = args[0]
+}
+
+func main() {
+	// load the package and all its dependencies
+	conf := loader.Config{}
+	conf.Import(rootPkg)
+	p, err := conf.Load()
+	if err != nil {
+		fmt.Fprintf(os.Stderr, "Error: unable to load the root package. %s\n", err.Error())
+		os.Exit(1)
+	}
+
+	// get the github.com/rs/zerolog.Event type
+	event := getEvent(p)
+	if event == nil {
+		fmt.Fprintln(os.Stderr, "Error: github.com/rs/zerolog.Event declaration not found, maybe zerolog is not imported in the scanned package?")
+		os.Exit(1)
+	}
+
+	// get all selections (function calls) with the github.com/rs/zerolog.Event (or pointer) receiver
+	selections := getSelectionsWithReceiverType(p, event)
+
+	// print the violations (if any)
+	hasViolations := false
+	for _, s := range selections {
+		if hasBadFinisher(p, s) {
+			hasViolations = true
+			fmt.Printf("Error: missing or bad finisher for log chain, last call: %q at: %s:%v\n", s.fn.Name(), p.Fset.File(s.Pos()).Name(), p.Fset.Position(s.Pos()).Line)
+		}
+	}
+
+	// if no violations detected, return normally
+	if !hasViolations {
+		fmt.Println("No violations found")
+		return
+	}
+
+	// if violations were detected, return error code
+	os.Exit(1)
+}
+
+func getEvent(p *loader.Program) types.Type {
+	for _, pkg := range p.AllPackages {
+		if strings.HasSuffix(pkg.Pkg.Path(), "github.com/rs/zerolog") {
+			for _, d := range pkg.Defs {
+				if d != nil && d.Name() == "Event" {
+					return d.Type()
+				}
+			}
+		}
+	}
+
+	return nil
+}
+
+func getSelectionsWithReceiverType(p *loader.Program, targetType types.Type) map[token.Pos]selection {
+	selections := map[token.Pos]selection{}
+
+	for _, z := range p.AllPackages {
+		for i, t := range z.Selections {
+			switch o := t.Obj().(type) {
+			case *types.Func:
+				// this is not a bug, o.Type() is always *types.Signature, see docs
+				if vt := o.Type().(*types.Signature).Recv(); vt != nil {
+					typ := vt.Type()
+					if pointer, ok := typ.(*types.Pointer); ok {
+						typ = pointer.Elem()
+					}
+
+					if typ == targetType {
+						if s, ok := selections[i.Pos()]; !ok || i.End() > s.End() {
+							selections[i.Pos()] = selection{i, o, z.Pkg}
+						}
+					}
+				}
+			default:
+				// skip
+			}
+		}
+	}
+
+	return selections
+}
+
+func hasBadFinisher(p *loader.Program, s selection) bool {
+	pkgPath := strings.TrimPrefix(s.pkg.Path(), rootPkg+"/vendor/")
+	absoluteFilePath := strings.TrimPrefix(p.Fset.File(s.Pos()).Name(), rootPkg+"/vendor/")
+	goFilePath := pkgPath + "/" + filepath.Base(p.Fset.Position(s.Pos()).Filename)
+
+	for _, f := range allowedFinishers {
+		if f == s.fn.Name() {
+			return false
+		}
+	}
+
+	for _, ignoredPkg := range recursivelyIgnoredPkgs {
+		if strings.HasPrefix(pkgPath, ignoredPkg) {
+			return false
+		}
+	}
+
+	for _, ignoredPkg := range ignoredPkgs {
+		if pkgPath == ignoredPkg {
+			return false
+		}
+	}
+
+	for _, ignoredFile := range ignoredFiles {
+		if absoluteFilePath == ignoredFile {
+			return false
+		}
+
+		if goFilePath == ignoredFile {
+			return false
+		}
+	}
+
+	return true
+}
+
+type arrayFlag []string
+
+func (i *arrayFlag) String() string {
+	return fmt.Sprintf("%v", []string(*i))
+}
+
+func (i *arrayFlag) Set(value string) error {
+	*i = append(*i, value)
+	return nil
+}
+
+type selection struct {
+	*ast.SelectorExpr
+	fn  *types.Func
+	pkg *types.Package
+}

cmd/lint/readme.md

@@ -0,0 +1,37 @@
+# Zerolog Lint
+
+This is a basic linter that checks for missing log event finishers. Finds errors like: `log.Error().Int64("userID": 5)` - missing the `Msg`/`Msgf` finishers.
+
+## Problem
+
+When using zerolog it's easy to forget to finish the log event chain by calling a finisher - the `Msg` or `Msgf` function that will schedule the event for writing. The problem with this is that it doesn't warn/panic during compilation and it's not easily found by grep or other general tools. It's even prominently mentioned in the project's readme, that:
+
+> It is very important to note that when using the **zerolog** chaining API, as shown above (`log.Info().Msg("hello world"`), the chain must have either the `Msg` or `Msgf` method call. If you forget to add either of these, the log will not occur and there is no compile time error to alert you of this.
+
+## Solution
+
+A basic linter like this one here that looks for method invocations on `zerolog.Event` can examine the last call in a method call chain and check if it is a finisher, thus pointing out these errors.
+
+## Usage
+
+Just compile this and then run it. Or just run it via `go run` command via something like `go run cmd/lint/lint.go`.
+
+The command accepts only one argument - the package to be inspected - and 4 optional flags, all of which can occur multiple times. The standard synopsis of the command is:
+
+`lint [-finisher value] [-ignoreFile value] [-ignorePkg value] [-ignorePkgRecursively value] package`
+
+#### Flags
+
+- finisher
+    - specify which finishers to accept, defaults to `Msg` and `Msgf`
+- ignoreFile
+    - which files to ignore, either by full path or by go path (package/file.go)
+- ignorePkg
+    - do not inspect the specified package if found in the dependecy tree
+- ignorePkgRecursively
+    - do not inspect the specified package or its subpackages if found in the dependency tree
+
+## Drawbacks
+
+As it is, linter can generate a false positives in a specific case. These false positives come from the fact that if you have a method that returns a `zerolog.Event` the linter will flag it because you are obviously not finishing the event. This will be solved in later release.
+

console.go

@@ -31,6 +31,10 @@ var consoleBufPool = sync.Pool{
 	},
 }
 
+// LevelWidth defines the desired character width of the log level column.
+// Default 0 does not trim or pad (variable width based level text, e.g. "INFO" or "ERROR")
+var LevelWidth = 0
+
 // ConsoleWriter reads a JSON object per write operation and output an
 // optionally colored human readable version on the Out writer.
 type ConsoleWriter struct {
@@ -55,7 +59,14 @@ func (w ConsoleWriter) Write(p []byte) (n int, err error) {
 		if !w.NoColor {
 			lvlColor = levelColor(l)
 		}
-		level = strings.ToUpper(l)[0:4]
+		level = strings.ToUpper(l)
+		if LevelWidth > 0 {
+			if padding := LevelWidth - len(level); padding > 0 {
+				level += strings.Repeat(" ", padding)
+			} else {
+				level = level[0:LevelWidth]
+			}
+		}
 	}
 	fmt.Fprintf(buf, "%s |%s| %s",
 		colorize(formatTime(event[TimestampFieldName]), cDarkGray, !w.NoColor),

context.go

@@ -26,7 +26,7 @@ func (c Context) Fields(fields map[string]interface{}) Context {
 func (c Context) Dict(key string, dict *Event) Context {
 	dict.buf = enc.AppendEndMarker(dict.buf)
 	c.l.context = append(enc.AppendKey(c.l.context, key), dict.buf...)
-	eventPool.Put(dict)
+	putEvent(dict)
 	return c
 }
 
@@ -55,7 +55,7 @@ func (c Context) Object(key string, obj LogObjectMarshaler) Context {
 	e := newEvent(levelWriterAdapter{ioutil.Discard}, 0)
 	e.Object(key, obj)
 	c.l.context = enc.AppendObjectData(c.l.context, e.buf)
-	eventPool.Put(e)
+	putEvent(e)
 	return c
 }
 
@@ -64,7 +64,7 @@ func (c Context) EmbedObject(obj LogObjectMarshaler) Context {
 	e := newEvent(levelWriterAdapter{ioutil.Discard}, 0)
 	e.EmbedObject(obj)
 	c.l.context = enc.AppendObjectData(c.l.context, e.buf)
-	eventPool.Put(e)
+	putEvent(e)
 	return c
 }
 
@@ -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.
@@ -330,8 +350,8 @@ func (c Context) Interface(key string, i interface{}) Context {
 type callerHook struct{}
 
 func (ch callerHook) Run(e *Event, level Level, msg string) {
-        //Two extra frames to skip (added by hook infra).
-	e.caller(CallerSkipFrameCount+2)
+	// Three extra frames to skip (added by hook infra).
+	e.caller(CallerSkipFrameCount + 3)
 }
 
 var ch = callerHook{}

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

@@ -8,7 +8,7 @@ import (
 	"sync"
 	"time"
 
-	diodes "code.cloudfoundry.org/go-diodes"
+	"github.com/rs/zerolog/diode/internal/diodes"
 )
 
 var bufPool = &sync.Pool{
@@ -17,6 +17,8 @@ var bufPool = &sync.Pool{
 	},
 }
 
+type Alerter func(missed int)
+
 // Writer is a io.Writer wrapper that uses a diode to make Write lock-free,
 // non-blocking and thread safe.
 type Writer struct {
@@ -33,19 +35,20 @@ type Writer struct {
 //
 // Use a diode.Writer when
 //
-//     d := diodes.NewManyToOne(1000, diodes.AlertFunc(func(missed int) {
+//     wr := diode.NewWriter(w, 1000, 10 * time.Millisecond, func(missed int) {
 //         log.Printf("Dropped %d messages", missed)
-//     }))
-//     w := diode.NewWriter(w, d, 10 * time.Millisecond)
-//     log := zerolog.New(w)
+//     })
+//     log := zerolog.New(wr)
+//
 //
 // See code.cloudfoundry.org/go-diodes for more info on diode.
-func NewWriter(w io.Writer, manyToOneDiode *diodes.ManyToOne, poolInterval time.Duration) Writer {
+func NewWriter(w io.Writer, size int, poolInterval time.Duration, f Alerter) Writer {
 	ctx, cancel := context.WithCancel(context.Background())
+	d := diodes.NewManyToOne(size, diodes.AlertFunc(f))
 	dw := Writer{
 		w: w,
-		d: manyToOneDiode,
-		p: diodes.NewPoller(manyToOneDiode,
+		d: d,
+		p: diodes.NewPoller(d,
 			diodes.WithPollingInterval(poolInterval),
 			diodes.WithPollingContext(ctx)),
 		c:    cancel,
@@ -83,6 +86,16 @@ func (dw Writer) poll() {
 		}
 		p := *(*[]byte)(d)
 		dw.w.Write(p)
-		bufPool.Put(p[:0])
+
+		// Proper usage of a sync.Pool requires each entry to have approximately
+		// the same memory cost. To obtain this property when the stored type
+		// contains a variably-sized buffer, we add a hard limit on the maximum buffer
+		// to place back in the pool.
+		//
+		// See https://golang.org/issue/23199
+		const maxSize = 1 << 16 // 64KiB
+		if cap(p) <= maxSize {
+			bufPool.Put(p[:0])
+		}
 	}
 }

diode/diode_example_test.go

@@ -7,16 +7,14 @@ import (
 	"os"
 	"time"
 
-	diodes "code.cloudfoundry.org/go-diodes"
 	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/diode"
 )
 
 func ExampleNewWriter() {
-	d := diodes.NewManyToOne(1000, diodes.AlertFunc(func(missed int) {
+	w := diode.NewWriter(os.Stdout, 1000, 10*time.Millisecond, func(missed int) {
 		fmt.Printf("Dropped %d messages\n", missed)
-	}))
-	w := diode.NewWriter(os.Stdout, d, 10*time.Millisecond)
+	})
 	log := zerolog.New(w)
 	log.Print("test")
 

diode/diode_test.go

@@ -9,18 +9,16 @@ import (
 	"testing"
 	"time"
 
-	diodes "code.cloudfoundry.org/go-diodes"
 	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/diode"
 	"github.com/rs/zerolog/internal/cbor"
 )
 
 func TestNewWriter(t *testing.T) {
-	d := diodes.NewManyToOne(1000, diodes.AlertFunc(func(missed int) {
-		fmt.Printf("Dropped %d messages\n", missed)
-	}))
 	buf := bytes.Buffer{}
-	w := diode.NewWriter(&buf, d, 10*time.Millisecond)
+	w := diode.NewWriter(&buf, 1000, 10*time.Millisecond, func(missed int) {
+		fmt.Printf("Dropped %d messages\n", missed)
+	})
 	log := zerolog.New(w)
 	log.Print("test")
 
@@ -35,8 +33,7 @@ func TestNewWriter(t *testing.T) {
 func Benchmark(b *testing.B) {
 	log.SetOutput(ioutil.Discard)
 	defer log.SetOutput(os.Stderr)
-	d := diodes.NewManyToOne(100000, nil)
-	w := diode.NewWriter(ioutil.Discard, d, 10*time.Millisecond)
+	w := diode.NewWriter(ioutil.Discard, 100000, 10*time.Millisecond, nil)
 	log := zerolog.New(w)
 	defer w.Close()
 

diode/internal/diodes/README

@@ -0,0 +1 @@
+Copied from https://github.com/cloudfoundry/go-diodes to avoid test dependencies.

diode/internal/diodes/many_to_one.go

@@ -0,0 +1,130 @@
+package diodes
+
+import (
+	"log"
+	"sync/atomic"
+	"unsafe"
+)
+
+// ManyToOne diode is optimal for many writers (go-routines B-n) and a single
+// reader (go-routine A). It is not thread safe for multiple readers.
+type ManyToOne struct {
+	buffer     []unsafe.Pointer
+	writeIndex uint64
+	readIndex  uint64
+	alerter    Alerter
+}
+
+// NewManyToOne creates a new diode (ring buffer). The ManyToOne diode
+// is optimzed for many writers (on go-routines B-n) and a single reader
+// (on go-routine A). The alerter is invoked on the read's go-routine. It is
+// called when it notices that the writer go-routine has passed it and wrote
+// over data. A nil can be used to ignore alerts.
+func NewManyToOne(size int, alerter Alerter) *ManyToOne {
+	if alerter == nil {
+		alerter = AlertFunc(func(int) {})
+	}
+
+	d := &ManyToOne{
+		buffer:  make([]unsafe.Pointer, size),
+		alerter: alerter,
+	}
+
+	// Start write index at the value before 0
+	// to allow the first write to use AddUint64
+	// and still have a beginning index of 0
+	d.writeIndex = ^d.writeIndex
+	return d
+}
+
+// Set sets the data in the next slot of the ring buffer.
+func (d *ManyToOne) Set(data GenericDataType) {
+	for {
+		writeIndex := atomic.AddUint64(&d.writeIndex, 1)
+		idx := writeIndex % uint64(len(d.buffer))
+		old := atomic.LoadPointer(&d.buffer[idx])
+
+		if old != nil &&
+			(*bucket)(old) != nil &&
+			(*bucket)(old).seq > writeIndex-uint64(len(d.buffer)) {
+			log.Println("Diode set collision: consider using a larger diode")
+			continue
+		}
+
+		newBucket := &bucket{
+			data: data,
+			seq:  writeIndex,
+		}
+
+		if !atomic.CompareAndSwapPointer(&d.buffer[idx], old, unsafe.Pointer(newBucket)) {
+			log.Println("Diode set collision: consider using a larger diode")
+			continue
+		}
+
+		return
+	}
+}
+
+// TryNext will attempt to read from the next slot of the ring buffer.
+// If there is not data available, it will return (nil, false).
+func (d *ManyToOne) TryNext() (data GenericDataType, ok bool) {
+	// Read a value from the ring buffer based on the readIndex.
+	idx := d.readIndex % uint64(len(d.buffer))
+	result := (*bucket)(atomic.SwapPointer(&d.buffer[idx], nil))
+
+	// When the result is nil that means the writer has not had the
+	// opportunity to write a value into the diode. This value must be ignored
+	// and the read head must not increment.
+	if result == nil {
+		return nil, false
+	}
+
+	// When the seq value is less than the current read index that means a
+	// value was read from idx that was previously written but has since has
+	// been dropped. This value must be ignored and the read head must not
+	// increment.
+	//
+	// The simulation for this scenario assumes the fast forward occurred as
+	// detailed below.
+	//
+	// 5. The reader reads again getting seq 5. It then reads again expecting
+	//    seq 6 but gets seq 2. This is a read of a stale value that was
+	//    effectively "dropped" so the read fails and the read head stays put.
+	//    `| 4 | 5 | 2 | 3 |` r: 7, w: 6
+	//
+	if result.seq < d.readIndex {
+		return nil, false
+	}
+
+	// When the seq value is greater than the current read index that means a
+	// value was read from idx that overwrote the value that was expected to
+	// be at this idx. This happens when the writer has lapped the reader. The
+	// reader needs to catch up to the writer so it moves its write head to
+	// the new seq, effectively dropping the messages that were not read in
+	// between the two values.
+	//
+	// Here is a simulation of this scenario:
+	//
+	// 1. Both the read and write heads start at 0.
+	//    `| nil | nil | nil | nil |` r: 0, w: 0
+	// 2. The writer fills the buffer.
+	//    `| 0 | 1 | 2 | 3 |` r: 0, w: 4
+	// 3. The writer laps the read head.
+	//    `| 4 | 5 | 2 | 3 |` r: 0, w: 6
+	// 4. The reader reads the first value, expecting a seq of 0 but reads 4,
+	//    this forces the reader to fast forward to 5.
+	//    `| 4 | 5 | 2 | 3 |` r: 5, w: 6
+	//
+	if result.seq > d.readIndex {
+		dropped := result.seq - d.readIndex
+		d.readIndex = result.seq
+		d.alerter.Alert(int(dropped))
+	}
+
+	// Only increment read index if a regular read occurred (where seq was
+	// equal to readIndex) or a value was read that caused a fast forward
+	// (where seq was greater than readIndex).
+	//
+	d.readIndex++
+	return result.data, true
+}

diode/internal/diodes/one_to_one.go

@@ -0,0 +1,129 @@
+package diodes
+
+import (
+	"sync/atomic"
+	"unsafe"
+)
+
+// GenericDataType is the data type the diodes operate on.
+type GenericDataType unsafe.Pointer
+
+// Alerter is used to report how many values were overwritten since the
+// last write.
+type Alerter interface {
+	Alert(missed int)
+}
+
+// AlertFunc type is an adapter to allow the use of ordinary functions as
+// Alert handlers.
+type AlertFunc func(missed int)
+
+// Alert calls f(missed)
+func (f AlertFunc) Alert(missed int) {
+	f(missed)
+}
+
+type bucket struct {
+	data GenericDataType
+	seq  uint64 // seq is the recorded write index at the time of writing
+}
+
+// OneToOne diode is meant to be used by a single reader and a single writer.
+// It is not thread safe if used otherwise.
+type OneToOne struct {
+	buffer     []unsafe.Pointer
+	writeIndex uint64
+	readIndex  uint64
+	alerter    Alerter
+}
+
+// NewOneToOne creates a new diode is meant to be used by a single reader and
+// a single writer. The alerter is invoked on the read's go-routine. It is
+// called when it notices that the writer go-routine has passed it and wrote
+// over data. A nil can be used to ignore alerts.
+func NewOneToOne(size int, alerter Alerter) *OneToOne {
+	if alerter == nil {
+		alerter = AlertFunc(func(int) {})
+	}
+
+	return &OneToOne{
+		buffer:  make([]unsafe.Pointer, size),
+		alerter: alerter,
+	}
+}
+
+// Set sets the data in the next slot of the ring buffer.
+func (d *OneToOne) Set(data GenericDataType) {
+	idx := d.writeIndex % uint64(len(d.buffer))
+
+	newBucket := &bucket{
+		data: data,
+		seq:  d.writeIndex,
+	}
+	d.writeIndex++
+
+	atomic.StorePointer(&d.buffer[idx], unsafe.Pointer(newBucket))
+}
+
+// TryNext will attempt to read from the next slot of the ring buffer.
+// If there is no data available, it will return (nil, false).
+func (d *OneToOne) TryNext() (data GenericDataType, ok bool) {
+	// Read a value from the ring buffer based on the readIndex.
+	idx := d.readIndex % uint64(len(d.buffer))
+	result := (*bucket)(atomic.SwapPointer(&d.buffer[idx], nil))
+
+	// When the result is nil that means the writer has not had the
+	// opportunity to write a value into the diode. This value must be ignored
+	// and the read head must not increment.
+	if result == nil {
+		return nil, false
+	}
+
+	// When the seq value is less than the current read index that means a
+	// value was read from idx that was previously written but has since has
+	// been dropped. This value must be ignored and the read head must not
+	// increment.
+	//
+	// The simulation for this scenario assumes the fast forward occurred as
+	// detailed below.
+	//
+	// 5. The reader reads again getting seq 5. It then reads again expecting
+	//    seq 6 but gets seq 2. This is a read of a stale value that was
+	//    effectively "dropped" so the read fails and the read head stays put.
+	//    `| 4 | 5 | 2 | 3 |` r: 7, w: 6
+	//
+	if result.seq < d.readIndex {
+		return nil, false
+	}
+
+	// When the seq value is greater than the current read index that means a
+	// value was read from idx that overwrote the value that was expected to
+	// be at this idx. This happens when the writer has lapped the reader. The
+	// reader needs to catch up to the writer so it moves its write head to
+	// the new seq, effectively dropping the messages that were not read in
+	// between the two values.
+	//
+	// Here is a simulation of this scenario:
+	//
+	// 1. Both the read and write heads start at 0.
+	//    `| nil | nil | nil | nil |` r: 0, w: 0
+	// 2. The writer fills the buffer.
+	//    `| 0 | 1 | 2 | 3 |` r: 0, w: 4
+	// 3. The writer laps the read head.
+	//    `| 4 | 5 | 2 | 3 |` r: 0, w: 6
+	// 4. The reader reads the first value, expecting a seq of 0 but reads 4,
+	//    this forces the reader to fast forward to 5.
+	//    `| 4 | 5 | 2 | 3 |` r: 5, w: 6
+	//
+	if result.seq > d.readIndex {
+		dropped := result.seq - d.readIndex
+		d.readIndex = result.seq
+		d.alerter.Alert(int(dropped))
+	}
+
+	// Only increment read index if a regular read occurred (where seq was
+	// equal to readIndex) or a value was read that caused a fast forward
+	// (where seq was greater than readIndex).
+	d.readIndex++
+	return result.data, true
+}

diode/internal/diodes/poller.go

@@ -0,0 +1,80 @@
+package diodes
+
+import (
+	"context"
+	"time"
+)
+
+// Diode is any implementation of a diode.
+type Diode interface {
+	Set(GenericDataType)
+	TryNext() (GenericDataType, bool)
+}
+
+// Poller will poll a diode until a value is available.
+type Poller struct {
+	Diode
+	interval time.Duration
+	ctx      context.Context
+}
+
+// PollerConfigOption can be used to setup the poller.
+type PollerConfigOption func(*Poller)
+
+// WithPollingInterval sets the interval at which the diode is queried
+// for new data. The default is 10ms.
+func WithPollingInterval(interval time.Duration) PollerConfigOption {
+	return PollerConfigOption(func(c *Poller) {
+		c.interval = interval
+	})
+}
+
+// WithPollingContext sets the context to cancel any retrieval (Next()). It
+// will not change any results for adding data (Set()). Default is
+// context.Background().
+func WithPollingContext(ctx context.Context) PollerConfigOption {
+	return PollerConfigOption(func(c *Poller) {
+		c.ctx = ctx
+	})
+}
+
+// NewPoller returns a new Poller that wraps the given diode.
+func NewPoller(d Diode, opts ...PollerConfigOption) *Poller {
+	p := &Poller{
+		Diode:    d,
+		interval: 10 * time.Millisecond,
+		ctx:      context.Background(),
+	}
+
+	for _, o := range opts {
+		o(p)
+	}
+
+	return p
+}
+
+// Next polls the diode until data is available or until the context is done.
+// If the context is done, then nil will be returned.
+func (p *Poller) Next() GenericDataType {
+	for {
+		data, ok := p.Diode.TryNext()
+		if !ok {
+			if p.isDone() {
+				return nil
+			}
+
+			time.Sleep(p.interval)
+			continue
+		}
+		return data
+	}
+}
+
+func (p *Poller) isDone() bool {
+	select {
+	case <-p.ctx.Done():
+		return true
+	default:
+		return false
+	}
+}

diode/internal/diodes/waiter.go

@@ -0,0 +1,83 @@
+package diodes
+
+import (
+	"context"
+	"sync"
+)
+
+// Waiter will use a conditional mutex to alert the reader to when data is
+// available.
+type Waiter struct {
+	Diode
+	mu  sync.Mutex
+	c   *sync.Cond
+	ctx context.Context
+}
+
+// WaiterConfigOption can be used to setup the waiter.
+type WaiterConfigOption func(*Waiter)
+
+// WithWaiterContext sets the context to cancel any retrieval (Next()). It
+// will not change any results for adding data (Set()). Default is
+// context.Background().
+func WithWaiterContext(ctx context.Context) WaiterConfigOption {
+	return WaiterConfigOption(func(c *Waiter) {
+		c.ctx = ctx
+	})
+}
+
+// NewWaiter returns a new Waiter that wraps the given diode.
+func NewWaiter(d Diode, opts ...WaiterConfigOption) *Waiter {
+	w := new(Waiter)
+	w.Diode = d
+	w.c = sync.NewCond(&w.mu)
+	w.ctx = context.Background()
+
+	for _, opt := range opts {
+		opt(w)
+	}
+
+	go func() {
+		<-w.ctx.Done()
+		w.c.Broadcast()
+	}()
+
+	return w
+}
+
+// Set invokes the wrapped diode's Set with the given data and uses Broadcast
+// to wake up any readers.
+func (w *Waiter) Set(data GenericDataType) {
+	w.Diode.Set(data)
+	w.c.Broadcast()
+}
+
+// Next returns the next data point on the wrapped diode. If there is not any
+// new data, it will Wait for set to be called or the context to be done.
+// If the context is done, then nil will be returned.
+func (w *Waiter) Next() GenericDataType {
+	w.mu.Lock()
+	defer w.mu.Unlock()
+
+	for {
+		data, ok := w.Diode.TryNext()
+		if !ok {
+			if w.isDone() {
+				return nil
+			}
+
+			w.c.Wait()
+			continue
+		}
+		return data
+	}
+}
+
+func (w *Waiter) isDone() bool {
+	select {
+	case <-w.ctx.Done():
+		return true
+	default:
+		return false
+	}
+}

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 {
@@ -26,7 +31,20 @@ type Event struct {
 	level Level
 	done  func(msg string)
 	ch    []Hook // hooks from context
-	h     []Hook
+}
+
+func putEvent(e *Event) {
+	// Proper usage of a sync.Pool requires each entry to have approximately
+	// the same memory cost. To obtain this property when the stored type
+	// contains a variably-sized buffer, we add a hard limit on the maximum buffer
+	// to place back in the pool.
+	//
+	// See https://golang.org/issue/23199
+	const maxSize = 1 << 16 // 64KiB
+	if cap(e.buf) > maxSize {
+		return
+	}
+	eventPool.Put(e)
 }
 
 // LogObjectMarshaler provides a strongly-typed and encoding-agnostic interface
@@ -44,7 +62,7 @@ type LogArrayMarshaler interface {
 func newEvent(w LevelWriter, level Level) *Event {
 	e := eventPool.Get().(*Event)
 	e.buf = e.buf[:0]
-	e.h = e.h[:0]
+	e.ch = nil
 	e.buf = enc.AppendBeginMarker(e.buf)
 	e.w = w
 	e.level = level
@@ -55,19 +73,27 @@ func (e *Event) write() (err error) {
 	if e == nil {
 		return nil
 	}
-	e.buf = enc.AppendEndMarker(e.buf)
-	e.buf = enc.AppendLineBreak(e.buf)
-	if e.w != nil {
-		_, err = e.w.WriteLevel(e.level, e.buf)
+	if e.level != Disabled {
+		e.buf = enc.AppendEndMarker(e.buf)
+		e.buf = enc.AppendLineBreak(e.buf)
+		if e.w != nil {
+			_, err = e.w.WriteLevel(e.level, e.buf)
+		}
 	}
-	eventPool.Put(e)
+	putEvent(e)
 	return
 }
 
 // Enabled return false if the *Event is going to be filtered out by
 // log level or sampling.
 func (e *Event) Enabled() bool {
-	return e != nil
+	return e != nil && e.level != Disabled
+}
+
+// Discard disables the event so Msg(f) won't print it.
+func (e *Event) Discard() *Event {
+	e.level = Disabled
+	return nil
 }
 
 // Msg sends the *Event with msg added as the message field if not empty.
@@ -78,6 +104,21 @@ func (e *Event) Msg(msg string) {
 	if e == nil {
 		return
 	}
+	e.msg(msg)
+}
+
+// Msgf sends the event with formated msg added as the message field if not empty.
+//
+// NOTICE: once this methid is called, the *Event should be disposed.
+// Calling Msg twice can have unexpected result.
+func (e *Event) Msgf(format string, v ...interface{}) {
+	if e == nil {
+		return
+	}
+	e.msg(fmt.Sprintf(format, v...))
+}
+
+func (e *Event) msg(msg string) {
 	if len(e.ch) > 0 {
 		e.ch[0].Run(e, e.level, msg)
 		if len(e.ch) > 1 {
@@ -86,14 +127,6 @@ func (e *Event) Msg(msg string) {
 			}
 		}
 	}
-	if len(e.h) > 0 {
-		e.h[0].Run(e, e.level, msg)
-		if len(e.h) > 1 {
-			for _, hook := range e.h[1:] {
-				hook.Run(e, e.level, msg)
-			}
-		}
-	}
 	if msg != "" {
 		e.buf = enc.AppendString(enc.AppendKey(e.buf, MessageFieldName), msg)
 	}
@@ -105,17 +138,6 @@ func (e *Event) Msg(msg string) {
 	}
 }
 
-// Msgf sends the event with formated msg added as the message field if not empty.
-//
-// NOTICE: once this methid is called, the *Event should be disposed.
-// Calling Msg twice can have unexpected result.
-func (e *Event) Msgf(format string, v ...interface{}) {
-	if e == nil {
-		return
-	}
-	e.Msg(fmt.Sprintf(format, v...))
-}
-
 // Fields is a helper function to use a map to set fields using type assertion.
 func (e *Event) Fields(fields map[string]interface{}) *Event {
 	if e == nil {
@@ -133,7 +155,7 @@ func (e *Event) Dict(key string, dict *Event) *Event {
 	}
 	dict.buf = enc.AppendEndMarker(dict.buf)
 	e.buf = append(enc.AppendKey(e.buf, key), dict.buf...)
-	eventPool.Put(dict)
+	putEvent(e)
 	return e
 }
 
@@ -239,39 +261,54 @@ 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

@@ -20,7 +20,7 @@ func appendFields(dst []byte, fields map[string]interface{}) []byte {
 			e.buf = e.buf[:0]
 			e.appendObject(val)
 			dst = append(dst, e.buf...)
-			eventPool.Put(e)
+			putEvent(e)
 			continue
 		}
 		switch val := val.(type) {
@@ -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...)
+				putEvent(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...)
+					putEvent(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:

hlog/hlog.go

@@ -129,7 +129,12 @@ func IDFromRequest(r *http.Request) (id xid.ID, ok bool) {
 	if r == nil {
 		return
 	}
-	id, ok = r.Context().Value(idKey{}).(xid.ID)
+	return IDFromCtx(r.Context())
+}
+
+// IDFromCtx returns the unique id associated to the context if any.
+func IDFromCtx(ctx context.Context) (id xid.ID, ok bool) {
+	id, ok = ctx.Value(idKey{}).(xid.ID)
 	return
 }
 

hook.go

@@ -6,6 +6,15 @@ type Hook interface {
 	Run(e *Event, level Level, message string)
 }
 
+// HookFunc is an adaptor to allow the use of an ordinary function
+// as a Hook.
+type HookFunc func(e *Event, level Level, message string)
+
+// Run implements the Hook interface.
+func (h HookFunc) Run(e *Event, level Level, message string) {
+	h(e, level, message)
+}
+
 // LevelHook applies a different hook for each level.
 type LevelHook struct {
 	NoLevelHook, DebugHook, InfoHook, WarnHook, ErrorHook, FatalHook, PanicHook Hook

hook_test.go

@@ -6,204 +6,135 @@ import (
 	"testing"
 )
 
-type LevelNameHook struct{}
-
-func (h LevelNameHook) Run(e *Event, level Level, msg string) {
-	levelName := level.String()
-	if level == NoLevel {
-		levelName = "nolevel"
-	}
-	e.Str("level_name", levelName)
-}
-
-type SimpleHook struct{}
-
-func (h SimpleHook) Run(e *Event, level Level, msg string) {
-	e.Bool("has_level", level != NoLevel)
-	e.Str("test", "logged")
-}
-
-type CopyHook struct{}
-
-func (h CopyHook) Run(e *Event, level Level, msg string) {
-	hasLevel := level != NoLevel
-	e.Bool("copy_has_level", hasLevel)
-	if hasLevel {
-		e.Str("copy_level", level.String())
-	}
-	e.Str("copy_msg", msg)
-}
-
-type NopHook struct{}
-
-func (h NopHook) Run(e *Event, level Level, msg string) {
-}
-
 var (
-	levelNameHook LevelNameHook
-	simpleHook    SimpleHook
-	copyHook      CopyHook
-	nopHook       NopHook
+	levelNameHook = HookFunc(func(e *Event, level Level, msg string) {
+		levelName := level.String()
+		if level == NoLevel {
+			levelName = "nolevel"
+		}
+		e.Str("level_name", levelName)
+	})
+	simpleHook = HookFunc(func(e *Event, level Level, msg string) {
+		e.Bool("has_level", level != NoLevel)
+		e.Str("test", "logged")
+	})
+	copyHook = HookFunc(func(e *Event, level Level, msg string) {
+		hasLevel := level != NoLevel
+		e.Bool("copy_has_level", hasLevel)
+		if hasLevel {
+			e.Str("copy_level", level.String())
+		}
+		e.Str("copy_msg", msg)
+	})
+	nopHook = HookFunc(func(e *Event, level Level, message string) {
+	})
+	discardHook = HookFunc(func(e *Event, level Level, message string) {
+		e.Discard()
+	})
 )
 
 func TestHook(t *testing.T) {
-	t.Run("Message", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(levelNameHook)
-		log.Log().Msg("test message")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level_name":"nolevel","message":"test message"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("NoLevel", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(levelNameHook)
-		log.Log().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level_name":"nolevel"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Print", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(levelNameHook)
-		log.Print("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"debug","level_name":"debug"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Error", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(levelNameHook)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","level_name":"error"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Copy/1", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(copyHook)
-		log.Log().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"copy_has_level":false,"copy_msg":""}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Copy/2", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(copyHook)
-		log.Info().Msg("a message")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"info","copy_has_level":true,"copy_level":"info","copy_msg":"a message","message":"a message"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Multi", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(levelNameHook).Hook(simpleHook)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","level_name":"error","has_level":true,"test":"logged"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Multi/Message", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(levelNameHook).Hook(simpleHook)
-		log.Error().Msg("a message")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","level_name":"error","has_level":true,"test":"logged","message":"a message"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Output/single/pre", func(t *testing.T) {
-		ignored := &bytes.Buffer{}
-		out := &bytes.Buffer{}
-		log := New(ignored).Hook(levelNameHook).Output(out)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","level_name":"error"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Output/single/post", func(t *testing.T) {
-		ignored := &bytes.Buffer{}
-		out := &bytes.Buffer{}
-		log := New(ignored).Output(out).Hook(levelNameHook)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","level_name":"error"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Output/multi/pre", func(t *testing.T) {
-		ignored := &bytes.Buffer{}
-		out := &bytes.Buffer{}
-		log := New(ignored).Hook(levelNameHook).Hook(simpleHook).Output(out)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","level_name":"error","has_level":true,"test":"logged"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Output/multi/post", func(t *testing.T) {
-		ignored := &bytes.Buffer{}
-		out := &bytes.Buffer{}
-		log := New(ignored).Output(out).Hook(levelNameHook).Hook(simpleHook)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","level_name":"error","has_level":true,"test":"logged"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("Output/mixed", func(t *testing.T) {
-		ignored := &bytes.Buffer{}
-		out := &bytes.Buffer{}
-		log := New(ignored).Hook(levelNameHook).Output(out).Hook(simpleHook)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","level_name":"error","has_level":true,"test":"logged"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("With/single/pre", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(levelNameHook).With().Str("with", "pre").Logger()
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","with":"pre","level_name":"error"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("With/single/post", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).With().Str("with", "post").Logger().Hook(levelNameHook)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","with":"post","level_name":"error"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("With/multi/pre", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(levelNameHook).Hook(simpleHook).With().Str("with", "pre").Logger()
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","with":"pre","level_name":"error","has_level":true,"test":"logged"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("With/multi/post", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).With().Str("with", "post").Logger().Hook(levelNameHook).Hook(simpleHook)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","with":"post","level_name":"error","has_level":true,"test":"logged"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("With/mixed", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out).Hook(levelNameHook).With().Str("with", "mixed").Logger().Hook(simpleHook)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error","with":"mixed","level_name":"error","has_level":true,"test":"logged"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
-	t.Run("None", func(t *testing.T) {
-		out := &bytes.Buffer{}
-		log := New(out)
-		log.Error().Msg("")
-		if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"error"}`+"\n"; got != want {
-			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
-		}
-	})
+	tests := []struct {
+		name string
+		want string
+		test func(log Logger)
+	}{
+		{"Message", `{"level_name":"nolevel","message":"test message"}` + "\n", func(log Logger) {
+			log = log.Hook(levelNameHook)
+			log.Log().Msg("test message")
+		}},
+		{"NoLevel", `{"level_name":"nolevel"}` + "\n", func(log Logger) {
+			log = log.Hook(levelNameHook)
+			log.Log().Msg("")
+		}},
+		{"Print", `{"level":"debug","level_name":"debug"}` + "\n", func(log Logger) {
+			log = log.Hook(levelNameHook)
+			log.Print("")
+		}},
+		{"Error", `{"level":"error","level_name":"error"}` + "\n", func(log Logger) {
+			log = log.Hook(levelNameHook)
+			log.Error().Msg("")
+		}},
+		{"Copy/1", `{"copy_has_level":false,"copy_msg":""}` + "\n", func(log Logger) {
+			log = log.Hook(copyHook)
+			log.Log().Msg("")
+		}},
+		{"Copy/2", `{"level":"info","copy_has_level":true,"copy_level":"info","copy_msg":"a message","message":"a message"}` + "\n", func(log Logger) {
+			log = log.Hook(copyHook)
+			log.Info().Msg("a message")
+		}},
+		{"Multi", `{"level":"error","level_name":"error","has_level":true,"test":"logged"}` + "\n", func(log Logger) {
+			log = log.Hook(levelNameHook).Hook(simpleHook)
+			log.Error().Msg("")
+		}},
+		{"Multi/Message", `{"level":"error","level_name":"error","has_level":true,"test":"logged","message":"a message"}` + "\n", func(log Logger) {
+			log = log.Hook(levelNameHook).Hook(simpleHook)
+			log.Error().Msg("a message")
+		}},
+		{"Output/single/pre", `{"level":"error","level_name":"error"}` + "\n", func(log Logger) {
+			ignored := &bytes.Buffer{}
+			log = New(ignored).Hook(levelNameHook).Output(log.w)
+			log.Error().Msg("")
+		}},
+		{"Output/single/post", `{"level":"error","level_name":"error"}` + "\n", func(log Logger) {
+			ignored := &bytes.Buffer{}
+			log = New(ignored).Output(log.w).Hook(levelNameHook)
+			log.Error().Msg("")
+		}},
+		{"Output/multi/pre", `{"level":"error","level_name":"error","has_level":true,"test":"logged"}` + "\n", func(log Logger) {
+			ignored := &bytes.Buffer{}
+			log = New(ignored).Hook(levelNameHook).Hook(simpleHook).Output(log.w)
+			log.Error().Msg("")
+		}},
+		{"Output/multi/post", `{"level":"error","level_name":"error","has_level":true,"test":"logged"}` + "\n", func(log Logger) {
+			ignored := &bytes.Buffer{}
+			log = New(ignored).Output(log.w).Hook(levelNameHook).Hook(simpleHook)
+			log.Error().Msg("")
+		}},
+		{"Output/mixed", `{"level":"error","level_name":"error","has_level":true,"test":"logged"}` + "\n", func(log Logger) {
+			ignored := &bytes.Buffer{}
+			log = New(ignored).Hook(levelNameHook).Output(log.w).Hook(simpleHook)
+			log.Error().Msg("")
+		}},
+		{"With/single/pre", `{"level":"error","with":"pre","level_name":"error"}` + "\n", func(log Logger) {
+			log = log.Hook(levelNameHook).With().Str("with", "pre").Logger()
+			log.Error().Msg("")
+		}},
+		{"With/single/post", `{"level":"error","with":"post","level_name":"error"}` + "\n", func(log Logger) {
+			log = log.With().Str("with", "post").Logger().Hook(levelNameHook)
+			log.Error().Msg("")
+		}},
+		{"With/multi/pre", `{"level":"error","with":"pre","level_name":"error","has_level":true,"test":"logged"}` + "\n", func(log Logger) {
+			log = log.Hook(levelNameHook).Hook(simpleHook).With().Str("with", "pre").Logger()
+			log.Error().Msg("")
+		}},
+		{"With/multi/post", `{"level":"error","with":"post","level_name":"error","has_level":true,"test":"logged"}` + "\n", func(log Logger) {
+			log = log.With().Str("with", "post").Logger().Hook(levelNameHook).Hook(simpleHook)
+			log.Error().Msg("")
+		}},
+		{"With/mixed", `{"level":"error","with":"mixed","level_name":"error","has_level":true,"test":"logged"}` + "\n", func(log Logger) {
+			log = log.Hook(levelNameHook).With().Str("with", "mixed").Logger().Hook(simpleHook)
+			log.Error().Msg("")
+		}},
+		{"Discard", "", func(log Logger) {
+			log = log.Hook(discardHook)
+			log.Log().Msg("test message")
+		}},
+		{"None", `{"level":"error"}` + "\n", func(log Logger) {
+			log.Error().Msg("")
+		}},
+	}
+	for _, tt := range tests {
+		tt := tt
+		t.Run(tt.name, func(t *testing.T) {
+			out := &bytes.Buffer{}
+			log := New(out)
+			tt.test(log)
+			if got, want := decodeIfBinaryToString(out.Bytes()), tt.want; got != want {
+				t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+			}
+		})
+	}
 }
 
 func BenchmarkHooks(b *testing.B) {

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_example_test.go

@@ -48,8 +48,8 @@ func ExampleLogger_Sample() {
 	log.Info().Msg("message 3")
 	log.Info().Msg("message 4")
 
-	// Output: {"level":"info","message":"message 2"}
-	// {"level":"info","message":"message 4"}
+	// Output: {"level":"info","message":"message 1"}
+	// {"level":"info","message":"message 3"}
 }
 
 type LevelNameHook struct{}

log_test.go

@@ -398,7 +398,7 @@ func TestSampling(t *testing.T) {
 	log.Log().Int("i", 2).Msg("")
 	log.Log().Int("i", 3).Msg("")
 	log.Log().Int("i", 4).Msg("")
-	if got, want := decodeIfBinaryToString(out.Bytes()), "{\"i\":2}\n{\"i\":4}\n"; got != want {
+	if got, want := decodeIfBinaryToString(out.Bytes()), "{\"i\":1}\n{\"i\":3}\n"; got != want {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
 }
@@ -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)
+	}
+}

sampler.go

@@ -47,7 +47,7 @@ type BasicSampler struct {
 // Sample implements the Sampler interface.
 func (s *BasicSampler) Sample(lvl Level) bool {
 	c := atomic.AddUint32(&s.counter, 1)
-	return c%s.N == 0
+	return c%s.N == s.N-1
 }
 
 // BurstSampler lets Burst events pass per Period then pass the decision to

sampler_test.go

@@ -15,7 +15,14 @@ var samplers = []struct {
 	wantMax int
 }{
 	{
-		"BasicSampler",
+		"BasicSampler_1",
+		func() Sampler {
+			return &BasicSampler{N: 1}
+		},
+		100, 100, 100,
+	},
+	{
+		"BasicSampler_5",
 		func() Sampler {
 			return &BasicSampler{N: 5}
 		},