pkgerrors: quick refactoring for better readibility

Alternative approach to #118: fix the race condition by replacing the package-level customization settings with curried functions.

.gitignore

@@ -6,6 +6,7 @@
 # Folders
 _obj
 _test
+tmp
 
 # Architecture specific extensions/prefixes
 *.[568vq]

CNAME

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

README.md

@@ -8,7 +8,7 @@ Zerolog's API is designed to provide both a great developer experience and stunn
 
 Uber's [zap](https://godoc.org/go.uber.org/zap) library pioneered this approach. Zerolog is taking this concept to the next level with a simpler to use API and even better performance.
 
-To keep the code base and the API simple, zerolog focuses on efficient structured logging only. Pretty logging on the console is made possible using the provided (but inefficient) `zerolog.ConsoleWriter`.
+To keep the code base and the API simple, zerolog focuses on efficient structured logging only. Pretty logging on the console is made possible using the provided (but inefficient) [`zerolog.ConsoleWriter`](#pretty-logging).
 
 ![Pretty Logging Image](pretty.png)
 
@@ -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
@@ -252,14 +252,38 @@ sublogger.Info().Msg("hello world")
 
 ### Pretty logging
 
+To log a human-friendly, colorized output, use `zerolog.ConsoleWriter`:
+
 ```go
-if isConsole {
-    log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr})
-}
+log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr})
 
 log.Info().Str("foo", "bar").Msg("Hello world")
 
-// Output: 1494567715 |INFO| Hello world foo=bar
+// Output: 3:04PM INF Hello World foo=bar
+```
+
+To customize the configuration and formatting:
+
+```go
+output := zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.RFC3339}
+output.FormatLevel = func(i interface{}) string {
+    return strings.ToUpper(fmt.Sprintf("| %-6s|", i))
+}
+output.FormatMessage = func(i interface{}) string {
+    return fmt.Sprintf("***%s****", i)
+}
+output.FormatFieldName = func(i interface{}) string {
+    return fmt.Sprintf("%s:", i)
+}
+output.FormatFieldValue = func(i interface{}) string {
+    return strings.ToUpper(fmt.Sprintf("%s", i))
+}
+
+log := zerolog.New(output).With().Timestamp().Logger()
+
+log.Info().Str("foo", "bar").Msg("Hello World")
+
+// Output: 2006-01-02T15:04:05Z07:00 | INFO  | ***Hello World**** foo:BAR
 ```
 
 ### Sub dictionary
@@ -364,7 +388,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")
 
@@ -444,7 +468,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.
@@ -455,6 +479,7 @@ Some settings can be changed and will by applied to all loggers:
     // using the Dur method.
 * `DurationFieldUnit`: Sets the unit of the fields added by `Dur` (default: `time.Millisecond`).
 * `DurationFieldInteger`: If set to true, `Dur` fields are formatted as integers instead of floats.
+* `ErrorHandler`: Called whenever zerolog fails to write an event on its output. If not set, an error is printed on the stderr. This handler must be thread safe and non-blocking.
 
 ## Field Types
 
@@ -492,6 +517,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
 }
 
@@ -80,7 +94,7 @@ func (a *Array) Err(err error) *Array {
 		e.buf = e.buf[:0]
 		e.appendObject(m)
 		a.buf = append(enc.AppendArrayDelim(a.buf), e.buf...)
-		eventPool.Put(e)
+		putEvent(e)
 	case error:
 		a.buf = enc.AppendString(enc.AppendArrayDelim(a.buf), m.Error())
 	case string:

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

@@ -5,6 +5,7 @@ import (
 	"encoding/json"
 	"fmt"
 	"io"
+	"os"
 	"sort"
 	"strconv"
 	"strings"
@@ -13,122 +14,246 @@ import (
 )
 
 const (
-	cReset    = 0
-	cBold     = 1
-	cRed      = 31
-	cGreen    = 32
-	cYellow   = 33
-	cBlue     = 34
-	cMagenta  = 35
-	cCyan     = 36
-	cGray     = 37
-	cDarkGray = 90
+	colorBold = iota + 1
+	colorFaint
 )
 
-var consoleBufPool = sync.Pool{
-	New: func() interface{} {
-		return bytes.NewBuffer(make([]byte, 0, 100))
-	},
-}
+const (
+	colorBlack = iota + 30
+	colorRed
+	colorGreen
+	colorYellow
+	colorBlue
+	colorMagenta
+	colorCyan
+	colorWhite
+)
 
-// ConsoleWriter reads a JSON object per write operation and output an
-// optionally colored human readable version on the Out writer.
+var (
+	consoleBufPool = sync.Pool{
+		New: func() interface{} {
+			return bytes.NewBuffer(make([]byte, 0, 100))
+		},
+	}
+)
+
+const (
+	consoleDefaultTimeFormat = time.Kitchen
+)
+
+// Formatter transforms the input into a formatted string.
+type Formatter func(interface{}) string
+
+// ConsoleWriter parses the JSON input and writes it in an
+// (optionally) colorized, human-friendly format to Out.
 type ConsoleWriter struct {
-	Out     io.Writer
+	// Out is the output destination.
+	Out io.Writer
+
+	// NoColor disables the colorized output.
 	NoColor bool
+
+	// TimeFormat specifies the format for timestamp in output.
+	TimeFormat string
+
+	// PartsOrder defines the order of parts in output.
+	PartsOrder []string
+
+	FormatTimestamp     Formatter
+	FormatLevel         Formatter
+	FormatCaller        Formatter
+	FormatMessage       Formatter
+	FormatFieldName     Formatter
+	FormatFieldValue    Formatter
+	FormatErrFieldName  Formatter
+	FormatErrFieldValue Formatter
 }
 
+// NewConsoleWriter creates and initializes a new ConsoleWriter.
+func NewConsoleWriter(options ...func(w *ConsoleWriter)) ConsoleWriter {
+	w := ConsoleWriter{
+		Out:        os.Stdout,
+		TimeFormat: consoleDefaultTimeFormat,
+		PartsOrder: consoleDefaultPartsOrder(),
+	}
+
+	for _, opt := range options {
+		opt(&w)
+	}
+
+	return w
+}
+
+// Write transforms the JSON input with formatters and appends to w.Out.
 func (w ConsoleWriter) Write(p []byte) (n int, err error) {
-	var event map[string]interface{}
+	if w.PartsOrder == nil {
+		w.PartsOrder = consoleDefaultPartsOrder()
+	}
+
+	var buf = consoleBufPool.Get().(*bytes.Buffer)
+	defer func() {
+		buf.Reset()
+		consoleBufPool.Put(buf)
+	}()
+
+	var evt map[string]interface{}
 	p = decodeIfBinaryToBytes(p)
 	d := json.NewDecoder(bytes.NewReader(p))
 	d.UseNumber()
-	err = d.Decode(&event)
+	err = d.Decode(&evt)
 	if err != nil {
-		return
+		return n, fmt.Errorf("cannot decode event: %s", err)
 	}
-	buf := consoleBufPool.Get().(*bytes.Buffer)
-	defer consoleBufPool.Put(buf)
-	lvlColor := cReset
-	level := "????"
-	if l, ok := event[LevelFieldName].(string); ok {
-		if !w.NoColor {
-			lvlColor = levelColor(l)
-		}
-		level = strings.ToUpper(l)[0:4]
+
+	for _, p := range w.PartsOrder {
+		w.writePart(buf, evt, p)
 	}
-	fmt.Fprintf(buf, "%s |%s| %s",
-		colorize(formatTime(event[TimestampFieldName]), cDarkGray, !w.NoColor),
-		colorize(level, lvlColor, !w.NoColor),
-		colorize(event[MessageFieldName], cReset, !w.NoColor))
-	fields := make([]string, 0, len(event))
-	for field := range event {
+
+	w.writeFields(evt, buf)
+
+	err = buf.WriteByte('\n')
+	if err != nil {
+		return n, err
+	}
+	_, err = buf.WriteTo(w.Out)
+	return len(p), err
+}
+
+// writeFields appends formatted key-value pairs to buf.
+func (w ConsoleWriter) writeFields(evt map[string]interface{}, buf *bytes.Buffer) {
+	var fields = make([]string, 0, len(evt))
+	for field := range evt {
 		switch field {
-		case LevelFieldName, TimestampFieldName, MessageFieldName:
+		case LevelFieldName, TimestampFieldName, MessageFieldName, CallerFieldName:
 			continue
 		}
 		fields = append(fields, field)
 	}
 	sort.Strings(fields)
-	for _, field := range fields {
-		fmt.Fprintf(buf, " %s=", colorize(field, cCyan, !w.NoColor))
-		switch value := event[field].(type) {
-		case string:
-			if needsQuote(value) {
-				buf.WriteString(strconv.Quote(value))
-			} else {
-				buf.WriteString(value)
+
+	if len(fields) > 0 {
+		buf.WriteByte(' ')
+	}
+
+	// Move the "error" field to the front
+	ei := sort.Search(len(fields), func(i int) bool { return fields[i] >= ErrorFieldName })
+	if ei < len(fields) && fields[ei] == ErrorFieldName {
+		fields[ei] = ""
+		fields = append([]string{ErrorFieldName}, fields...)
+		var xfields = make([]string, 0, len(fields))
+		for _, field := range fields {
+			if field == "" { // Skip empty fields
+				continue
 			}
-		case json.Number:
-			fmt.Fprint(buf, value)
-		default:
-			b, err := json.Marshal(value)
-			if err != nil {
-				fmt.Fprintf(buf, "[error: %v]", err)
+			xfields = append(xfields, field)
+		}
+		fields = xfields
+	}
+
+	for i, field := range fields {
+		var fn Formatter
+		var fv Formatter
+
+		if field == ErrorFieldName {
+			if w.FormatErrFieldName == nil {
+				fn = consoleDefaultFormatErrFieldName(w.NoColor)
 			} else {
-				fmt.Fprint(buf, string(b))
+				fn = w.FormatErrFieldName
+			}
+
+			if w.FormatErrFieldValue == nil {
+				fv = consoleDefaultFormatErrFieldValue(w.NoColor)
+			} else {
+				fv = w.FormatErrFieldValue
+			}
+		} else {
+			if w.FormatFieldName == nil {
+				fn = consoleDefaultFormatFieldName(w.NoColor)
+			} else {
+				fn = w.FormatFieldName
+			}
+
+			if w.FormatFieldValue == nil {
+				fv = consoleDefaultFormatFieldValue
+			} else {
+				fv = w.FormatFieldValue
 			}
 		}
+
+		buf.WriteString(fn(field))
+
+		switch fValue := evt[field].(type) {
+		case string:
+			if needsQuote(fValue) {
+				buf.WriteString(fv(strconv.Quote(fValue)))
+			} else {
+				buf.WriteString(fv(fValue))
+			}
+		case json.Number:
+			buf.WriteString(fv(fValue))
+		default:
+			b, err := json.Marshal(fValue)
+			if err != nil {
+				fmt.Fprintf(buf, colorize("[error: %v]", colorRed, w.NoColor), err)
+			} else {
+				fmt.Fprint(buf, fv(b))
+			}
+		}
+
+		if i < len(fields)-1 { // Skip space for last field
+			buf.WriteByte(' ')
+		}
 	}
-	buf.WriteByte('\n')
-	buf.WriteTo(w.Out)
-	n = len(p)
-	return
 }
 
-func formatTime(t interface{}) string {
-	switch t := t.(type) {
-	case string:
-		return t
-	case json.Number:
-		u, _ := t.Int64()
-		return time.Unix(u, 0).Format(time.RFC3339)
-	}
-	return "<nil>"
-}
+// writePart appends a formatted part to buf.
+func (w ConsoleWriter) writePart(buf *bytes.Buffer, evt map[string]interface{}, p string) {
+	var f Formatter
 
-func colorize(s interface{}, color int, enabled bool) string {
-	if !enabled {
-		return fmt.Sprintf("%v", s)
-	}
-	return fmt.Sprintf("\x1b[%dm%v\x1b[0m", color, s)
-}
-
-func levelColor(level string) int {
-	switch level {
-	case "debug":
-		return cMagenta
-	case "info":
-		return cGreen
-	case "warn":
-		return cYellow
-	case "error", "fatal", "panic":
-		return cRed
+	switch p {
+	case LevelFieldName:
+		if w.FormatLevel == nil {
+			f = consoleDefaultFormatLevel(w.NoColor)
+		} else {
+			f = w.FormatLevel
+		}
+	case TimestampFieldName:
+		if w.FormatTimestamp == nil {
+			f = consoleDefaultFormatTimestamp(w.TimeFormat, w.NoColor)
+		} else {
+			f = w.FormatTimestamp
+		}
+	case MessageFieldName:
+		if w.FormatMessage == nil {
+			f = consoleDefaultFormatMessage
+		} else {
+			f = w.FormatMessage
+		}
+	case CallerFieldName:
+		if w.FormatCaller == nil {
+			f = consoleDefaultFormatCaller(w.NoColor)
+		} else {
+			f = w.FormatCaller
+		}
 	default:
-		return cReset
+		if w.FormatFieldValue == nil {
+			f = consoleDefaultFormatFieldValue
+		} else {
+			f = w.FormatFieldValue
+		}
+	}
+
+	var s = f(evt[p])
+
+	if len(s) > 0 {
+		buf.WriteString(s)
+		if p != w.PartsOrder[len(w.PartsOrder)-1] { // Skip space for last part
+			buf.WriteByte(' ')
+		}
 	}
 }
 
+// needsQuote returns true when the string s should be quoted in output.
 func needsQuote(s string) bool {
 	for i := range s {
 		if s[i] < 0x20 || s[i] > 0x7e || s[i] == ' ' || s[i] == '\\' || s[i] == '"' {
@@ -137,3 +262,114 @@ func needsQuote(s string) bool {
 	}
 	return false
 }
+
+// colorize returns the string s wrapped in ANSI code c, unless disabled is true.
+func colorize(s interface{}, c int, disabled bool) string {
+	if disabled {
+		return fmt.Sprintf("%s", s)
+	}
+	return fmt.Sprintf("\x1b[%dm%v\x1b[0m", c, s)
+}
+
+// ----- DEFAULT FORMATTERS ---------------------------------------------------
+
+func consoleDefaultPartsOrder() []string {
+	return []string{
+		TimestampFieldName,
+		LevelFieldName,
+		CallerFieldName,
+		MessageFieldName,
+	}
+}
+
+func consoleDefaultFormatTimestamp(timeFormat string, noColor bool) Formatter {
+	if timeFormat == "" {
+		timeFormat = consoleDefaultTimeFormat
+	}
+	return func(i interface{}) string {
+		t := "<nil>"
+		switch tt := i.(type) {
+		case string:
+			ts, err := time.Parse(TimeFieldFormat, tt)
+			if err != nil {
+				t = tt
+			} else {
+				t = ts.Format(timeFormat)
+			}
+		case json.Number:
+			t = tt.String()
+		}
+		return colorize(t, colorFaint, noColor)
+	}
+}
+
+func consoleDefaultFormatLevel(noColor bool) Formatter {
+	return func(i interface{}) string {
+		var l string
+		if ll, ok := i.(string); ok {
+			switch ll {
+			case "debug":
+				l = colorize("DBG", colorYellow, noColor)
+			case "info":
+				l = colorize("INF", colorGreen, noColor)
+			case "warn":
+				l = colorize("WRN", colorRed, noColor)
+			case "error":
+				l = colorize(colorize("ERR", colorRed, noColor), colorBold, noColor)
+			case "fatal":
+				l = colorize(colorize("FTL", colorRed, noColor), colorBold, noColor)
+			case "panic":
+				l = colorize(colorize("PNC", colorRed, noColor), colorBold, noColor)
+			default:
+				l = colorize("???", colorBold, noColor)
+			}
+		} else {
+			l = strings.ToUpper(fmt.Sprintf("%s", i))[0:3]
+		}
+		return l
+	}
+}
+
+func consoleDefaultFormatCaller(noColor bool) Formatter {
+	return func(i interface{}) string {
+		var c string
+		if cc, ok := i.(string); ok {
+			c = cc
+		}
+		if len(c) > 0 {
+			cwd, err := os.Getwd()
+			if err == nil {
+				c = strings.TrimPrefix(c, cwd)
+				c = strings.TrimPrefix(c, "/")
+			}
+			c = colorize(c, colorBold, noColor) + colorize(" >", colorFaint, noColor)
+		}
+		return c
+	}
+}
+
+func consoleDefaultFormatMessage(i interface{}) string {
+	return fmt.Sprintf("%s", i)
+}
+
+func consoleDefaultFormatFieldName(noColor bool) Formatter {
+	return func(i interface{}) string {
+		return colorize(fmt.Sprintf("%s=", i), colorFaint, noColor)
+	}
+}
+
+func consoleDefaultFormatFieldValue(i interface{}) string {
+	return fmt.Sprintf("%s", i)
+}
+
+func consoleDefaultFormatErrFieldName(noColor bool) Formatter {
+	return func(i interface{}) string {
+		return colorize(fmt.Sprintf("%s=", i), colorRed, noColor)
+	}
+}
+
+func consoleDefaultFormatErrFieldValue(noColor bool) Formatter {
+	return func(i interface{}) string {
+		return colorize(fmt.Sprintf("%s", i), colorRed, noColor)
+	}
+}

console_test.go

@@ -2,29 +2,237 @@ package zerolog_test
 
 import (
 	"bytes"
+	"fmt"
+	"io/ioutil"
 	"os"
 	"strings"
 	"testing"
+	"time"
 
 	"github.com/rs/zerolog"
 )
 
-func ExampleConsoleWriter_Write() {
+func ExampleConsoleWriter() {
 	log := zerolog.New(zerolog.ConsoleWriter{Out: os.Stdout, NoColor: true})
 
-	log.Info().Msg("hello world")
-	// Output: <nil> |INFO| hello world
+	log.Info().Str("foo", "bar").Msg("Hello World")
+	// Output: <nil> INF Hello World foo=bar
 }
 
-func TestConsoleWriterNumbers(t *testing.T) {
-	buf := &bytes.Buffer{}
-	log := zerolog.New(zerolog.ConsoleWriter{Out: buf, NoColor: true})
-	log.Info().
-		Float64("float", 1.23).
-		Uint64("small", 123).
-		Uint64("big", 1152921504606846976).
-		Msg("msg")
-	if got, want := strings.TrimSpace(buf.String()), "<nil> |INFO| msg big=1152921504606846976 float=1.23 small=123"; got != want {
-		t.Errorf("\ngot:\n%s\nwant:\n%s", got, want)
+func ExampleConsoleWriter_customFormatters() {
+	out := zerolog.ConsoleWriter{Out: os.Stdout, NoColor: true}
+	out.FormatLevel = func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("%-6s|", i)) }
+	out.FormatFieldName = func(i interface{}) string { return fmt.Sprintf("%s:", i) }
+	out.FormatFieldValue = func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("%s", i)) }
+	log := zerolog.New(out)
+
+	log.Info().Str("foo", "bar").Msg("Hello World")
+	// Output: <nil> INFO  | Hello World foo:BAR
+}
+
+func ExampleNewConsoleWriter() {
+	out := zerolog.NewConsoleWriter()
+	out.NoColor = true // For testing purposes only
+	log := zerolog.New(out)
+
+	log.Debug().Str("foo", "bar").Msg("Hello World")
+	// Output: <nil> DBG Hello World foo=bar
+}
+
+func ExampleNewConsoleWriter_customFormatters() {
+	out := zerolog.NewConsoleWriter(
+		func(w *zerolog.ConsoleWriter) {
+			// Customize time format
+			w.TimeFormat = time.RFC822
+			// Customize level formatting
+			w.FormatLevel = func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("[%-5s]", i)) }
+		},
+	)
+	out.NoColor = true // For testing purposes only
+
+	log := zerolog.New(out)
+
+	log.Info().Str("foo", "bar").Msg("Hello World")
+	// Output: <nil> [INFO ] Hello World foo=bar
+}
+
+func TestConsoleLogger(t *testing.T) {
+	t.Run("Numbers", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		log := zerolog.New(zerolog.ConsoleWriter{Out: buf, NoColor: true})
+		log.Info().
+			Float64("float", 1.23).
+			Uint64("small", 123).
+			Uint64("big", 1152921504606846976).
+			Msg("msg")
+		if got, want := strings.TrimSpace(buf.String()), "<nil> INF msg big=1152921504606846976 float=1.23 small=123"; got != want {
+			t.Errorf("\ngot:\n%s\nwant:\n%s", got, want)
+		}
+	})
+}
+
+func TestConsoleWriter(t *testing.T) {
+	t.Run("Default field formatter", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, PartsOrder: []string{"foo"}}
+
+		_, err := w.Write([]byte(`{"foo" : "DEFAULT"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "DEFAULT foo=DEFAULT\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Write colorized", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: false}
+
+		_, err := w.Write([]byte(`{"level" : "warn", "message" : "Foobar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "\x1b[2m<nil>\x1b[0m \x1b[31mWRN\x1b[0m Foobar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Write fields", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
+
+		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
+		_, err := w.Write([]byte(`{"time" : "` + d + `", "level" : "debug", "message" : "Foobar", "foo" : "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "12:00AM DBG Foobar foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Write error field", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
+
+		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
+		evt := `{"time" : "` + d + `", "level" : "error", "message" : "Foobar", "aaa" : "bbb", "error" : "Error"}`
+		// t.Log(evt)
+
+		_, err := w.Write([]byte(evt))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "12:00AM ERR Foobar error=Error aaa=bbb\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Write caller field", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
+
+		cwd, err := os.Getwd()
+		if err != nil {
+			t.Fatalf("Cannot get working directory: %s", err)
+		}
+
+		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
+		evt := `{"time" : "` + d + `", "level" : "debug", "message" : "Foobar", "foo" : "bar", "caller" : "` + cwd + `/foo/bar.go"}`
+		// t.Log(evt)
+
+		_, err = w.Write([]byte(evt))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "12:00AM DBG foo/bar.go > Foobar foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Write JSON field", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
+
+		evt := `{"level" : "debug", "message" : "Foobar", "foo" : [1, 2, 3], "bar" : true}`
+		// t.Log(evt)
+
+		_, err := w.Write([]byte(evt))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "<nil> DBG Foobar bar=true foo=[1,2,3]\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+}
+
+func TestConsoleWriterConfiguration(t *testing.T) {
+	t.Run("Sets TimeFormat", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, TimeFormat: time.RFC3339}
+
+		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
+		evt := `{"time" : "` + d + `", "level" : "info", "message" : "Foobar"}`
+
+		_, err := w.Write([]byte(evt))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "1970-01-01T00:00:00Z INF Foobar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Sets PartsOrder", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, PartsOrder: []string{"message", "level"}}
+
+		evt := `{"level" : "info", "message" : "Foobar"}`
+		_, err := w.Write([]byte(evt))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "Foobar INF\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+}
+
+func BenchmarkConsoleWriter(b *testing.B) {
+	b.ResetTimer()
+	b.ReportAllocs()
+
+	var msg = []byte(`{"level" : "info", "foo" : "bar", "message" : "HELLO", "time" : "1990-01-01"}`)
+
+	w := zerolog.ConsoleWriter{Out: ioutil.Discard, NoColor: false}
+
+	for i := 0; i < b.N; i++ {
+		w.Write(msg)
 	}
 }

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
 }
 
@@ -108,7 +108,7 @@ func (c Context) AnErr(key string, err error) Context {
 	case nil:
 		return c
 	case LogObjectMarshaler:
-		return c.Object(key,m)
+		return c.Object(key, m)
 	case error:
 		return c.Str(key, m.Error())
 	case string:
@@ -350,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{}
@@ -362,6 +362,20 @@ func (c Context) Caller() Context {
 	return c
 }
 
+type stackTraceHook struct{}
+
+func (sh stackTraceHook) Run(e *Event, level Level, msg string) {
+	e.Stack()
+}
+
+var sh = stackTraceHook{}
+
+// Stack enables stack trace printing for the error passed to Err().
+func (c Context) Stack() Context {
+	c.l = c.l.Hook(sh)
+	return c
+}
+
 // IPAddr adds IPv4 or IPv6 Address to the context
 func (c Context) IPAddr(key string, ip net.IP) Context {
 	c.l.context = enc.AppendIPAddr(enc.AppendKey(c.l.context, key), ip)

diode/diode.go

@@ -19,12 +19,16 @@ var bufPool = &sync.Pool{
 
 type Alerter func(missed int)
 
+type diodeFetcher interface {
+	diodes.Diode
+	Next() diodes.GenericDataType
+}
+
 // Writer is a io.Writer wrapper that uses a diode to make Write lock-free,
 // non-blocking and thread safe.
 type Writer struct {
 	w    io.Writer
-	d    *diodes.ManyToOne
-	p    *diodes.Poller
+	d    diodeFetcher
 	c    context.CancelFunc
 	done chan struct{}
 }
@@ -35,25 +39,34 @@ type Writer struct {
 //
 // Use a diode.Writer when
 //
-//     wr := diode.NewWriter(w, 1000, 10 * time.Millisecond, func(missed int) {
+//     wr := diode.NewWriter(w, 1000, 0, func(missed int) {
 //         log.Printf("Dropped %d messages", missed)
 //     })
 //     log := zerolog.New(wr)
 //
+// If pollInterval is greater than 0, a poller is used otherwise a waiter is
+// used.
 //
 // See code.cloudfoundry.org/go-diodes for more info on diode.
 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: d,
-		p: diodes.NewPoller(d,
-			diodes.WithPollingInterval(poolInterval),
-			diodes.WithPollingContext(ctx)),
+		w:    w,
 		c:    cancel,
 		done: make(chan struct{}),
 	}
+	if f == nil {
+		f = func(int) {}
+	}
+	d := diodes.NewManyToOne(size, diodes.AlertFunc(f))
+	if poolInterval > 0 {
+		dw.d = diodes.NewPoller(d,
+			diodes.WithPollingInterval(poolInterval),
+			diodes.WithPollingContext(ctx))
+	} else {
+		dw.d = diodes.NewWaiter(d,
+			diodes.WithWaiterContext(ctx))
+	}
 	go dw.poll()
 	return dw
 }
@@ -80,12 +93,22 @@ func (dw Writer) Close() error {
 func (dw Writer) poll() {
 	defer close(dw.done)
 	for {
-		d := dw.p.Next()
+		d := dw.d.Next()
 		if d == nil {
 			return
 		}
 		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

@@ -5,14 +5,13 @@ package diode_test
 import (
 	"fmt"
 	"os"
-	"time"
 
 	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/diode"
 )
 
 func ExampleNewWriter() {
-	w := diode.NewWriter(os.Stdout, 1000, 10*time.Millisecond, func(missed int) {
+	w := diode.NewWriter(os.Stdout, 1000, 0, func(missed int) {
 		fmt.Printf("Dropped %d messages\n", missed)
 	})
 	log := zerolog.New(w)

diode/diode_test.go

@@ -16,7 +16,7 @@ import (
 
 func TestNewWriter(t *testing.T) {
 	buf := bytes.Buffer{}
-	w := diode.NewWriter(&buf, 1000, 10*time.Millisecond, func(missed int) {
+	w := diode.NewWriter(&buf, 1000, 0, func(missed int) {
 		fmt.Printf("Dropped %d messages\n", missed)
 	})
 	log := zerolog.New(w)
@@ -33,15 +33,22 @@ func TestNewWriter(t *testing.T) {
 func Benchmark(b *testing.B) {
 	log.SetOutput(ioutil.Discard)
 	defer log.SetOutput(os.Stderr)
-	w := diode.NewWriter(ioutil.Discard, 100000, 10*time.Millisecond, nil)
-	log := zerolog.New(w)
-	defer w.Close()
-
-	b.SetParallelism(1000)
-	b.RunParallel(func(pb *testing.PB) {
-		for pb.Next() {
-			log.Print("test")
-		}
-	})
+	benchs := map[string]time.Duration{
+		"Waiter": 0,
+		"Pooler": 10 * time.Millisecond,
+	}
+	for name, interval := range benchs {
+		b.Run(name, func(b *testing.B) {
+			w := diode.NewWriter(ioutil.Discard, 100000, interval, nil)
+			log := zerolog.New(w)
+			defer w.Close()
 
+			b.SetParallelism(1000)
+			b.RunParallel(func(pb *testing.PB) {
+				for pb.Next() {
+					log.Print("test")
+				}
+			})
+		})
+	}
 }

event.go

@@ -18,11 +18,6 @@ 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 {
@@ -30,8 +25,22 @@ type Event struct {
 	w     LevelWriter
 	level Level
 	done  func(msg string)
+	stack bool   // enable error stack trace
 	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
@@ -49,7 +58,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
@@ -60,19 +69,30 @@ 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 {
+	if e == nil {
+		return e
+	}
+	e.level = Disabled
+	return nil
 }
 
 // Msg sends the *Event with msg added as the message field if not empty.
@@ -83,6 +103,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 {
@@ -91,14 +126,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)
 	}
@@ -106,21 +133,14 @@ func (e *Event) Msg(msg string) {
 		defer e.done(msg)
 	}
 	if err := e.write(); err != nil {
-		fmt.Fprintf(os.Stderr, "zerolog: could not write event: %v", err)
+		if ErrorHandler != nil {
+			ErrorHandler(err)
+		} else {
+			fmt.Fprintf(os.Stderr, "zerolog: could not write event: %v\n", err)
+		}
 	}
 }
 
-// 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 {
@@ -138,7 +158,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(dict)
 	return e
 }
 
@@ -247,8 +267,10 @@ func (e *Event) RawJSON(key string, b []byte) *Event {
 // 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 {
-	marshaled := ErrorMarshalFunc(err)
-	switch m := marshaled.(type) {
+	if e == nil {
+		return e
+	}
+	switch m := ErrorMarshalFunc(err).(type) {
 	case nil:
 		return e
 	case LogObjectMarshaler:
@@ -261,17 +283,16 @@ func (e *Event) AnErr(key string, err error) *Event {
 		return e.Interface(key, m)
 	}
 }
+
 // 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
 	}
-
 	arr := Arr()
 	for _, err := range errs {
-		marshaled := ErrorMarshalFunc(err)
-		switch m := marshaled.(type) {
+		switch m := ErrorMarshalFunc(err).(type) {
 		case LogObjectMarshaler:
 			arr = arr.Object(m)
 		case error:
@@ -289,10 +310,42 @@ func (e *Event) Errs(key string, errs []error) *Event {
 // 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.
+//
+// To customize the key name, change zerolog.ErrorFieldName.
+//
+// If Stack() has been called before and zerolog.ErrorStackMarshaler is defined,
+// the err is passed to ErrorStackMarshaler and the result is appended to the
+// zerolog.ErrorStackFieldName.
 func (e *Event) Err(err error) *Event {
+	if e == nil {
+		return e
+	}
+	if e.stack && ErrorStackMarshaler != nil {
+		switch m := ErrorStackMarshaler(err).(type) {
+		case nil:
+		case LogObjectMarshaler:
+			e.Object(ErrorStackFieldName, m)
+		case error:
+			e.Str(ErrorStackFieldName, m.Error())
+		case string:
+			e.Str(ErrorStackFieldName, m)
+		default:
+			e.Interface(ErrorStackFieldName, m)
+		}
+	}
 	return e.AnErr(ErrorFieldName, err)
 }
 
+// Stack enables stack trace printing for the error passed to Err().
+//
+// ErrorStackMarshaler must be set for this method to do something.
+func (e *Event) Stack() *Event {
+	if e != nil {
+		e.stack = true
+	}
+	return e
+}
+
 // Bool adds the field key with val as a bool to the *Event context.
 func (e *Event) Bool(key string, b bool) *Event {
 	if e == nil {

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) {
@@ -36,7 +36,7 @@ func appendFields(dst []byte, fields map[string]interface{}) []byte {
 				e.buf = e.buf[:0]
 				e.appendObject(m)
 				dst = append(dst, e.buf...)
-				eventPool.Put(e)
+				putEvent(e)
 			case error:
 				dst = enc.AppendString(dst, m.Error())
 			case string:
@@ -54,7 +54,7 @@ func appendFields(dst []byte, fields map[string]interface{}) []byte {
 					e.buf = e.buf[:0]
 					e.appendObject(m)
 					dst = append(dst, e.buf...)
-					eventPool.Put(e)
+					putEvent(e)
 				case error:
 					dst = enc.AppendString(dst, m.Error())
 				case string:
@@ -99,37 +99,101 @@ func appendFields(dst []byte, fields map[string]interface{}) []byte {
 		case time.Duration:
 			dst = enc.AppendDuration(dst, val, DurationFieldUnit, DurationFieldInteger)
 		case *string:
-			dst = enc.AppendString(dst, *val)
+			if val != nil {
+				dst = enc.AppendString(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *bool:
-			dst = enc.AppendBool(dst, *val)
+			if val != nil {
+				dst = enc.AppendBool(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *int:
-			dst = enc.AppendInt(dst, *val)
+			if val != nil {
+				dst = enc.AppendInt(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *int8:
-			dst = enc.AppendInt8(dst, *val)
+			if val != nil {
+				dst = enc.AppendInt8(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *int16:
-			dst = enc.AppendInt16(dst, *val)
+			if val != nil {
+				dst = enc.AppendInt16(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *int32:
-			dst = enc.AppendInt32(dst, *val)
+			if val != nil {
+				dst = enc.AppendInt32(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *int64:
-			dst = enc.AppendInt64(dst, *val)
+			if val != nil {
+				dst = enc.AppendInt64(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *uint:
-			dst = enc.AppendUint(dst, *val)
+			if val != nil {
+				dst = enc.AppendUint(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *uint8:
-			dst = enc.AppendUint8(dst, *val)
+			if val != nil {
+				dst = enc.AppendUint8(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *uint16:
-			dst = enc.AppendUint16(dst, *val)
+			if val != nil {
+				dst = enc.AppendUint16(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *uint32:
-			dst = enc.AppendUint32(dst, *val)
+			if val != nil {
+				dst = enc.AppendUint32(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *uint64:
-			dst = enc.AppendUint64(dst, *val)
+			if val != nil {
+				dst = enc.AppendUint64(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *float32:
-			dst = enc.AppendFloat32(dst, *val)
+			if val != nil {
+				dst = enc.AppendFloat32(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *float64:
-			dst = enc.AppendFloat64(dst, *val)
+			if val != nil {
+				dst = enc.AppendFloat64(dst, *val)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *time.Time:
-			dst = enc.AppendTime(dst, *val, TimeFieldFormat)
+			if val != nil {
+				dst = enc.AppendTime(dst, *val, TimeFieldFormat)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case *time.Duration:
-			dst = enc.AppendDuration(dst, *val, DurationFieldUnit, DurationFieldInteger)
+			if val != nil {
+				dst = enc.AppendDuration(dst, *val, DurationFieldUnit, DurationFieldInteger)
+			} else {
+				dst = enc.AppendNil(dst)
+			}
 		case []string:
 			dst = enc.AppendStrings(dst, val)
 		case []bool:

globals.go

@@ -22,6 +22,17 @@ var (
 	// CallerSkipFrameCount is the number of stack frames to skip to find the caller.
 	CallerSkipFrameCount = 2
 
+	// ErrorStackFieldName is the field name used for error stacks.
+	ErrorStackFieldName = "stack"
+
+	// ErrorStackMarshaler extract the stack from err if any.
+	ErrorStackMarshaler func(err error) interface{}
+
+	// ErrorMarshalFunc allows customization of global error marshaling
+	ErrorMarshalFunc = func(err error) interface{} {
+		return err
+	}
+
 	// TimeFieldFormat defines the time format of the Time field type.
 	// If set to an empty string, the time is formatted as an UNIX timestamp
 	// as integer.
@@ -37,6 +48,11 @@ var (
 	// DurationFieldInteger renders Dur fields as integer instead of float if
 	// set to true.
 	DurationFieldInteger = false
+
+	// ErrorHandler is called whenever zerolog fails to write an event on its
+	// output. If not set, an error is printed on the stderr. This handler must
+	// be thread safe and non-blocking.
+	ErrorHandler func(err error)
 )
 
 var (

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) {

log.go

@@ -292,22 +292,24 @@ func (l *Logger) Error() *Event {
 }
 
 // Fatal starts a new message with fatal level. The os.Exit(1) function
-// is called by the Msg method.
+// is called by the Msg method, which terminates the program immediately.
 //
 // You must call Msg on the returned event in order to send the event.
 func (l *Logger) Fatal() *Event {
 	return l.newEvent(FatalLevel, func(msg string) { os.Exit(1) })
 }
 
-// Panic starts a new message with panic level. The message is also sent
-// to the panic function.
+// Panic starts a new message with panic level. The panic() function
+// is called by the Msg method, which stops the ordinary flow of a goroutine.
 //
 // You must call Msg on the returned event in order to send the event.
 func (l *Logger) Panic() *Event {
 	return l.newEvent(PanicLevel, func(msg string) { panic(msg) })
 }
 
-// WithLevel starts a new message with level.
+// WithLevel starts a new message with level. Unlike Fatal and Panic
+// methods, WithLevel does not terminate the program or stop the ordinary
+// flow of a gourotine when used with their respective levels.
 //
 // You must call Msg on the returned event in order to send the event.
 func (l *Logger) WithLevel(level Level) *Event {
@@ -321,9 +323,9 @@ func (l *Logger) WithLevel(level Level) *Event {
 	case ErrorLevel:
 		return l.Error()
 	case FatalLevel:
-		return l.Fatal()
+		return l.newEvent(FatalLevel, nil)
 	case PanicLevel:
-		return l.Panic()
+		return l.newEvent(PanicLevel, nil)
 	case NoLevel:
 		return l.Log()
 	case Disabled:

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

@@ -164,6 +164,52 @@ func TestFieldsMapPnt(t *testing.T) {
 	}
 }
 
+func TestFieldsMapNilPnt(t *testing.T) {
+	var (
+		stringPnt  *string
+		boolPnt    *bool
+		intPnt     *int
+		int8Pnt    *int8
+		int16Pnt   *int16
+		int32Pnt   *int32
+		int64Pnt   *int64
+		uintPnt    *uint
+		uint8Pnt   *uint8
+		uint16Pnt  *uint16
+		uint32Pnt  *uint32
+		uint64Pnt  *uint64
+		float32Pnt *float32
+		float64Pnt *float64
+		durPnt     *time.Duration
+		timePnt    *time.Time
+	)
+	out := &bytes.Buffer{}
+	log := New(out)
+	fields := map[string]interface{}{
+		"string":  stringPnt,
+		"bool":    boolPnt,
+		"int":     intPnt,
+		"int8":    int8Pnt,
+		"int16":   int16Pnt,
+		"int32":   int32Pnt,
+		"int64":   int64Pnt,
+		"uint":    uintPnt,
+		"uint8":   uint8Pnt,
+		"uint16":  uint16Pnt,
+		"uint32":  uint32Pnt,
+		"uint64":  uint64Pnt,
+		"float32": float32Pnt,
+		"float64": float64Pnt,
+		"dur":     durPnt,
+		"time":    timePnt,
+	}
+
+	log.Log().Fields(fields).Msg("")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"bool":null,"dur":null,"float32":null,"float64":null,"int":null,"int16":null,"int32":null,"int64":null,"int8":null,"string":null,"time":null,"uint":null,"uint16":null,"uint32":null,"uint64":null,"uint8":null}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+}
+
 func TestFields(t *testing.T) {
 	out := &bytes.Buffer{}
 	log := New(out)
@@ -398,7 +444,22 @@ 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)
+	}
+}
+
+func TestDiscard(t *testing.T) {
+	out := &bytes.Buffer{}
+	log := New(out)
+	log.Log().Discard().Str("a", "b").Msgf("one %s %.1f %d %v", "two", 3.4, 5, errors.New("six"))
+	if got, want := decodeIfBinaryToString(out.Bytes()), ""; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+
+	// Double call
+	log.Log().Discard().Discard().Str("a", "b").Msgf("one %s %.1f %d %v", "two", 3.4, 5, errors.New("six"))
+	if got, want := decodeIfBinaryToString(out.Bytes()), ""; got != want {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
 }
@@ -527,7 +588,7 @@ type loggableError struct {
 }
 
 func (l loggableError) MarshalZerologObject(e *Event) {
-	e.Str("message", l.error.Error() + ": loggableError")
+	e.Str("message", l.error.Error()+": loggableError")
 }
 
 func TestErrorMarshalFunc(t *testing.T) {
@@ -549,7 +610,7 @@ func TestErrorMarshalFunc(t *testing.T) {
 
 	// test overriding the ErrorMarshalFunc
 	originalErrorMarshalFunc := ErrorMarshalFunc
-	defer func(){
+	defer func() {
 		ErrorMarshalFunc = originalErrorMarshalFunc
 	}()
 
@@ -579,3 +640,24 @@ func TestErrorMarshalFunc(t *testing.T) {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
 }
+
+type errWriter struct {
+	error
+}
+
+func (w errWriter) Write(p []byte) (n int, err error) {
+	return 0, w.error
+}
+
+func TestErrorHandler(t *testing.T) {
+	var got error
+	want := errors.New("write error")
+	ErrorHandler = func(err error) {
+		got = err
+	}
+	log := New(errWriter{want})
+	log.Log().Msg("test")
+	if got != want {
+		t.Errorf("ErrorHandler err = %#v, want %#v", got, want)
+	}
+}

pkgerrors/stacktrace.go

@@ -0,0 +1,65 @@
+package pkgerrors
+
+import (
+	"github.com/pkg/errors"
+)
+
+var (
+	StackSourceFileName     = "source"
+	StackSourceLineName     = "line"
+	StackSourceFunctionName = "func"
+)
+
+type state struct {
+	b []byte
+}
+
+// Write implement fmt.Formatter interface.
+func (s *state) Write(b []byte) (n int, err error) {
+	s.b = b
+	return len(b), nil
+}
+
+// Width implement fmt.Formatter interface.
+func (s *state) Width() (wid int, ok bool) {
+	return 0, false
+}
+
+// Precision implement fmt.Formatter interface.
+func (s *state) Precision() (prec int, ok bool) {
+	return 0, false
+}
+
+// Flag implement fmt.Formatter interface.
+func (s *state) Flag(c int) bool {
+	return false
+}
+
+func frameField(f errors.Frame, s *state, c rune) string {
+	f.Format(s, c)
+	return string(s.b)
+}
+
+// MarshalStack implements pkg/errors stack trace marshaling.
+//
+//   zerolog.ErrorStackMarshaler = MarshalStack
+func MarshalStack(err error) interface{} {
+	type stackTracer interface {
+		StackTrace() errors.StackTrace
+	}
+	sterr, ok := err.(stackTracer)
+	if !ok {
+		return nil
+	}
+	st := sterr.StackTrace()
+	s := &state{}
+	out := make([]map[string]string, 0, len(st))
+	for _, frame := range st {
+		out = append(out, map[string]string{
+			StackSourceFileName:     frameField(frame, s, 's'),
+			StackSourceLineName:     frameField(frame, s, 'd'),
+			StackSourceFunctionName: frameField(frame, s, 'n'),
+		})
+	}
+	return out
+}

pkgerrors/stacktrace_test.go

@@ -0,0 +1,41 @@
+// +build !binary_log
+
+package pkgerrors
+
+import (
+	"bytes"
+	"regexp"
+	"testing"
+
+	"github.com/pkg/errors"
+	"github.com/rs/zerolog"
+)
+
+func TestLogStack(t *testing.T) {
+	zerolog.ErrorStackMarshaler = MarshalStack
+
+	out := &bytes.Buffer{}
+	log := zerolog.New(out)
+
+	err := errors.Wrap(errors.New("error message"), "from error")
+	log.Log().Stack().Err(err).Msg("")
+
+	got := out.String()
+	want := `\{"stack":\[\{"func":"TestLogStack","line":"20","source":"stacktrace_test.go"\},.*\],"error":"from error: error message"\}\n`
+	if ok, _ := regexp.MatchString(want, got); !ok {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+}
+
+func BenchmarkLogStack(b *testing.B) {
+	zerolog.ErrorStackMarshaler = MarshalStack
+	out := &bytes.Buffer{}
+	log := zerolog.New(out)
+	err := errors.Wrap(errors.New("error message"), "from error")
+	b.ReportAllocs()
+
+	for i := 0; i < b.N; i++ {
+		log.Log().Stack().Err(err).Msg("")
+		out.Reset()
+	}
+}

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}
 		},