Add support for dicts in array (#375)

Fixes #111.

.github/dependabot.yml

@@ -0,0 +1,10 @@
+version: 2
+updates:
+  - package-ecosystem: github-actions
+    directory: /
+    schedule:
+      interval: weekly
+  - package-ecosystem: gomod
+    directory: /
+    schedule:
+      interval: weekly

.github/workflows/test.yml

@@ -0,0 +1,27 @@
+on: [push, pull_request]
+name: Test
+jobs:
+  test:
+    strategy:
+      matrix:
+        go-version: [1.15.x, 1.16.x]
+        os: [ubuntu-latest, macos-latest]
+    runs-on: ${{ matrix.os }}
+    steps:
+    - name: Install Go
+      uses: actions/setup-go@v2
+      with:
+        go-version: ${{ matrix.go-version }}
+    - name: Checkout code
+      uses: actions/checkout@v2
+    - uses: actions/cache@v2
+      with:
+        path: ~/go/pkg/mod
+        key: ${{ runner.os }}-go-${{ hashFiles('**/go.sum') }}
+        restore-keys: |
+          ${{ runner.os }}-go-
+    - name: Test
+      run: go test -race -bench . -benchmem ./...
+    - name: Test CBOR
+      run: go test -tags binary_log ./...
+

.gitignore

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

.travis.yml

@@ -1,13 +0,0 @@
-language: go
-go:
-- "1.7"
-- "1.8"
-- "1.9"
-- "1.10"
-- "master"
-matrix:
-  allow_failures:
-      - go: "master"
-script:
-  - go test -v -race -cpu=1,2,4 -bench . -benchmem ./...
-  - go test -v -tags binary_log -race -cpu=1,2,4 -bench . -benchmem ./...

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)
 
@@ -18,20 +18,21 @@ Find out [who uses zerolog](https://github.com/rs/zerolog/wiki/Who-uses-zerolog)
 
 ## Features
 
-* Blazing fast
-* Low to zero allocation
-* Level logging
-* Sampling
-* Hooks
-* Contextual fields
+* [Blazing fast](#benchmarks)
+* [Low to zero allocation](#benchmarks)
+* [Leveled logging](#leveled-logging)
+* [Sampling](#log-sampling)
+* [Hooks](#hooks)
+* [Contextual fields](#contextual-logging)
 * `context.Context` integration
-* `net/http` helpers
-* JSON and CBOR encoding formats
-* Pretty logging for development
+* [Integration with `net/http`](#integration-with-nethttp)
+* [JSON and CBOR encoding formats](#binary-encoding)
+* [Pretty logging for development](#pretty-logging)
+* [Error Logging (with optional Stacktrace)](#error-logging)
 
 ## Installation
 
-```go
+```bash
 go get -u github.com/rs/zerolog/log
 ```
 
@@ -51,16 +52,14 @@ import (
 
 func main() {
     // UNIX Time is faster and smaller than most timestamps
-    // If you set zerolog.TimeFieldFormat to an empty string,
-    // logs will write with UNIX time
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Print("hello world")
 }
 
 // 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
@@ -76,15 +75,20 @@ import (
 )
 
 func main() {
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Debug().
         Str("Scale", "833 cents").
         Float64("Interval", 833.09).
         Msg("Fibonacci is everywhere")
+    
+    log.Debug().
+        Str("Name", "Tom").
+        Send()
 }
 
-// Output: {"time":1524104936,"level":"debug","Scale":"833 cents","Interval":833.09,"message":"Fibonacci is everywhere"}
+// Output: {"level":"debug","Scale":"833 cents","Interval":833.09,"time":1562212768,"message":"Fibonacci is everywhere"}
+// Output: {"level":"debug","Name":"Tom","time":1562212768}
 ```
 
 > You'll note in the above example that when adding contextual fields, the fields are strongly typed. You can find the full list of supported fields [here](#standard-types)
@@ -102,7 +106,7 @@ import (
 )
 
 func main() {
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Info().Msg("hello world")
 }
@@ -120,6 +124,7 @@ func main() {
 * warn (`zerolog.WarnLevel`, 2)
 * info (`zerolog.InfoLevel`, 1)
 * debug (`zerolog.DebugLevel`, 0)
+* trace (`zerolog.TraceLevel`, -1)
 
 You can set the Global logging level to any of these options using the `SetGlobalLevel` function in the zerolog package, passing in one of the given constants above, e.g. `zerolog.InfoLevel` would be the "info" level.  Whichever level is chosen, all logs with a level greater than or equal to that level will be written. To turn off logging entirely, pass the `zerolog.Disabled` constant.
 
@@ -138,7 +143,7 @@ import (
 )
 
 func main() {
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
     debug := flag.Bool("debug", false, "sets log level to debug")
 
     flag.Parse()
@@ -189,7 +194,7 @@ import (
 )
 
 func main() {
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Log().
         Str("foo", "bar").
@@ -199,6 +204,80 @@ func main() {
 // Output: {"time":1494567715,"foo":"bar"}
 ```
 
+### Error Logging
+
+You can log errors using the `Err` method
+
+```go
+package main
+
+import (
+	"errors"
+
+	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/log"
+)
+
+func main() {
+	zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
+
+	err := errors.New("seems we have an error here")
+	log.Error().Err(err).Msg("")
+}
+
+// Output: {"level":"error","error":"seems we have an error here","time":1609085256}
+```
+
+> The default field name for errors is `error`, you can change this by setting `zerolog.ErrorFieldName` to meet your needs.
+
+#### Error Logging with Stacktrace
+
+Using `github.com/pkg/errors`, you can add a formatted stacktrace to your errors. 
+
+```go
+package main
+
+import (
+	"github.com/pkg/errors"
+	"github.com/rs/zerolog/pkgerrors"
+
+	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/log"
+)
+
+func main() {
+	zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
+	zerolog.ErrorStackMarshaler = pkgerrors.MarshalStack
+
+	err := outer()
+	log.Error().Stack().Err(err).Msg("")
+}
+
+func inner() error {
+	return errors.New("seems we have an error here")
+}
+
+func middle() error {
+	err := inner()
+	if err != nil {
+		return err
+	}
+	return nil
+}
+
+func outer() error {
+	err := middle()
+	if err != nil {
+		return err
+	}
+	return nil
+}
+
+// Output: {"level":"error","stack":[{"func":"inner","line":"20","source":"errors.go"},{"func":"middle","line":"24","source":"errors.go"},{"func":"outer","line":"32","source":"errors.go"},{"func":"main","line":"15","source":"errors.go"},{"func":"main","line":"204","source":"proc.go"},{"func":"goexit","line":"1374","source":"asm_amd64.s"}],"error":"seems we have an error here","time":1609086683}
+```
+
+> zerolog.ErrorStackMarshaler must be set in order for the stack to output anything.
+
 #### Logging Fatal Messages
 
 ```go
@@ -215,7 +294,7 @@ func main() {
     err := errors.New("A repo man spends his life getting into tense situations")
     service := "myservice"
 
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Fatal().
         Err(err).
@@ -229,6 +308,7 @@ func main() {
 
 > NOTE: Using `Msgf` generates one allocation even when the logger is disabled.
 
+
 ### Create logger instance to manage different outputs
 
 ```go
@@ -243,7 +323,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")
 
@@ -252,14 +332,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
@@ -293,16 +397,25 @@ 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)
-log := zerolog.New(w)
+wr := diode.NewWriter(os.Stdout, 1000, 10*time.Millisecond, func(missed int) {
+		fmt.Printf("Logger Dropped %d messages", missed)
+	})
+log := zerolog.New(wr)
 log.Print("test")
 ```
 
@@ -355,7 +468,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")
 
@@ -396,11 +509,11 @@ c := alice.New()
 c = c.Append(hlog.NewHandler(log))
 
 // Install some provided extra handler to set some request's context fields.
-// Thanks to those handler, all our logs will come with some pre-populated fields.
+// Thanks to that handler, all our logs will come with some prepopulated fields.
 c = c.Append(hlog.AccessHandler(func(r *http.Request, status, size int, duration time.Duration) {
     hlog.FromRequest(r).Info().
         Str("method", r.Method).
-        Str("url", r.URL.String()).
+        Stringer("url", r.URL).
         Int("status", status).
         Int("size", size).
         Dur("duration", duration).
@@ -430,22 +543,40 @@ if err := http.ListenAndServe(":8080", nil); err != nil {
 }
 ```
 
+## Multiple Log Output
+`zerolog.MultiLevelWriter` may be used to send the log message to multiple outputs. 
+In this example, we send the log message to both `os.Stdout` and the in-built ConsoleWriter.
+```go
+func main() {
+	consoleWriter := zerolog.ConsoleWriter{Out: os.Stdout}
+
+	multi := zerolog.MultiLevelWriter(consoleWriter, os.Stdout)
+
+	logger := zerolog.New(multi).With().Timestamp().Logger()
+
+	logger.Info().Msg("Hello World!")
+}
+
+// Output (Line 1: Console; Line 2: Stdout)
+// 12:36PM INF Hello World!
+// {"level":"info","time":"2019-11-07T12:36:38+03:00","message":"Hello World!"}
+``` 
+
 ## Global Settings
 
 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. Call this with `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.
 * `zerolog.MessageFieldName`: Can be set to customize message field name.
 * `zerolog.ErrorFieldName`: Can be set to customize `Err` field name.
-* `zerolog.TimeFieldFormat`: Can be set to customize `Time` field value formatting. If set with an empty string, times are formated as UNIX timestamp.
-    // DurationFieldUnit defines the unit for time.Duration type fields added
-    // 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.
+* `zerolog.TimeFieldFormat`: Can be set to customize `Time` field value formatting. If set with `zerolog.TimeFormatUnix`, `zerolog.TimeFormatUnixMs` or `zerolog.TimeFormatUnixMicro`, times are formated as UNIX timestamp.
+* `zerolog.DurationFieldUnit`: Can be set to customize the unit for time.Duration type fields added by `Dur` (default: `time.Millisecond`).
+* `zerolog.DurationFieldInteger`: If set to `true`, `Dur` fields are formatted as integers instead of floats (default: `false`). 
+* `zerolog.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
 
@@ -459,13 +590,18 @@ Some settings can be changed and will by applied to all loggers:
 
 ### Advanced Fields
 
-* `Err`: Takes an `error` and render it as a string using the `zerolog.ErrorFieldName` field name.
-* `Timestamp`: Insert a timestamp field with `zerolog.TimestampFieldName` field name and formatted using `zerolog.TimeFieldFormat`.
-* `Time`: Adds a field with the time formated with the `zerolog.TimeFieldFormat`.
-* `Dur`: Adds a field with a `time.Duration`.
+* `Err`: Takes an `error` and renders it as a string using the `zerolog.ErrorFieldName` field name.
+* `Func`: Run a `func` only if the level is enabled.
+* `Timestamp`: Inserts a timestamp field with `zerolog.TimestampFieldName` field name, formatted using `zerolog.TimeFieldFormat`.
+* `Time`: Adds a field with time formatted with `zerolog.TimeFieldFormat`.
+* `Dur`: Adds a field with `time.Duration`.
 * `Dict`: Adds a sub-key/value as a field of the event.
+* `RawJSON`: Adds a field with an already encoded JSON (`[]byte`)
+* `Hex`: Adds a field with value formatted as a hexadecimal string (`[]byte`)
 * `Interface`: Uses reflection to marshal the type.
 
+Most fields are also available in the slice format (`Strs` for `[]string`, `Errs` for `[]error` etc.)
+
 ## Binary Encoding
 
 In addition to the default JSON encoding, `zerolog` can produce binary logs using [CBOR](http://cbor.io) encoding. The choice of encoding can be decided at compile time using the build tag `binary_log` as follows:
@@ -480,9 +616,13 @@ with zerolog library is [CSD](https://github.com/toravir/csd/).
 ## Related Projects
 
 * [grpc-zerolog](https://github.com/cheapRoc/grpc-zerolog): Implementation of `grpclog.LoggerV2` interface using `zerolog`
+* [overlog](https://github.com/Trendyol/overlog): Implementation of `Mapped Diagnostic Context` interface using `zerolog`
+* [zerologr](https://github.com/go-logr/zerologr): Implementation of `logr.LogSink` interface using `zerolog`
 
 ## 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
@@ -542,7 +682,7 @@ Log a static string, without any context or `printf`-style templating:
 
 ## Caveats
 
-Note that zerolog does de-duplication fields. Using the same key multiple times creates multiple keys in final JSON:
+Note that zerolog does no de-duplication of fields. Using the same key multiple times creates multiple keys in final JSON:
 
 ```go
 logger := zerolog.New(os.Stderr).With().Timestamp().Logger()
@@ -552,4 +692,4 @@ logger.Info().
 // Output: {"level":"info","time":1494567715,"time":1494567715,"message":"dup"}
 ```
 
-However, it’s not a big deal as JSON accepts dup keys; the last one prevails.
+In this case, many consumers will take the last value, but this is not guaranteed; check yours if in doubt.

_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,33 @@ func (a *Array) Hex(val []byte) *Array {
 	return a
 }
 
-// Err append append the err as a string to the array.
+// RawJSON adds already encoded JSON to the array.
+func (a *Array) RawJSON(val []byte) *Array {
+	a.buf = appendJSON(enc.AppendArrayDelim(a.buf), val)
+	return a
+}
+
+// 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)
+	switch m := ErrorMarshalFunc(err).(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:
+		if m == nil || isNilValue(m) {
+			a.buf = enc.AppendNil(enc.AppendArrayDelim(a.buf))
+		} else {
+			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
 }
 
@@ -193,3 +231,10 @@ func (a *Array) MACAddr(ha net.HardwareAddr) *Array {
 	a.buf = enc.AppendMACAddr(enc.AppendArrayDelim(a.buf), ha)
 	return a
 }
+
+// Dict adds the dict Event to the array
+func (a *Array) Dict(dict *Event) *Array {
+	dict.buf = enc.AppendEndMarker(dict.buf)
+	a.buf = append(enc.AppendArrayDelim(a.buf), dict.buf...)
+	return a
+}

array_test.go

@@ -24,10 +24,15 @@ func TestArray(t *testing.T) {
 		Str("a").
 		Bytes([]byte("b")).
 		Hex([]byte{0x1f}).
+		RawJSON([]byte(`{"some":"json"}`)).
 		Time(time.Time{}).
 		IPAddr(net.IP{192, 168, 0, 10}).
-		Dur(0)
-	want := `[true,1,2,3,4,5,6,7,8,9,10,11.98122,12.987654321,"a","b","1f","0001-01-01T00:00:00Z","192.168.0.10",0]`
+		Dur(0).
+		Dict(Dict().
+			Str("bar", "baz").
+			Int("n", 1),
+		)
+	want := `[true,1,2,3,4,5,6,7,8,9,10,11.98122,12.987654321,"a","b","1f",{"some":"json"},"0001-01-01T00:00:00Z","192.168.0.10",0,{"bar":"baz","n":1}]`
 	if got := decodeObjectToStr(a.write([]byte{})); got != want {
 		t.Errorf("Array.write()\ngot:  %s\nwant: %s", got, want)
 	}

benchmark_test.go

@@ -3,6 +3,7 @@ package zerolog
 import (
 	"errors"
 	"io/ioutil"
+	"net"
 	"testing"
 	"time"
 )
@@ -147,16 +148,16 @@ func BenchmarkLogFieldType(b *testing.B) {
 		{"a", "a", 0},
 	}
 	objects := []obj{
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
 	}
 	errs := []error{errors.New("a"), errors.New("b"), errors.New("c"), errors.New("d"), errors.New("e")}
 	types := map[string]func(e *Event) *Event{
@@ -234,12 +235,13 @@ func BenchmarkLogFieldType(b *testing.B) {
 
 func BenchmarkContextFieldType(b *testing.B) {
 	oldFormat := TimeFieldFormat
-	TimeFieldFormat = ""
+	TimeFieldFormat = TimeFormatUnix
 	defer func() { TimeFieldFormat = oldFormat }()
 	bools := []bool{true, false, true, false, true, false, true, false, true, false}
 	ints := []int{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}
 	floats := []float64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}
 	strings := []string{"a", "b", "c", "d", "e", "f", "g", "h", "i", "j"}
+	stringer := net.IP{127, 0, 0, 1}
 	durations := []time.Duration{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}
 	times := []time.Time{
 		time.Unix(0, 0),
@@ -270,16 +272,16 @@ func BenchmarkContextFieldType(b *testing.B) {
 		{"a", "a", 0},
 	}
 	objects := []obj{
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
-		obj{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
+		{"a", "a", 0},
 	}
 	errs := []error{errors.New("a"), errors.New("b"), errors.New("c"), errors.New("d"), errors.New("e")}
 	types := map[string]func(c Context) Context{
@@ -307,6 +309,9 @@ func BenchmarkContextFieldType(b *testing.B) {
 		"Strs": func(c Context) Context {
 			return c.Strs("k", strings)
 		},
+		"Stringer": func(c Context) Context {
+			return c.Stringer("k", stringer)
+		},
 		"Err": func(c Context) Context {
 			return c.Err(errs[0])
 		},

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{}
@@ -107,6 +108,19 @@ func ExampleLogger_Printf() {
 	// Output: {"level":"debug","message":"hello world"}
 }
 
+func ExampleLogger_Trace() {
+	dst := bytes.Buffer{}
+	log := New(&dst)
+
+	log.Trace().
+		Str("foo", "bar").
+		Int("n", 123).
+		Msg("hello world")
+
+	fmt.Println(decodeIfBinaryToString(dst.Bytes()))
+	// Output: {"level":"trace","foo":"bar","n":123,"message":"hello world"}
+}
+
 func ExampleLogger_Debug() {
 	dst := bytes.Buffer{}
 	log := New(&dst)
@@ -350,6 +364,42 @@ func ExampleEvent_Durs() {
 	// Output: {"foo":"bar","durs":[10000,20000],"message":"hello world"}
 }
 
+func ExampleEvent_Fields_map() {
+	fields := map[string]interface{}{
+		"bar": "baz",
+		"n":   1,
+	}
+
+	dst := bytes.Buffer{}
+	log := New(&dst)
+
+	log.Log().
+		Str("foo", "bar").
+		Fields(fields).
+		Msg("hello world")
+
+	fmt.Println(decodeIfBinaryToString(dst.Bytes()))
+	// Output: {"foo":"bar","bar":"baz","n":1,"message":"hello world"}
+}
+
+func ExampleEvent_Fields_slice() {
+	fields := []interface{}{
+		"bar", "baz",
+		"n", 1,
+	}
+
+	dst := bytes.Buffer{}
+	log := New(&dst)
+
+	log.Log().
+		Str("foo", "bar").
+		Fields(fields).
+		Msg("hello world")
+
+	fmt.Println(decodeIfBinaryToString(dst.Bytes()))
+	// Output: {"foo":"bar","bar":"baz","n":1,"message":"hello world"}
+}
+
 func ExampleContext_Dict() {
 	dst := bytes.Buffer{}
 	log := New(&dst).With().
@@ -496,3 +546,39 @@ func ExampleContext_Durs() {
 	fmt.Println(decodeIfBinaryToString(dst.Bytes()))
 	// Output: {"foo":"bar","durs":[10000,20000],"message":"hello world"}
 }
+
+func ExampleContext_Fields_map() {
+	fields := map[string]interface{}{
+		"bar": "baz",
+		"n":   1,
+	}
+
+	dst := bytes.Buffer{}
+	log := New(&dst).With().
+		Str("foo", "bar").
+		Fields(fields).
+		Logger()
+
+	log.Log().Msg("hello world")
+
+	fmt.Println(decodeIfBinaryToString(dst.Bytes()))
+	// Output: {"foo":"bar","bar":"baz","n":1,"message":"hello world"}
+}
+
+func ExampleContext_Fields_slice() {
+	fields := []interface{}{
+		"bar", "baz",
+		"n", 1,
+	}
+
+	dst := bytes.Buffer{}
+	log := New(&dst).With().
+		Str("foo", "bar").
+		Fields(fields).
+		Logger()
+
+	log.Log().Msg("hello world")
+
+	fmt.Println(decodeIfBinaryToString(dst.Bytes()))
+	// Output: {"foo":"bar","bar":"baz","n":1,"message":"hello world"}
+}

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,8 @@ import (
 	"encoding/json"
 	"fmt"
 	"io"
+	"os"
+	"path/filepath"
 	"sort"
 	"strconv"
 	"strings"
@@ -13,122 +15,255 @@ import (
 )
 
 const (
-	cReset    = 0
-	cBold     = 1
-	cRed      = 31
-	cGreen    = 32
-	cYellow   = 33
-	cBlue     = 34
-	cMagenta  = 35
-	cCyan     = 36
-	cGray     = 37
-	cDarkGray = 90
+	colorBlack = iota + 30
+	colorRed
+	colorGreen
+	colorYellow
+	colorBlue
+	colorMagenta
+	colorCyan
+	colorWhite
+
+	colorBold     = 1
+	colorDarkGray = 90
 )
 
-var consoleBufPool = sync.Pool{
-	New: func() interface{} {
-		return bytes.NewBuffer(make([]byte, 0, 100))
-	},
-}
+var (
+	consoleBufPool = sync.Pool{
+		New: func() interface{} {
+			return bytes.NewBuffer(make([]byte, 0, 100))
+		},
+	}
+)
 
-// ConsoleWriter reads a JSON object per write operation and output an
-// optionally colored human readable version on the Out writer.
+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
+
+	// PartsExclude defines parts to not display in output.
+	PartsExclude []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))
+
+	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
+			}
+			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 {
-				buf.WriteString(value)
+				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:
-			fmt.Fprint(buf, value)
+			buf.WriteString(fv(fValue))
 		default:
-			b, err := json.Marshal(value)
+			b, err := json.Marshal(fValue)
 			if err != nil {
-				fmt.Fprintf(buf, "[error: %v]", err)
+				fmt.Fprintf(buf, colorize("[error: %v]", colorRed, w.NoColor), err)
 			} else {
-				fmt.Fprint(buf, string(b))
+				fmt.Fprint(buf, fv(b))
+			}
+		}
+
+		if i < len(fields)-1 { // Skip space for last field
+			buf.WriteByte(' ')
+		}
+	}
+}
+
+// writePart appends a formatted part to buf.
+func (w ConsoleWriter) writePart(buf *bytes.Buffer, evt map[string]interface{}, p string) {
+	var f Formatter
+
+	if w.PartsExclude != nil && len(w.PartsExclude) > 0 {
+		for _, exclude := range w.PartsExclude {
+			if exclude == p {
+				return
 			}
 		}
 	}
-	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>"
-}
-
-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 +272,138 @@ 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:
+			i, err := tt.Int64()
+			if err != nil {
+				t = tt.String()
+			} else {
+				var sec, nsec int64 = i, 0
+				switch TimeFieldFormat {
+				case TimeFormatUnixMs:
+					nsec = int64(time.Duration(i) * time.Millisecond)
+					sec = 0
+				case TimeFormatUnixMicro:
+					nsec = int64(time.Duration(i) * time.Microsecond)
+					sec = 0
+				}
+				ts := time.Unix(sec, nsec).UTC()
+				t = ts.Format(timeFormat)
+			}
+		}
+		return colorize(t, colorDarkGray, noColor)
+	}
+}
+
+func consoleDefaultFormatLevel(noColor bool) Formatter {
+	return func(i interface{}) string {
+		var l string
+		if ll, ok := i.(string); ok {
+			switch ll {
+			case LevelTraceValue:
+				l = colorize("TRC", colorMagenta, noColor)
+			case LevelDebugValue:
+				l = colorize("DBG", colorYellow, noColor)
+			case LevelInfoValue:
+				l = colorize("INF", colorGreen, noColor)
+			case LevelWarnValue:
+				l = colorize("WRN", colorRed, noColor)
+			case LevelErrorValue:
+				l = colorize(colorize("ERR", colorRed, noColor), colorBold, noColor)
+			case LevelFatalValue:
+				l = colorize(colorize("FTL", colorRed, noColor), colorBold, noColor)
+			case LevelPanicValue:
+				l = colorize(colorize("PNC", colorRed, noColor), colorBold, noColor)
+			default:
+				l = colorize("???", colorBold, noColor)
+			}
+		} else {
+			if i == nil {
+				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 {
+			if cwd, err := os.Getwd(); err == nil {
+				if rel, err := filepath.Rel(cwd, c); err == nil {
+					c = rel
+				}
+			}
+			c = colorize(c, colorBold, noColor) + colorize(" >", colorCyan, noColor)
+		}
+		return c
+	}
+}
+
+func consoleDefaultFormatMessage(i interface{}) string {
+	if i == nil {
+		return ""
+	}
+	return fmt.Sprintf("%s", i)
+}
+
+func consoleDefaultFormatFieldName(noColor bool) Formatter {
+	return func(i interface{}) string {
+		return colorize(fmt.Sprintf("%s=", i), colorCyan, 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,369 @@ 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[90m<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("Unix timestamp input format", func(t *testing.T) {
+		of := zerolog.TimeFieldFormat
+		defer func() {
+			zerolog.TimeFieldFormat = of
+		}()
+		zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
+
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, TimeFormat: time.StampMilli, NoColor: true}
+
+		_, err := w.Write([]byte(`{"time": 1234, "level": "debug", "message": "Foobar", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "Jan  1 00:20:34.000 DBG Foobar foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Unix timestamp ms input format", func(t *testing.T) {
+		of := zerolog.TimeFieldFormat
+		defer func() {
+			zerolog.TimeFieldFormat = of
+		}()
+		zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMs
+
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, TimeFormat: time.StampMilli, NoColor: true}
+
+		_, err := w.Write([]byte(`{"time": 1234567, "level": "debug", "message": "Foobar", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "Jan  1 00:20:34.567 DBG Foobar foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Unix timestamp us input format", func(t *testing.T) {
+		of := zerolog.TimeFieldFormat
+		defer func() {
+			zerolog.TimeFieldFormat = of
+		}()
+		zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMicro
+
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, TimeFormat: time.StampMicro, NoColor: true}
+
+		_, err := w.Write([]byte(`{"time": 1234567891, "level": "debug", "message": "Foobar", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "Jan  1 00:20:34.567891 DBG Foobar foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("No message field", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
+
+		_, err := w.Write([]byte(`{"level": "debug", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "<nil> DBG  foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("No level field", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
+
+		_, err := w.Write([]byte(`{"message": "Foobar", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "<nil> ??? Foobar foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Write colorized fields", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: false}
+
+		_, err := w.Write([]byte(`{"level": "warn", "message": "Foobar", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "\x1b[90m<nil>\x1b[0m \x1b[31mWRN\x1b[0m Foobar \x1b[36mfoo=\x1b[0mbar\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)
+		}
+	})
+
+	t.Run("Sets PartsExclude", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, PartsExclude: []string{"time"}}
+
+		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 := "INF Foobar\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

@@ -1,7 +1,9 @@
 package zerolog
 
 import (
+	"fmt"
 	"io/ioutil"
+	"math"
 	"net"
 	"time"
 )
@@ -16,8 +18,10 @@ func (c Context) Logger() Logger {
 	return c.l
 }
 
-// Fields is a helper function to use a map to set fields using type assertion.
-func (c Context) Fields(fields map[string]interface{}) Context {
+// Fields is a helper function to use a map or slice to set fields using type assertion.
+// Only map[string]interface{} and []interface{} are accepted. []interface{} must
+// alternate string keys and arbitrary values, and extraneous ones are ignored.
+func (c Context) Fields(fields interface{}) Context {
 	c.l.context = appendFields(c.l.context, fields)
 	return c
 }
@@ -26,7 +30,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 +59,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 +68,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
 }
 
@@ -80,6 +84,17 @@ func (c Context) Strs(key string, vals []string) Context {
 	return c
 }
 
+// Stringer adds the field key with val.String() (or null if val is nil) to the logger context.
+func (c Context) Stringer(key string, val fmt.Stringer) Context {
+	if val != nil {
+		c.l.context = enc.AppendString(enc.AppendKey(c.l.context, key), val.String())
+		return c
+	}
+
+	c.l.context = enc.AppendInterface(enc.AppendKey(c.l.context, key), nil)
+	return c
+}
+
 // Bytes adds the field key with val as a []byte to the logger context.
 func (c Context) Bytes(key string, val []byte) Context {
 	c.l.context = enc.AppendBytes(enc.AppendKey(c.l.context, key), val)
@@ -101,27 +116,53 @@ 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)
+	switch m := ErrorMarshalFunc(err).(type) {
+	case nil:
+		return c
+	case LogObjectMarshaler:
+		return c.Object(key, m)
+	case error:
+		if m == nil || isNilValue(m) {
+			return c
+		} else {
+			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 {
+		switch m := ErrorMarshalFunc(err).(type) {
+		case LogObjectMarshaler:
+			arr = arr.Object(m)
+		case error:
+			if m == nil || isNilValue(m) {
+				arr = arr.Interface(nil)
+			} else {
+				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.
@@ -327,14 +368,31 @@ func (c Context) Interface(key string, i interface{}) Context {
 	return c
 }
 
-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)
+type callerHook struct {
+	callerSkipFrameCount int
 }
 
-var ch = callerHook{}
+func newCallerHook(skipFrameCount int) callerHook {
+	return callerHook{callerSkipFrameCount: skipFrameCount}
+}
+
+func (ch callerHook) Run(e *Event, level Level, msg string) {
+	switch ch.callerSkipFrameCount {
+	case useGlobalSkipFrameCount:
+		// Extra frames to skip (added by hook infra).
+		e.caller(CallerSkipFrameCount + contextCallerSkipFrameCount)
+	default:
+		// Extra frames to skip (added by hook infra).
+		e.caller(ch.callerSkipFrameCount + contextCallerSkipFrameCount)
+	}
+}
+
+// useGlobalSkipFrameCount acts as a flag to informat callerHook.Run
+// to use the global CallerSkipFrameCount.
+const useGlobalSkipFrameCount = math.MinInt32
+
+// ch is the default caller hook using the global CallerSkipFrameCount.
+var ch = newCallerHook(useGlobalSkipFrameCount)
 
 // Caller adds the file:line of the caller with the zerolog.CallerFieldName key.
 func (c Context) Caller() Context {
@@ -342,6 +400,20 @@ func (c Context) Caller() Context {
 	return c
 }
 
+// CallerWithSkipFrameCount adds the file:line of the caller with the zerolog.CallerFieldName key.
+// The specified skipFrameCount int will override the global CallerSkipFrameCount for this context's respective logger.
+// If set to -1 the global CallerSkipFrameCount will be used.
+func (c Context) CallerWithSkipFrameCount(skipFrameCount int) Context {
+	c.l = c.l.Hook(newCallerHook(skipFrameCount))
+	return c
+}
+
+// Stack enables stack trace printing for the error passed to Err().
+func (c Context) Stack() Context {
+	c.l.stack = true
+	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)

ctx.go

@@ -2,45 +2,50 @@ package zerolog
 
 import (
 	"context"
-	"io/ioutil"
 )
 
 var disabledLogger *Logger
 
 func init() {
-	l := New(ioutil.Discard).Level(Disabled)
+	SetGlobalLevel(TraceLevel)
+	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
-// is associated, a disabled logger is returned.
+// is associated, DefaultContextLogger is returned, unless DefaultContextLogger
+// is nil, in which case a disabled logger is returned.
 func Ctx(ctx context.Context) *Logger {
 	if l, ok := ctx.Value(ctxKey{}).(*Logger); ok {
 		return l
+	} else if l = DefaultContextLogger; l != nil {
+		return l
 	}
 	return disabledLogger
 }

ctx_test.go

@@ -27,21 +27,44 @@ func TestCtx(t *testing.T) {
 	if log2 != disabledLogger {
 		t.Error("Ctx did not return the expected logger")
 	}
+
+	DefaultContextLogger = &log
+	t.Cleanup(func() { DefaultContextLogger = nil })
+	log2 = Ctx(context.Background())
+	if log2 != &log {
+		t.Error("Ctx did not return the expected logger")
+	}
 }
 
 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

@@ -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,24 +39,34 @@ type Writer struct {
 //
 // Use a diode.Writer when
 //
-//     w := 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(w)
+//     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 {
+func NewWriter(w io.Writer, size int, pollInterval 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 pollInterval > 0 {
+		dw.d = diodes.NewPoller(d,
+			diodes.WithPollingInterval(pollInterval),
+			diodes.WithPollingContext(ctx))
+	} else {
+		dw.d = diodes.NewWaiter(d,
+			diodes.WithWaiterContext(ctx))
+	}
 	go dw.poll()
 	return dw
 }
@@ -79,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")
+				}
+			})
+		})
+	}
 }

diode/internal/diodes/many_to_one.go

@@ -9,9 +9,9 @@ import (
 // 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
+	buffer     []unsafe.Pointer
 	alerter    Alerter
 }
 

diode/internal/diodes/one_to_one.go

@@ -31,9 +31,9 @@ type bucket struct {
 // 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
+	buffer     []unsafe.Pointer
 	alerter    Alerter
 }
 

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

encoder_cbor.go

@@ -14,6 +14,13 @@ var (
 	enc = cbor.Encoder{}
 )
 
+func init() {
+	// using closure to reflect the changes at runtime.
+	cbor.JSONMarshalFunc = func(v interface{}) ([]byte, error) {
+		return InterfaceMarshalFunc(v)
+	}
+}
+
 func appendJSON(dst []byte, j []byte) []byte {
 	return cbor.AppendEmbeddedJSON(dst, j)
 }

encoder_json.go

@@ -15,6 +15,13 @@ var (
 	enc = json.Encoder{}
 )
 
+func init() {
+	// using closure to reflect the changes at runtime.
+	json.JSONMarshalFunc = func(v interface{}) ([]byte, error) {
+		return InterfaceMarshalFunc(v)
+	}
+}
+
 func appendJSON(dst []byte, j []byte) []byte {
 	return append(dst, j...)
 }

event.go

@@ -5,7 +5,6 @@ import (
 	"net"
 	"os"
 	"runtime"
-	"strconv"
 	"sync"
 	"time"
 )
@@ -21,12 +20,27 @@ var eventPool = &sync.Pool{
 // 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 {
-	buf   []byte
-	w     LevelWriter
-	level Level
-	done  func(msg string)
-	ch    []Hook // hooks from context
-	h     []Hook
+	buf       []byte
+	w         LevelWriter
+	level     Level
+	done      func(msg string)
+	stack     bool   // enable error stack trace
+	ch        []Hook // hooks from context
+	skipFrame int    // The number of additional frames to skip when printing the caller.
+}
+
+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,10 +58,12 @@ 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
+	e.stack = false
+	e.skipFrame = 0
 	return e
 }
 
@@ -55,19 +71,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.
@@ -78,21 +105,33 @@ func (e *Event) Msg(msg string) {
 	if e == nil {
 		return
 	}
-	if len(e.ch) > 0 {
-		e.ch[0].Run(e, e.level, msg)
-		if len(e.ch) > 1 {
-			for _, hook := range e.ch[1:] {
-				hook.Run(e, e.level, msg)
-			}
-		}
+	e.msg(msg)
+}
+
+// Send is equivalent to calling Msg("").
+//
+// NOTICE: once this method is called, the *Event should be disposed.
+func (e *Event) Send() {
+	if e == nil {
+		return
 	}
-	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)
-			}
-		}
+	e.msg("")
+}
+
+// Msgf sends the event with formatted msg added as the message field if not empty.
+//
+// NOTICE: once this method is called, the *Event should be disposed.
+// Calling Msgf 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) {
+	for _, hook := range e.ch {
+		hook.Run(e, e.level, msg)
 	}
 	if msg != "" {
 		e.buf = enc.AppendString(enc.AppendKey(e.buf, MessageFieldName), msg)
@@ -101,23 +140,18 @@ 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 {
+// Fields is a helper function to use a map or slice to set fields using type assertion.
+// Only map[string]interface{} and []interface{} are accepted. []interface{} must
+// alternate string keys and arbitrary values, and extraneous ones are ignored.
+func (e *Event) Fields(fields interface{}) *Event {
 	if e == nil {
 		return e
 	}
@@ -133,7 +167,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
 }
 
@@ -175,15 +209,32 @@ func (e *Event) Object(key string, obj LogObjectMarshaler) *Event {
 		return e
 	}
 	e.buf = enc.AppendKey(e.buf, key)
+	if obj == nil {
+		e.buf = enc.AppendNil(e.buf)
+
+		return e
+	}
+
 	e.appendObject(obj)
 	return e
 }
 
-// Object marshals an object that implement the LogObjectMarshaler interface.
+// Func allows an anonymous func to run only if the event is enabled.
+func (e *Event) Func(f func(e *Event)) *Event {
+	if e != nil && e.Enabled() {
+		f(e)
+	}
+	return e
+}
+
+// EmbedObject marshals an object that implement the LogObjectMarshaler interface.
 func (e *Event) EmbedObject(obj LogObjectMarshaler) *Event {
 	if e == nil {
 		return e
 	}
+	if obj == nil {
+		return e
+	}
 	obj.MarshalZerologObject(e)
 	return e
 }
@@ -206,6 +257,27 @@ func (e *Event) Strs(key string, vals []string) *Event {
 	return e
 }
 
+// Stringer adds the field key with val.String() (or null if val is nil)
+// to the *Event context.
+func (e *Event) Stringer(key string, val fmt.Stringer) *Event {
+	if e == nil {
+		return e
+	}
+	e.buf = enc.AppendStringer(enc.AppendKey(e.buf, key), val)
+	return e
+}
+
+// Stringers adds the field key with vals where each individual val
+// is used as val.String() (or null if val is empty) to the *Event
+// context.
+func (e *Event) Stringers(key string, vals []fmt.Stringer) *Event {
+	if e == nil {
+		return e
+	}
+	e.buf = enc.AppendStringers(enc.AppendKey(e.buf, key), vals)
+	return e
+}
+
 // Bytes adds the field key with val as a string to the *Event context.
 //
 // Runes outside of normal ASCII ranges will be hex-encoded in the resulting
@@ -239,37 +311,89 @@ 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 {
 		return e
 	}
-	if err != nil {
-		e.buf = enc.AppendError(enc.AppendKey(e.buf, key), err)
+	switch m := ErrorMarshalFunc(err).(type) {
+	case nil:
+		return e
+	case LogObjectMarshaler:
+		return e.Object(key, m)
+	case error:
+		if m == nil || isNilValue(m) {
+			return e
+		} else {
+			return e.Str(key, m.Error())
+		}
+	case string:
+		return e.Str(key, m)
+	default:
+		return e.Interface(key, m)
 	}
-	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 {
+		switch m := ErrorMarshalFunc(err).(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.
+//
+// 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 err != nil {
-		e.buf = enc.AppendError(enc.AppendKey(e.buf, ErrorFieldName), err)
+	if e.stack && ErrorStackMarshaler != nil {
+		switch m := ErrorStackMarshaler(err).(type) {
+		case nil:
+		case LogObjectMarshaler:
+			e.Object(ErrorStackFieldName, m)
+		case error:
+			if m != nil && !isNilValue(m) {
+				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
 }
@@ -588,20 +712,36 @@ func (e *Event) Interface(key string, i interface{}) *Event {
 	return e
 }
 
+// CallerSkipFrame instructs any future Caller calls to skip the specified number of frames.
+// This includes those added via hooks from the context.
+func (e *Event) CallerSkipFrame(skip int) *Event {
+	if e == nil {
+		return e
+	}
+	e.skipFrame += skip
+	return e
+}
+
 // Caller adds the file:line of the caller with the zerolog.CallerFieldName key.
-func (e *Event) Caller() *Event {
-	return e.caller(CallerSkipFrameCount)
+// The argument skip is the number of stack frames to ascend
+// Skip If not passed, use the global variable CallerSkipFrameCount
+func (e *Event) Caller(skip ...int) *Event {
+	sk := CallerSkipFrameCount
+	if len(skip) > 0 {
+		sk = skip[0] + CallerSkipFrameCount
+	}
+	return e.caller(sk)
 }
 
 func (e *Event) caller(skip int) *Event {
 	if e == nil {
 		return e
 	}
-	_, file, line, ok := runtime.Caller(skip)
+	_, file, line, ok := runtime.Caller(skip + e.skipFrame)
 	if !ok {
 		return e
 	}
-	e.buf = enc.AppendString(enc.AppendKey(e.buf, CallerFieldName), file+":"+strconv.Itoa(line))
+	e.buf = enc.AppendString(enc.AppendKey(e.buf, CallerFieldName), CallerMarshalFunc(file, line))
 	return e
 }
 

event_test.go

@@ -0,0 +1,65 @@
+// +build !binary_log
+
+package zerolog
+
+import (
+	"bytes"
+	"errors"
+	"strings"
+	"testing"
+)
+
+type nilError struct{}
+
+func (nilError) Error() string {
+	return ""
+}
+
+func TestEvent_AnErr(t *testing.T) {
+	tests := []struct {
+		name string
+		err  error
+		want string
+	}{
+		{"nil", nil, `{}`},
+		{"error", errors.New("test"), `{"err":"test"}`},
+		{"nil interface", func() *nilError { return nil }(), `{}`},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			var buf bytes.Buffer
+			e := newEvent(levelWriterAdapter{&buf}, DebugLevel)
+			e.AnErr("err", tt.err)
+			_ = e.write()
+			if got, want := strings.TrimSpace(buf.String()), tt.want; got != want {
+				t.Errorf("Event.AnErr() = %v, want %v", got, want)
+			}
+		})
+	}
+}
+
+func TestEvent_ObjectWithNil(t *testing.T) {
+	var buf bytes.Buffer
+	e := newEvent(levelWriterAdapter{&buf}, DebugLevel)
+	_ = e.Object("obj", nil)
+	_ = e.write()
+
+	want := `{"obj":null}`
+	got := strings.TrimSpace(buf.String())
+	if got != want {
+		t.Errorf("Event.Object() = %q, want %q", got, want)
+	}
+}
+
+func TestEvent_EmbedObjectWithNil(t *testing.T) {
+	var buf bytes.Buffer
+	e := newEvent(levelWriterAdapter{&buf}, DebugLevel)
+	_ = e.EmbedObject(nil)
+	_ = e.write()
+
+	want := "{}"
+	got := strings.TrimSpace(buf.String())
+	if got != want {
+		t.Errorf("Event.EmbedObject() = %q, want %q", got, want)
+	}
+}

fields.go

@@ -1,26 +1,53 @@
 package zerolog
 
 import (
+	"encoding/json"
 	"net"
 	"sort"
 	"time"
+	"unsafe"
 )
 
-func appendFields(dst []byte, fields map[string]interface{}) []byte {
-	keys := make([]string, 0, len(fields))
-	for key := range fields {
-		keys = append(keys, key)
+func isNilValue(i interface{}) bool {
+	return (*[2]uintptr)(unsafe.Pointer(&i))[1] == 0
+}
+
+func appendFields(dst []byte, fields interface{}) []byte {
+	switch fields := fields.(type) {
+	case []interface{}:
+		if n := len(fields); n&0x1 == 1 { // odd number
+			fields = fields[:n-1]
+		}
+		dst = appendFieldList(dst, fields)
+	case map[string]interface{}:
+		keys := make([]string, 0, len(fields))
+		for key := range fields {
+			keys = append(keys, key)
+		}
+		sort.Strings(keys)
+		kv := make([]interface{}, 2)
+		for _, key := range keys {
+			kv[0], kv[1] = key, fields[key]
+			dst = appendFieldList(dst, kv)
+		}
 	}
-	sort.Strings(keys)
-	for _, key := range keys {
-		dst = enc.AppendKey(dst, key)
-		val := fields[key]
+	return dst
+}
+
+func appendFieldList(dst []byte, kvList []interface{}) []byte {
+	for i, n := 0, len(kvList); i < n; i += 2 {
+		key, val := kvList[i], kvList[i+1]
+		if key, ok := key.(string); ok {
+			dst = enc.AppendKey(dst, key)
+		} else {
+			continue
+		}
 		if val, ok := val.(LogObjectMarshaler); ok {
 			e := newEvent(nil, 0)
 			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 +56,51 @@ func appendFields(dst []byte, fields map[string]interface{}) []byte {
 		case []byte:
 			dst = enc.AppendBytes(dst, val)
 		case error:
-			dst = enc.AppendError(dst, val)
+			switch m := ErrorMarshalFunc(val).(type) {
+			case LogObjectMarshaler:
+				e := newEvent(nil, 0)
+				e.buf = e.buf[:0]
+				e.appendObject(m)
+				dst = append(dst, e.buf...)
+				putEvent(e)
+			case error:
+				if m == nil || isNilValue(m) {
+					dst = enc.AppendNil(dst)
+				} else {
+					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 {
+				switch m := ErrorMarshalFunc(err).(type) {
+				case LogObjectMarshaler:
+					e := newEvent(nil, 0)
+					e.buf = e.buf[:0]
+					e.appendObject(m)
+					dst = append(dst, e.buf...)
+					putEvent(e)
+				case error:
+					if m == nil || isNilValue(m) {
+						dst = enc.AppendNil(dst)
+					} else {
+						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:
@@ -63,37 +132,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:
@@ -134,6 +267,8 @@ func appendFields(dst []byte, fields map[string]interface{}) []byte {
 			dst = enc.AppendIPPrefix(dst, val)
 		case net.HardwareAddr:
 			dst = enc.AppendMACAddr(dst, val)
+		case json.RawMessage:
+			dst = appendJSON(dst, val)
 		default:
 			dst = enc.AppendInterface(dst, val)
 		}

globals.go

@@ -1,7 +1,25 @@
 package zerolog
 
-import "time"
-import "sync/atomic"
+import (
+	"encoding/json"
+	"strconv"
+	"sync/atomic"
+	"time"
+)
+
+const (
+	// TimeFormatUnix defines a time format that makes time fields to be
+	// serialized as Unix timestamp integers.
+	TimeFormatUnix = ""
+
+	// TimeFormatUnixMs defines a time format that makes time fields to be
+	// serialized as Unix timestamp integers in milliseconds.
+	TimeFormatUnixMs = "UNIXMS"
+
+	// TimeFormatUnixMicro defines a time format that makes time fields to be
+	// serialized as Unix timestamp integers in microseconds.
+	TimeFormatUnixMicro = "UNIXMICRO"
+)
 
 var (
 	// TimestampFieldName is the field name used for the timestamp field.
@@ -10,6 +28,26 @@ var (
 	// LevelFieldName is the field name used for the level field.
 	LevelFieldName = "level"
 
+	// LevelTraceValue is the value used for the trace level field.
+	LevelTraceValue = "trace"
+	// LevelDebugValue is the value used for the debug level field.
+	LevelDebugValue = "debug"
+	// LevelInfoValue is the value used for the info level field.
+	LevelInfoValue = "info"
+	// LevelWarnValue is the value used for the warn level field.
+	LevelWarnValue = "warn"
+	// LevelErrorValue is the value used for the error level field.
+	LevelErrorValue = "error"
+	// LevelFatalValue is the value used for the fatal level field.
+	LevelFatalValue = "fatal"
+	// LevelPanicValue is the value used for the panic level field.
+	LevelPanicValue = "panic"
+
+	// LevelFieldMarshalFunc allows customization of global level field marshaling.
+	LevelFieldMarshalFunc = func(l Level) string {
+		return l.String()
+	}
+
 	// MessageFieldName is the field name used for the message field.
 	MessageFieldName = "message"
 
@@ -22,9 +60,29 @@ var (
 	// CallerSkipFrameCount is the number of stack frames to skip to find the caller.
 	CallerSkipFrameCount = 2
 
-	// 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.
+	// CallerMarshalFunc allows customization of global caller marshaling
+	CallerMarshalFunc = func(file string, line int) string {
+		return file + ":" + strconv.Itoa(line)
+	}
+
+	// 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
+	}
+
+	// InterfaceMarshalFunc allows customization of interface marshaling.
+	// Default: "encoding/json.Marshal"
+	InterfaceMarshalFunc = json.Marshal
+
+	// TimeFieldFormat defines the time format of the Time field type. If set to
+	// TimeFormatUnix, TimeFormatUnixMs or TimeFormatUnixMicro, the time is formatted as an UNIX
+	// timestamp as integer.
 	TimeFieldFormat = time.RFC3339
 
 	// TimestampFunc defines the function called to generate a timestamp.
@@ -37,11 +95,20 @@ 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)
+
+	// DefaultContextLogger is returned from Ctx() if there is no logger associated
+	// with the context.
+	DefaultContextLogger *Logger
 )
 
 var (
-	gLevel          = new(uint32)
-	disableSampling = new(uint32)
+	gLevel          = new(int32)
+	disableSampling = new(int32)
 )
 
 // SetGlobalLevel sets the global override for log level. If this
@@ -49,23 +116,23 @@ var (
 //
 // To globally disable logs, set GlobalLevel to Disabled.
 func SetGlobalLevel(l Level) {
-	atomic.StoreUint32(gLevel, uint32(l))
+	atomic.StoreInt32(gLevel, int32(l))
 }
 
 // GlobalLevel returns the current global log level
 func GlobalLevel() Level {
-	return Level(atomic.LoadUint32(gLevel))
+	return Level(atomic.LoadInt32(gLevel))
 }
 
 // DisableSampling will disable sampling in all Loggers if true.
 func DisableSampling(v bool) {
-	var i uint32
+	var i int32
 	if v {
 		i = 1
 	}
-	atomic.StoreUint32(disableSampling, i)
+	atomic.StoreInt32(disableSampling, i)
 }
 
 func samplingDisabled() bool {
-	return atomic.LoadUint32(disableSampling) == 1
+	return atomic.LoadInt32(disableSampling) == 1
 }

go.mod

@@ -1 +1,10 @@
 module github.com/rs/zerolog
+
+go 1.15
+
+require (
+	github.com/coreos/go-systemd/v22 v22.3.2
+	github.com/pkg/errors v0.9.1
+	github.com/rs/xid v1.3.0
+	golang.org/x/tools v0.1.7
+)

go.sum

@@ -0,0 +1,34 @@
+github.com/coreos/go-systemd/v22 v22.3.2 h1:D9/bQk5vlXQFZ6Kwuu6zaiXJ9oTPe68++AzAJc1DzSI=
+github.com/coreos/go-systemd/v22 v22.3.2/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
+github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
+github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
+github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
+github.com/rs/xid v1.3.0 h1:6NjYksEUlhurdVehpc7S7dk6DAmcKv8V9gG0FsVN2U4=
+github.com/rs/xid v1.3.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
+github.com/yuin/goldmark v1.4.0/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k=
+golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
+golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
+golang.org/x/mod v0.4.2 h1:Gz96sIWK3OalVv/I/qNygP42zyoKp3xptRVCWRFEBvo=
+golang.org/x/mod v0.4.2/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
+golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
+golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s=
+golang.org/x/net v0.0.0-20210805182204-aaa1db679c0d/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y=
+golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sync v0.0.0-20210220032951-036812b2e83c/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
+golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20210423082822-04245dca01da/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20210809222454-d867a43fc93e h1:WUoyKPm6nCo1BnNUvPGnFG3T5DUVem42yDJZZ4CNxMA=
+golang.org/x/sys v0.0.0-20210809222454-d867a43fc93e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=
+golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
+golang.org/x/text v0.3.6/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ=
+golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
+golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
+golang.org/x/tools v0.1.7 h1:6j8CgantCy3yc8JGBqkDLMKWqZ0RDU2g1HVgacojGWQ=
+golang.org/x/tools v0.1.7/go.mod h1:LGqMHiF4EqQNHR1JncWGqT5BVaXmza+X+BDGol+dOxo=
+golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1 h1:go1bK/D/BFZV2I8cIQd1NKEZ+0owSTG1fDTci4IqFcE=
+golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=

go112.go

@@ -0,0 +1,7 @@
+// +build go1.12
+
+package zerolog
+
+// Since go 1.12, some auto generated init functions are hidden from
+// runtime.Caller.
+const contextCallerSkipFrameCount = 2

hlog/hlog.go

@@ -3,14 +3,13 @@ package hlog
 
 import (
 	"context"
-	"net"
 	"net/http"
 	"time"
 
 	"github.com/rs/xid"
 	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/hlog/internal/mutil"
 	"github.com/rs/zerolog/log"
-	"github.com/zenazn/goji/web/mutil"
 )
 
 // FromRequest gets the logger in the request's context.
@@ -79,10 +78,10 @@ func RequestHandler(fieldKey string) func(next http.Handler) http.Handler {
 func RemoteAddrHandler(fieldKey string) func(next http.Handler) http.Handler {
 	return func(next http.Handler) http.Handler {
 		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
-			if host, _, err := net.SplitHostPort(r.RemoteAddr); err == nil {
+			if r.RemoteAddr != "" {
 				log := zerolog.Ctx(r.Context())
 				log.UpdateContext(func(c zerolog.Context) zerolog.Context {
-					return c.Str(fieldKey, host)
+					return c.Str(fieldKey, r.RemoteAddr)
 				})
 			}
 			next.ServeHTTP(w, r)
@@ -129,10 +128,20 @@ 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
 }
 
+// CtxWithID adds the given xid.ID to the context
+func CtxWithID(ctx context.Context, id xid.ID) context.Context {
+	return context.WithValue(ctx, idKey{}, id)
+}
+
 // RequestIDHandler returns a handler setting a unique id to the request which can
 // be gathered using IDFromRequest(req). This generated id is added as a field to the
 // logger using the passed fieldKey as field name. The id is also added as a response
@@ -149,7 +158,7 @@ func RequestIDHandler(fieldKey, headerName string) func(next http.Handler) http.
 			id, ok := IDFromRequest(r)
 			if !ok {
 				id = xid.New()
-				ctx = context.WithValue(ctx, idKey{}, id)
+				ctx = CtxWithID(ctx, id)
 				r = r.WithContext(ctx)
 			}
 			if fieldKey != "" {
@@ -166,6 +175,22 @@ func RequestIDHandler(fieldKey, headerName string) func(next http.Handler) http.
 	}
 }
 
+// CustomHeaderHandler adds given header from request's header as a field to
+// the context's logger using fieldKey as field key.
+func CustomHeaderHandler(fieldKey, header string) func(next http.Handler) http.Handler {
+	return func(next http.Handler) http.Handler {
+		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+			if val := r.Header.Get(header); val != "" {
+				log := zerolog.Ctx(r.Context())
+				log.UpdateContext(func(c zerolog.Context) zerolog.Context {
+					return c.Str(fieldKey, val)
+				})
+			}
+			next.ServeHTTP(w, r)
+		})
+	}
+}
+
 // AccessHandler returns a handler that call f after each request.
 func AccessHandler(f func(r *http.Request, status, size int, duration time.Duration)) func(next http.Handler) http.Handler {
 	return func(next http.Handler) http.Handler {

hlog/hlog_test.go

@@ -4,16 +4,16 @@ package hlog
 
 import (
 	"bytes"
+	"context"
 	"fmt"
 	"io/ioutil"
 	"net/http"
+	"net/http/httptest"
 	"net/url"
+	"reflect"
 	"testing"
 
-	"reflect"
-
-	"net/http/httptest"
-
+	"github.com/rs/xid"
 	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/internal/cbor"
 )
@@ -100,7 +100,7 @@ func TestRemoteAddrHandler(t *testing.T) {
 	}))
 	h = NewHandler(zerolog.New(out))(h)
 	h.ServeHTTP(nil, r)
-	if want, got := `{"ip":"1.2.3.4"}`+"\n", decodeIfBinary(out); want != got {
+	if want, got := `{"ip":"1.2.3.4:1234"}`+"\n", decodeIfBinary(out); want != got {
 		t.Errorf("Invalid log output, got: %s, want: %s", got, want)
 	}
 }
@@ -116,7 +116,7 @@ func TestRemoteAddrHandlerIPv6(t *testing.T) {
 	}))
 	h = NewHandler(zerolog.New(out))(h)
 	h.ServeHTTP(nil, r)
-	if want, got := `{"ip":"2001:db8:a0b:12f0::1"}`+"\n", decodeIfBinary(out); want != got {
+	if want, got := `{"ip":"[2001:db8:a0b:12f0::1]:1234"}`+"\n", decodeIfBinary(out); want != got {
 		t.Errorf("Invalid log output, got: %s, want: %s", got, want)
 	}
 }
@@ -182,6 +182,24 @@ func TestRequestIDHandler(t *testing.T) {
 	h.ServeHTTP(httptest.NewRecorder(), r)
 }
 
+func TestCustomHeaderHandler(t *testing.T) {
+	out := &bytes.Buffer{}
+	r := &http.Request{
+		Header: http.Header{
+			"X-Request-Id": []string{"514bbe5bb5251c92bd07a9846f4a1ab6"},
+		},
+	}
+	h := CustomHeaderHandler("reqID", "X-Request-Id")(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		l := FromRequest(r)
+		l.Log().Msg("")
+	}))
+	h = NewHandler(zerolog.New(out))(h)
+	h.ServeHTTP(nil, r)
+	if want, got := `{"reqID":"514bbe5bb5251c92bd07a9846f4a1ab6"}`+"\n", decodeIfBinary(out); want != got {
+		t.Errorf("Invalid log output, got: %s, want: %s", got, want)
+	}
+}
+
 func TestCombinedHandlers(t *testing.T) {
 	out := &bytes.Buffer{}
 	r := &http.Request{
@@ -244,3 +262,16 @@ func BenchmarkDataRace(b *testing.B) {
 		}
 	})
 }
+
+func TestCtxWithID(t *testing.T) {
+	ctx := context.Background()
+
+	id, _ := xid.FromString(`c0umremcie6smuu506pg`)
+
+	want := context.Background()
+	want = context.WithValue(want, idKey{}, id)
+
+	if got := CtxWithID(ctx, id); !reflect.DeepEqual(got, want) {
+		t.Errorf("CtxWithID() = %v, want %v", got, want)
+	}
+}

hlog/internal/mutil/LICENSE

@@ -0,0 +1,20 @@
+Copyright (c) 2014, 2015, 2016 Carl Jackson (carl@avtok.com)
+
+MIT License
+
+Permission is hereby granted, free of charge, to any person obtaining a copy of
+this software and associated documentation files (the "Software"), to deal in
+the Software without restriction, including without limitation the rights to
+use, copy, modify, merge, publish, distribute, sublicense, and/or sell copies of
+the Software, and to permit persons to whom the Software is furnished to do so,
+subject to the following conditions:
+
+The above copyright notice and this permission notice shall be included in all
+copies or substantial portions of the Software.
+
+THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS
+FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR
+COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER
+IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN
+CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.

hlog/internal/mutil/mutil.go

@@ -0,0 +1,6 @@
+// Package mutil contains various functions that are helpful when writing http
+// middleware.
+//
+// It has been vendored from Goji v1.0, with the exception of the code for Go 1.8:
+// https://github.com/zenazn/goji/
+package mutil

hlog/internal/mutil/writer_proxy.go

@@ -0,0 +1,154 @@
+package mutil
+
+import (
+	"bufio"
+	"io"
+	"net"
+	"net/http"
+)
+
+// WriterProxy is a proxy around an http.ResponseWriter that allows you to hook
+// into various parts of the response process.
+type WriterProxy interface {
+	http.ResponseWriter
+	// Status returns the HTTP status of the request, or 0 if one has not
+	// yet been sent.
+	Status() int
+	// BytesWritten returns the total number of bytes sent to the client.
+	BytesWritten() int
+	// Tee causes the response body to be written to the given io.Writer in
+	// addition to proxying the writes through. Only one io.Writer can be
+	// tee'd to at once: setting a second one will overwrite the first.
+	// Writes will be sent to the proxy before being written to this
+	// io.Writer. It is illegal for the tee'd writer to be modified
+	// concurrently with writes.
+	Tee(io.Writer)
+	// Unwrap returns the original proxied target.
+	Unwrap() http.ResponseWriter
+}
+
+// WrapWriter wraps an http.ResponseWriter, returning a proxy that allows you to
+// hook into various parts of the response process.
+func WrapWriter(w http.ResponseWriter) WriterProxy {
+	_, cn := w.(http.CloseNotifier)
+	_, fl := w.(http.Flusher)
+	_, hj := w.(http.Hijacker)
+	_, rf := w.(io.ReaderFrom)
+
+	bw := basicWriter{ResponseWriter: w}
+	if cn && fl && hj && rf {
+		return &fancyWriter{bw}
+	}
+	if fl {
+		return &flushWriter{bw}
+	}
+	return &bw
+}
+
+// basicWriter wraps a http.ResponseWriter that implements the minimal
+// http.ResponseWriter interface.
+type basicWriter struct {
+	http.ResponseWriter
+	wroteHeader bool
+	code        int
+	bytes       int
+	tee         io.Writer
+}
+
+func (b *basicWriter) WriteHeader(code int) {
+	if !b.wroteHeader {
+		b.code = code
+		b.wroteHeader = true
+		b.ResponseWriter.WriteHeader(code)
+	}
+}
+
+func (b *basicWriter) Write(buf []byte) (int, error) {
+	b.WriteHeader(http.StatusOK)
+	n, err := b.ResponseWriter.Write(buf)
+	if b.tee != nil {
+		_, err2 := b.tee.Write(buf[:n])
+		// Prefer errors generated by the proxied writer.
+		if err == nil {
+			err = err2
+		}
+	}
+	b.bytes += n
+	return n, err
+}
+
+func (b *basicWriter) maybeWriteHeader() {
+	if !b.wroteHeader {
+		b.WriteHeader(http.StatusOK)
+	}
+}
+
+func (b *basicWriter) Status() int {
+	return b.code
+}
+
+func (b *basicWriter) BytesWritten() int {
+	return b.bytes
+}
+
+func (b *basicWriter) Tee(w io.Writer) {
+	b.tee = w
+}
+
+func (b *basicWriter) Unwrap() http.ResponseWriter {
+	return b.ResponseWriter
+}
+
+// fancyWriter is a writer that additionally satisfies http.CloseNotifier,
+// http.Flusher, http.Hijacker, and io.ReaderFrom. It exists for the common case
+// of wrapping the http.ResponseWriter that package http gives you, in order to
+// make the proxied object support the full method set of the proxied object.
+type fancyWriter struct {
+	basicWriter
+}
+
+func (f *fancyWriter) CloseNotify() <-chan bool {
+	cn := f.basicWriter.ResponseWriter.(http.CloseNotifier)
+	return cn.CloseNotify()
+}
+
+func (f *fancyWriter) Flush() {
+	fl := f.basicWriter.ResponseWriter.(http.Flusher)
+	fl.Flush()
+}
+
+func (f *fancyWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) {
+	hj := f.basicWriter.ResponseWriter.(http.Hijacker)
+	return hj.Hijack()
+}
+
+func (f *fancyWriter) ReadFrom(r io.Reader) (int64, error) {
+	if f.basicWriter.tee != nil {
+		n, err := io.Copy(&f.basicWriter, r)
+		f.bytes += int(n)
+		return n, err
+	}
+	rf := f.basicWriter.ResponseWriter.(io.ReaderFrom)
+	f.basicWriter.maybeWriteHeader()
+
+	n, err := rf.ReadFrom(r)
+	f.bytes += int(n)
+	return n, err
+}
+
+type flushWriter struct {
+	basicWriter
+}
+
+func (f *flushWriter) Flush() {
+	fl := f.basicWriter.ResponseWriter.(http.Flusher)
+	fl.Flush()
+}
+
+var (
+	_ http.CloseNotifier = &fancyWriter{}
+	_ http.Flusher       = &fancyWriter{}
+	_ http.Hijacker      = &fancyWriter{}
+	_ io.ReaderFrom      = &fancyWriter{}
+	_ http.Flusher       = &flushWriter{}
+)

hook.go

@@ -6,14 +6,27 @@ 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
+	NoLevelHook, TraceHook, DebugHook, InfoHook, WarnHook, ErrorHook, FatalHook, PanicHook Hook
 }
 
 // Run implements the Hook interface.
 func (h LevelHook) Run(e *Event, level Level, message string) {
 	switch level {
+	case TraceLevel:
+		if h.TraceHook != nil {
+			h.TraceHook.Run(e, level, message)
+		}
 	case DebugLevel:
 		if h.DebugHook != nil {
 			h.DebugHook.Run(e, level, message)

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

@@ -1,5 +1,13 @@
 package cbor
 
+// JSONMarshalFunc is used to marshal interface to JSON encoded byte slice.
+// Making it package level instead of embedded in Encoder brings
+// some extra efforts at importing, but avoids value copy when the functions
+// of Encoder being invoked.
+// DO REMEMBER to set this variable at importing, or
+// you might get a nil pointer dereference panic at runtime.
+var JSONMarshalFunc func(v interface{}) ([]byte, error)
+
 type Encoder struct{}
 
 // AppendKey adds a key (string) to the binary encoded log message
@@ -9,37 +17,3 @@ func (e Encoder) AppendKey(dst []byte, key string) []byte {
 	}
 	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/cbor/string.go

@@ -1,5 +1,7 @@
 package cbor
 
+import "fmt"
+
 // AppendStrings encodes and adds an array of strings to the dst byte array.
 func (e Encoder) AppendStrings(dst []byte, vals []string) []byte {
 	major := majorTypeArray
@@ -30,6 +32,31 @@ func (Encoder) AppendString(dst []byte, s string) []byte {
 	return append(dst, s...)
 }
 
+// AppendStringers encodes and adds an array of Stringer values
+// to the dst byte array.
+func (e Encoder) AppendStringers(dst []byte, vals []fmt.Stringer) []byte {
+	if len(vals) == 0 {
+		return e.AppendArrayEnd(e.AppendArrayStart(dst))
+	}
+	dst = e.AppendArrayStart(dst)
+	dst = e.AppendStringer(dst, vals[0])
+	if len(vals) > 1 {
+		for _, val := range vals[1:] {
+			dst = e.AppendStringer(dst, val)
+		}
+	}
+	return e.AppendArrayEnd(dst)
+}
+
+// AppendStringer encodes and adds the Stringer value to the dst
+// byte array.
+func (e Encoder) AppendStringer(dst []byte, val fmt.Stringer) []byte {
+	if val == nil {
+		return e.AppendNil(dst)
+	}
+	return e.AppendString(dst, val.String())
+}
+
 // AppendBytes encodes and adds an array of bytes to the dst byte array.
 func (Encoder) AppendBytes(dst, s []byte) []byte {
 	major := majorTypeByteString

internal/cbor/types.go

@@ -1,7 +1,6 @@
 package cbor
 
 import (
-	"encoding/json"
 	"fmt"
 	"math"
 	"net"
@@ -24,9 +23,9 @@ func (Encoder) AppendEndMarker(dst []byte) []byte {
 
 // AppendObjectData takes an object in form of a byte array and appends to dst.
 func (Encoder) AppendObjectData(dst []byte, o []byte) []byte {
-        // BeginMarker is present in the dst, which
-        // should not be copied when appending to existing data.
-        return append(dst, o[1:]...)
+	// BeginMarker is present in the dst, which
+	// should not be copied when appending to existing data.
+	return append(dst, o[1:]...)
 }
 
 // AppendArrayStart adds markers to indicate the start of an array.
@@ -432,7 +431,7 @@ func (e Encoder) AppendFloats64(dst []byte, vals []float64) []byte {
 
 // AppendInterface takes an arbitrary object and converts it to JSON and embeds it dst.
 func (e Encoder) AppendInterface(dst []byte, i interface{}) []byte {
-	marshaled, err := json.Marshal(i)
+	marshaled, err := JSONMarshalFunc(i)
 	if err != nil {
 		return e.AppendString(dst, fmt.Sprintf("marshaling error: %v", err))
 	}

internal/cbor/types_64_test.go

@@ -0,0 +1,34 @@
+// +build !386
+
+package cbor
+
+import (
+	"encoding/hex"
+	"testing"
+)
+
+var enc2 = Encoder{}
+
+var integerTestCases_64bit = []struct {
+	val    int
+	binary string
+}{
+	// Value in 8 bytes.
+	{0xabcd100000000, "\x1b\x00\x0a\xbc\xd1\x00\x00\x00\x00"},
+	{1000000000000, "\x1b\x00\x00\x00\xe8\xd4\xa5\x10\x00"},
+	// Value in 8 bytes.
+	{-0xabcd100000001, "\x3b\x00\x0a\xbc\xd1\x00\x00\x00\x00"},
+	{-1000000000001, "\x3b\x00\x00\x00\xe8\xd4\xa5\x10\x00"},
+}
+
+func TestAppendInt_64bit(t *testing.T) {
+	for _, tc := range integerTestCases_64bit {
+		s := enc2.AppendInt([]byte{}, tc.val)
+		got := string(s)
+		if got != tc.binary {
+			t.Errorf("AppendInt(0x%x)=0x%s, want: 0x%s",
+				tc.val, hex.EncodeToString(s),
+				hex.EncodeToString([]byte(tc.binary)))
+		}
+	}
+}

internal/cbor/types_test.go

@@ -88,11 +88,8 @@ var integerTestCases = []struct {
 	{0xFFFF, "\x19\xff\xff"},
 	// Value in 4 bytes.
 	{0x10000, "\x1a\x00\x01\x00\x00"},
-	{0xFFFFFFFE, "\x1a\xff\xff\xff\xfe"},
+	{0x7FFFFFFE, "\x1a\x7f\xff\xff\xfe"},
 	{1000000, "\x1a\x00\x0f\x42\x40"},
-	// Value in 8 bytes.
-	{0xabcd100000000, "\x1b\x00\x0a\xbc\xd1\x00\x00\x00\x00"},
-	{1000000000000, "\x1b\x00\x00\x00\xe8\xd4\xa5\x10\x00"},
 	// Negative number test cases.
 	// Value included in the type.
 	{-1, "\x20"},
@@ -116,11 +113,9 @@ var integerTestCases = []struct {
 	{-1000, "\x39\x03\xe7"},
 	// Value in 4 bytes.
 	{-0x10001, "\x3a\x00\x01\x00\x00"},
-	{-0xFFFFFFFE, "\x3a\xff\xff\xff\xfd"},
+	{-0x7FFFFFFE, "\x3a\x7f\xff\xff\xfd"},
 	{-1000000, "\x3a\x00\x0f\x42\x3f"},
-	// Value in 8 bytes.
-	{-0xabcd100000001, "\x3b\x00\x0a\xbc\xd1\x00\x00\x00\x00"},
-	{-1000000000001, "\x3b\x00\x00\x00\xe8\xd4\xa5\x10\x00"},
+
 }
 
 func TestAppendInt(t *testing.T) {

internal/json/base.go

@@ -1,46 +1,19 @@
 package json
 
+// JSONMarshalFunc is used to marshal interface to JSON encoded byte slice.
+// Making it package level instead of embedded in Encoder brings
+// some extra efforts at importing, but avoids value copy when the functions
+// of Encoder being invoked.
+// DO REMEMBER to set this variable at importing, or
+// you might get a nil pointer dereference panic at runtime.
+var JSONMarshalFunc func(v interface{}) ([]byte, error)
+
 type Encoder struct{}
 
 // AppendKey appends a new key to the output JSON.
 func (e Encoder) AppendKey(dst []byte, key string) []byte {
-	if len(dst) > 1 && dst[len(dst)-1] != '{' {
+	if dst[len(dst)-1] != '{' {
 		dst = append(dst, ',')
 	}
-	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
+	return append(e.AppendString(dst, key), ':')
 }

internal/json/string.go

@@ -1,6 +1,9 @@
 package json
 
-import "unicode/utf8"
+import (
+	"fmt"
+	"unicode/utf8"
+)
 
 const hex = "0123456789abcdef"
 
@@ -60,7 +63,32 @@ func (Encoder) AppendString(dst []byte, s string) []byte {
 	return append(dst, '"')
 }
 
-// appendStringComplex is used by appendString to take over an in
+// AppendStringers encodes the provided Stringer list to json and
+// appends the encoded Stringer list to the input byte slice.
+func (e Encoder) AppendStringers(dst []byte, vals []fmt.Stringer) []byte {
+	if len(vals) == 0 {
+		return append(dst, '[', ']')
+	}
+	dst = append(dst, '[')
+	dst = e.AppendStringer(dst, vals[0])
+	if len(vals) > 1 {
+		for _, val := range vals[1:] {
+			dst = e.AppendStringer(append(dst, ','), val)
+		}
+	}
+	return append(dst, ']')
+}
+
+// AppendStringer encodes the input Stringer to json and appends the
+// encoded Stringer value to the input byte slice.
+func (e Encoder) AppendStringer(dst []byte, val fmt.Stringer) []byte {
+	if val == nil {
+		return e.AppendInterface(dst, nil)
+	}
+	return e.AppendString(dst, val.String())
+}
+
+//// appendStringComplex is used by appendString to take over an in
 // progress JSON string encoding that encountered a character that needs
 // to be encoded.
 func appendStringComplex(dst []byte, s string, i int) []byte {

internal/json/time.go

@@ -5,11 +5,23 @@ import (
 	"time"
 )
 
+const (
+	// Import from zerolog/global.go
+	timeFormatUnix   = ""
+	timeFormatUnixMs = "UNIXMS"
+	timeFormatUnixMicro = "UNIXMICRO"
+)
+
 // AppendTime formats the input time with the given format
 // and appends the encoded string to the input byte slice.
 func (e Encoder) AppendTime(dst []byte, t time.Time, format string) []byte {
-	if format == "" {
+	switch format {
+	case timeFormatUnix:
 		return e.AppendInt64(dst, t.Unix())
+	case timeFormatUnixMs:
+		return e.AppendInt64(dst, t.UnixNano()/1000000)
+	case timeFormatUnixMicro:
+		return e.AppendInt64(dst, t.UnixNano()/1000)
 	}
 	return append(t.AppendFormat(append(dst, '"'), format), '"')
 }
@@ -17,8 +29,11 @@ func (e Encoder) AppendTime(dst []byte, t time.Time, format string) []byte {
 // AppendTimes converts the input times with the given format
 // and appends the encoded string list to the input byte slice.
 func (Encoder) AppendTimes(dst []byte, vals []time.Time, format string) []byte {
-	if format == "" {
+	switch format {
+	case timeFormatUnix:
 		return appendUnixTimes(dst, vals)
+	case timeFormatUnixMs:
+		return appendUnixMsTimes(dst, vals)
 	}
 	if len(vals) == 0 {
 		return append(dst, '[', ']')
@@ -49,6 +64,21 @@ func appendUnixTimes(dst []byte, vals []time.Time) []byte {
 	return dst
 }
 
+func appendUnixMsTimes(dst []byte, vals []time.Time) []byte {
+	if len(vals) == 0 {
+		return append(dst, '[', ']')
+	}
+	dst = append(dst, '[')
+	dst = strconv.AppendInt(dst, vals[0].UnixNano()/1000000, 10)
+	if len(vals) > 1 {
+		for _, t := range vals[1:] {
+			dst = strconv.AppendInt(append(dst, ','), t.UnixNano()/1000000, 10)
+		}
+	}
+	dst = append(dst, ']')
+	return dst
+}
+
 // AppendDuration formats the input duration with the given unit & format
 // and appends the encoded string to the input byte slice.
 func (e Encoder) AppendDuration(dst []byte, d time.Duration, unit time.Duration, useInt bool) []byte {

internal/json/types.go

@@ -1,7 +1,6 @@
 package json
 
 import (
-	"encoding/json"
 	"fmt"
 	"math"
 	"net"
@@ -350,7 +349,7 @@ func (Encoder) AppendFloats64(dst []byte, vals []float64) []byte {
 		return append(dst, '[', ']')
 	}
 	dst = append(dst, '[')
-	dst = appendFloat(dst, vals[0], 32)
+	dst = appendFloat(dst, vals[0], 64)
 	if len(vals) > 1 {
 		for _, val := range vals[1:] {
 			dst = appendFloat(append(dst, ','), val, 64)
@@ -363,7 +362,7 @@ func (Encoder) AppendFloats64(dst []byte, vals []float64) []byte {
 // AppendInterface marshals the input interface to a string and
 // appends the encoded string to the input byte slice.
 func (e Encoder) AppendInterface(dst []byte, i interface{}) []byte {
-	marshaled, err := json.Marshal(i)
+	marshaled, err := JSONMarshalFunc(i)
 	if err != nil {
 		return e.AppendString(dst, fmt.Sprintf("marshaling error: %v", err))
 	}
@@ -373,12 +372,16 @@ func (e Encoder) AppendInterface(dst []byte, i interface{}) []byte {
 // AppendObjectData takes in an object that is already in a byte array
 // and adds it to the dst.
 func (Encoder) AppendObjectData(dst []byte, o []byte) []byte {
-	// Two conditions we want to put a ',' between existing content and
-	// new content:
-	// 1. new content starts with '{' - which shd be dropped   OR
-	// 2. existing content has already other fields
+	// Three conditions apply here:
+	// 1. new content starts with '{' - which should be dropped   OR
+	// 2. new content starts with '{' - which should be replaced with ','
+	//    to separate with existing content OR
+	// 3. existing content has already other fields
 	if o[0] == '{' {
-		o[0] = ','
+		if len(dst) > 1 {
+			dst = append(dst, ',')
+		}
+		o = o[1:]
 	} else if len(dst) > 1 {
 		dst = append(dst, ',')
 	}

internal/json/types_test.go

@@ -165,3 +165,23 @@ func Test_appendMac(t *testing.T) {
 		})
 	}
 }
+
+func Test_appendObjectData(t *testing.T) {
+	tests := []struct {
+		dst  []byte
+		obj  []byte
+		want []byte
+	}{
+		{[]byte{}, []byte(`{"foo":"bar"}`), []byte(`"foo":"bar"}`)},
+		{[]byte(`{"qux":"quz"`), []byte(`{"foo":"bar"}`), []byte(`{"qux":"quz","foo":"bar"}`)},
+		{[]byte{}, []byte(`"foo":"bar"`), []byte(`"foo":"bar"`)},
+		{[]byte(`{"qux":"quz"`), []byte(`"foo":"bar"`), []byte(`{"qux":"quz","foo":"bar"`)},
+	}
+	for _, tt := range tests {
+		t.Run("ObjectData", func(t *testing.T) {
+			if got := enc.AppendObjectData(tt.dst, tt.obj); !reflect.DeepEqual(got, tt.want) {
+				t.Errorf("appendObjectData() = %s, want %s", got, tt.want)
+			}
+		})
+	}
+}

journald/journald.go

@@ -20,11 +20,12 @@ import (
 	"bytes"
 	"encoding/json"
 	"fmt"
-	"github.com/coreos/go-systemd/journal"
-	"github.com/rs/zerolog"
-	"github.com/rs/zerolog/internal/cbor"
 	"io"
 	"strings"
+
+	"github.com/coreos/go-systemd/v22/journal"
+	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/internal/cbor"
 )
 
 const defaultJournalDPrio = journal.PriNotice
@@ -47,6 +48,8 @@ func levelToJPrio(zLevel string) journal.Priority {
 	lvl, _ := zerolog.ParseLevel(zLevel)
 
 	switch lvl {
+	case zerolog.TraceLevel:
+		return journal.PriDebug
 	case zerolog.DebugLevel:
 		return journal.PriDebug
 	case zerolog.InfoLevel:
@@ -67,10 +70,12 @@ func levelToJPrio(zLevel string) journal.Priority {
 
 func (w journalWriter) Write(p []byte) (n int, err error) {
 	if !journal.Enabled() {
-		err = fmt.Errorf("Cannot connect to journalD!!")
+		err = fmt.Errorf("cannot connect to journalD")
 		return
 	}
+
 	var event map[string]interface{}
+	origPLen := len(p)
 	p = cbor.DecodeIfBinaryToBytes(p)
 	d := json.NewDecoder(bytes.NewReader(p))
 	d.UseNumber()
@@ -111,5 +116,10 @@ func (w journalWriter) Write(p []byte) (n int, err error) {
 	}
 	args["JSON"] = string(p)
 	err = journal.Send(msg, jPrio, args)
+
+	if err == nil {
+		n = origPLen
+	}
+
 	return
 }

journald/journald_test.go

@@ -1,9 +1,15 @@
-// +build !windows
+// +build linux
 
 package journald_test
 
-import "github.com/rs/zerolog"
-import "github.com/rs/zerolog/journald"
+import (
+	"bytes"
+	"io"
+	"testing"
+
+	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/journald"
+)
 
 func ExampleNewJournalDWriter() {
 	log := zerolog.New(journald.NewJournalDWriter())
@@ -42,3 +48,39 @@ Thu 2018-04-26 22:30:20.768136 PDT [s=3284d695bde946e4b5017c77a399237f;i=329f0;b
     _PID=27103
     _SOURCE_REALTIME_TIMESTAMP=1524807020768136
 */
+
+func TestWriteReturnsNoOfWrittenBytes(t *testing.T) {
+	input := []byte(`{"level":"info","time":1570912626,"message":"Starting..."}`)
+	wr := journald.NewJournalDWriter()
+	want := len(input)
+	got, err := wr.Write(input)
+
+	if err != nil {
+		t.Errorf("Unexpected error %v", err)
+	}
+
+	if want != got {
+		t.Errorf("Expected %d bytes to be written got %d", want, got)
+	}
+}
+
+func TestMultiWrite(t *testing.T) {
+	var (
+		w1 = new(bytes.Buffer)
+		w2 = new(bytes.Buffer)
+		w3 = journald.NewJournalDWriter()
+	)
+
+	zerolog.ErrorHandler = func(err error) {
+		if err == io.ErrShortWrite {
+			t.Errorf("Unexpected ShortWriteError")
+			t.FailNow()
+		}
+	}
+
+	log := zerolog.New(io.MultiWriter(w1, w2, w3)).With().Logger()
+
+	for i := 0; i < 10; i++ {
+		log.Info().Msg("Tick!")
+	}
+}

log.go

@@ -94,8 +94,8 @@
 //            Msg("dup")
 //     // Output: {"level":"info","time":1494567715,"time":1494567715,"message":"dup"}
 //
-// However, it’s not a big deal though as JSON accepts dup keys,
-// the last one prevails.
+// In this case, many consumers will take the last value,
+// but this is not guaranteed; check yours if in doubt.
 package zerolog
 
 import (
@@ -107,7 +107,7 @@ import (
 )
 
 // Level defines log levels.
-type Level uint8
+type Level int8
 
 const (
 	// DebugLevel defines debug log level.
@@ -126,53 +126,72 @@ const (
 	NoLevel
 	// Disabled disables the logger.
 	Disabled
+
+	// TraceLevel defines trace log level.
+	TraceLevel Level = -1
+	// Values less than TraceLevel are handled as numbers.
 )
 
 func (l Level) String() string {
 	switch l {
+	case TraceLevel:
+		return LevelTraceValue
 	case DebugLevel:
-		return "debug"
+		return LevelDebugValue
 	case InfoLevel:
-		return "info"
+		return LevelInfoValue
 	case WarnLevel:
-		return "warn"
+		return LevelWarnValue
 	case ErrorLevel:
-		return "error"
+		return LevelErrorValue
 	case FatalLevel:
-		return "fatal"
+		return LevelFatalValue
 	case PanicLevel:
-		return "panic"
+		return LevelPanicValue
+	case Disabled:
+		return "disabled"
 	case NoLevel:
 		return ""
 	}
-	return ""
+	return strconv.Itoa(int(l))
 }
 
 // ParseLevel converts a level string into a zerolog Level value.
 // returns an error if the input string does not match known values.
 func ParseLevel(levelStr string) (Level, error) {
 	switch levelStr {
-	case DebugLevel.String():
+	case LevelFieldMarshalFunc(TraceLevel):
+		return TraceLevel, nil
+	case LevelFieldMarshalFunc(DebugLevel):
 		return DebugLevel, nil
-	case InfoLevel.String():
+	case LevelFieldMarshalFunc(InfoLevel):
 		return InfoLevel, nil
-	case WarnLevel.String():
+	case LevelFieldMarshalFunc(WarnLevel):
 		return WarnLevel, nil
-	case ErrorLevel.String():
+	case LevelFieldMarshalFunc(ErrorLevel):
 		return ErrorLevel, nil
-	case FatalLevel.String():
+	case LevelFieldMarshalFunc(FatalLevel):
 		return FatalLevel, nil
-	case PanicLevel.String():
+	case LevelFieldMarshalFunc(PanicLevel):
 		return PanicLevel, nil
-	case NoLevel.String():
+	case LevelFieldMarshalFunc(Disabled):
+		return Disabled, nil
+	case LevelFieldMarshalFunc(NoLevel):
 		return NoLevel, nil
 	}
-	return NoLevel, fmt.Errorf("Unknown Level String: '%s', defaulting to NoLevel", levelStr)
+	i, err := strconv.Atoi(levelStr)
+	if err != nil {
+		return NoLevel, fmt.Errorf("Unknown Level String: '%s', defaulting to NoLevel", levelStr)
+	}
+	if i > 127 || i < -128 {
+		return NoLevel, fmt.Errorf("Out-Of-Bounds Level: '%d', defaulting to NoLevel", i)
+	}
+	return Level(i), nil
 }
 
 // A Logger represents an active logging object that generates lines
 // of JSON output to an io.Writer. Each logging operation makes a single
-// call to the Writer's Write method. There is no guaranty on access
+// call to the Writer's Write method. There is no guarantee on access
 // serialization to the Writer. If your Writer is not thread safe,
 // you may consider a sync wrapper.
 type Logger struct {
@@ -181,6 +200,7 @@ type Logger struct {
 	sampler Sampler
 	context []byte
 	hooks   []Hook
+	stack   bool
 }
 
 // New creates a root logger with given output writer. If the output writer implements
@@ -188,7 +208,7 @@ type Logger struct {
 // one.
 //
 // Each logging operation makes a single call to the Writer's Write method. There is no
-// guaranty on access serialization to the Writer. If your Writer is not thread safe,
+// guarantee on access serialization to the Writer. If your Writer is not thread safe,
 // you may consider using sync wrapper.
 func New(w io.Writer) Logger {
 	if w == nil {
@@ -198,7 +218,7 @@ func New(w io.Writer) Logger {
 	if !ok {
 		lw = levelWriterAdapter{w}
 	}
-	return Logger{w: lw}
+	return Logger{w: lw, level: TraceLevel}
 }
 
 // Nop returns a disabled logger for which all operation are no-op.
@@ -211,6 +231,7 @@ func (l Logger) Output(w io.Writer) Logger {
 	l2 := New(w)
 	l2.level = l.level
 	l2.sampler = l.sampler
+	l2.stack = l.stack
 	if len(l.hooks) > 0 {
 		l2.hooks = append(l2.hooks, l.hooks...)
 	}
@@ -227,6 +248,10 @@ func (l Logger) With() Context {
 	l.context = make([]byte, 0, 500)
 	if context != nil {
 		l.context = append(l.context, context...)
+	} else {
+		// This is needed for AppendKey to not check len of input
+		// thus making it inlinable
+		l.context = enc.AppendBeginMarker(l.context)
 	}
 	return Context{l}
 }
@@ -241,6 +266,9 @@ func (l *Logger) UpdateContext(update func(c Context) Context) {
 	if cap(l.context) == 0 {
 		l.context = make([]byte, 0, 500)
 	}
+	if len(l.context) == 0 {
+		l.context = enc.AppendBeginMarker(l.context)
+	}
 	c := update(Context{*l})
 	l.context = c.l.context
 }
@@ -251,6 +279,11 @@ func (l Logger) Level(lvl Level) Logger {
 	return l
 }
 
+// GetLevel returns the current Level of l.
+func (l Logger) GetLevel() Level {
+	return l.level
+}
+
 // Sample returns a logger with the s sampler.
 func (l Logger) Sample(s Sampler) Logger {
 	l.sampler = s
@@ -263,6 +296,13 @@ func (l Logger) Hook(h Hook) Logger {
 	return l
 }
 
+// Trace starts a new message with trace level.
+//
+// You must call Msg on the returned event in order to send the event.
+func (l *Logger) Trace() *Event {
+	return l.newEvent(TraceLevel, nil)
+}
+
 // Debug starts a new message with debug level.
 //
 // You must call Msg on the returned event in order to send the event.
@@ -291,27 +331,43 @@ func (l *Logger) Error() *Event {
 	return l.newEvent(ErrorLevel, nil)
 }
 
+// Err starts a new message with error level with err as a field if not nil or
+// with info level if err is nil.
+//
+// You must call Msg on the returned event in order to send the event.
+func (l *Logger) Err(err error) *Event {
+	if err != nil {
+		return l.Error().Err(err)
+	}
+
+	return l.Info()
+}
+
 // 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 {
 	switch level {
+	case TraceLevel:
+		return l.Trace()
 	case DebugLevel:
 		return l.Debug()
 	case InfoLevel:
@@ -321,15 +377,15 @@ 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:
 		return nil
 	default:
-		panic("zerolog: WithLevel(): invalid level: " + strconv.Itoa(int(level)))
+		return l.newEvent(level, nil)
 	}
 }
 
@@ -345,7 +401,7 @@ func (l *Logger) Log() *Event {
 // Arguments are handled in the manner of fmt.Print.
 func (l *Logger) Print(v ...interface{}) {
 	if e := l.Debug(); e.Enabled() {
-		e.Msg(fmt.Sprint(v...))
+		e.CallerSkipFrame(1).Msg(fmt.Sprint(v...))
 	}
 }
 
@@ -353,7 +409,7 @@ func (l *Logger) Print(v ...interface{}) {
 // Arguments are handled in the manner of fmt.Printf.
 func (l *Logger) Printf(format string, v ...interface{}) {
 	if e := l.Debug(); e.Enabled() {
-		e.Msg(fmt.Sprintf(format, v...))
+		e.CallerSkipFrame(1).Msg(fmt.Sprintf(format, v...))
 	}
 }
 
@@ -365,7 +421,7 @@ func (l Logger) Write(p []byte) (n int, err error) {
 		// Trim CR added by stdlog.
 		p = p[0 : n-1]
 	}
-	l.Log().Msg(string(p))
+	l.Log().CallerSkipFrame(1).Msg(string(p))
 	return
 }
 
@@ -377,12 +433,15 @@ func (l *Logger) newEvent(level Level, done func(string)) *Event {
 	e := newEvent(l.w, level)
 	e.done = done
 	e.ch = l.hooks
-	if level != NoLevel {
-		e.Str(LevelFieldName, level.String())
+	if level != NoLevel && LevelFieldName != "" {
+		e.Str(LevelFieldName, LevelFieldMarshalFunc(level))
 	}
-	if l.context != nil && len(l.context) > 0 {
+	if l.context != nil && len(l.context) > 1 {
 		e.buf = enc.AppendObjectData(e.buf, l.context)
 	}
+	if l.stack {
+		e.Stack()
+	}
 	return e
 }
 

log/log.go

@@ -3,6 +3,7 @@ package log
 
 import (
 	"context"
+	"fmt"
 	"io"
 	"os"
 
@@ -37,6 +38,21 @@ func Hook(h zerolog.Hook) zerolog.Logger {
 	return Logger.Hook(h)
 }
 
+// Err starts a new message with error level with err as a field if not nil or
+// with info level if err is nil.
+//
+// You must call Msg on the returned event in order to send the event.
+func Err(err error) *zerolog.Event {
+	return Logger.Err(err)
+}
+
+// Trace starts a new message with trace level.
+//
+// You must call Msg on the returned event in order to send the event.
+func Trace() *zerolog.Event {
+	return Logger.Trace()
+}
+
 // Debug starts a new message with debug level.
 //
 // You must call Msg on the returned event in order to send the event.
@@ -99,13 +115,13 @@ func Log() *zerolog.Event {
 // Print sends a log event using debug level and no extra field.
 // Arguments are handled in the manner of fmt.Print.
 func Print(v ...interface{}) {
-	Logger.Print(v...)
+	Logger.Debug().CallerSkipFrame(1).Msg(fmt.Sprint(v...))
 }
 
 // Printf sends a log event using debug level and no extra field.
 // Arguments are handled in the manner of fmt.Printf.
 func Printf(format string, v ...interface{}) {
-	Logger.Printf(format, v...)
+	Logger.Debug().CallerSkipFrame(1).Msgf(format, v...)
 }
 
 // Ctx returns the Logger associated with the ctx. If no logger

log/log_example_test.go

@@ -54,6 +54,25 @@ func ExampleLog() {
 	// Output: {"time":1199811905,"message":"hello world"}
 }
 
+// Example of a conditional level based on the presence of an error.
+func ExampleErr() {
+	setup()
+	err := errors.New("some error")
+	log.Err(err).Msg("hello world")
+	log.Err(nil).Msg("hello world")
+
+	// Output: {"level":"error","error":"some error","time":1199811905,"message":"hello world"}
+	// {"level":"info","time":1199811905,"message":"hello world"}
+}
+
+// Example of a log at a particular "level" (in this case, "trace")
+func ExampleTrace() {
+	setup()
+	log.Trace().Msg("hello world")
+
+	// Output: {"level":"trace","time":1199811905,"message":"hello world"}
+}
+
 // Example of a log at a particular "level" (in this case, "debug")
 func ExampleDebug() {
 	setup()

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{}
@@ -95,6 +95,17 @@ func ExampleLogger_Printf() {
 	// Output: {"level":"debug","message":"hello world"}
 }
 
+func ExampleLogger_Trace() {
+	log := zerolog.New(os.Stdout)
+
+	log.Trace().
+		Str("foo", "bar").
+		Int("n", 123).
+		Msg("hello world")
+
+	// Output: {"level":"trace","foo":"bar","n":123,"message":"hello world"}
+}
+
 func ExampleLogger_Debug() {
 	log := zerolog.New(os.Stdout)
 
@@ -227,11 +238,15 @@ func ExampleEvent_Array() {
 		Str("foo", "bar").
 		Array("array", zerolog.Arr().
 			Str("baz").
-			Int(1),
+			Int(1).
+			Dict(zerolog.Dict().
+				Str("bar", "baz").
+				Int("n", 1),
+			),
 		).
 		Msg("hello world")
 
-	// Output: {"foo":"bar","array":["baz",1],"message":"hello world"}
+	// Output: {"foo":"bar","array":["baz",1,{"bar":"baz","n":1}],"message":"hello world"}
 }
 
 func ExampleEvent_Array_object() {
@@ -324,6 +339,38 @@ func ExampleEvent_Durs() {
 	// Output: {"foo":"bar","durs":[10000,20000],"message":"hello world"}
 }
 
+func ExampleEvent_Fields_map() {
+	fields := map[string]interface{}{
+		"bar": "baz",
+		"n":   1,
+	}
+
+	log := zerolog.New(os.Stdout)
+
+	log.Log().
+		Str("foo", "bar").
+		Fields(fields).
+		Msg("hello world")
+
+	// Output: {"foo":"bar","bar":"baz","n":1,"message":"hello world"}
+}
+
+func ExampleEvent_Fields_slice() {
+	fields := []interface{}{
+		"bar", "baz",
+		"n", 1,
+	}
+
+	log := zerolog.New(os.Stdout)
+
+	log.Log().
+		Str("foo", "bar").
+		Fields(fields).
+		Msg("hello world")
+
+	// Output: {"foo":"bar","bar":"baz","n":1,"message":"hello world"}
+}
+
 func ExampleContext_Dict() {
 	log := zerolog.New(os.Stdout).With().
 		Str("foo", "bar").
@@ -473,3 +520,35 @@ func ExampleContext_MacAddr() {
 
 	// Output: {"hostMAC":"00:14:22:01:23:45","message":"hello world"}
 }
+
+func ExampleContext_Fields_map() {
+	fields := map[string]interface{}{
+		"bar": "baz",
+		"n":   1,
+	}
+
+	log := zerolog.New(os.Stdout).With().
+		Str("foo", "bar").
+		Fields(fields).
+		Logger()
+
+	log.Log().Msg("hello world")
+
+	// Output: {"foo":"bar","bar":"baz","n":1,"message":"hello world"}
+}
+
+func ExampleContext_Fields_slice() {
+	fields := []interface{}{
+		"bar", "baz",
+		"n", 1,
+	}
+
+	log := zerolog.New(os.Stdout).With().
+		Str("foo", "bar").
+		Fields(fields).
+		Logger()
+
+	log.Log().Msg("hello world")
+
+	// Output: {"foo":"bar","bar":"baz","n":1,"message":"hello world"}
+}

log_test.go

@@ -7,6 +7,8 @@ import (
 	"net"
 	"reflect"
 	"runtime"
+	"strconv"
+	"strings"
 	"testing"
 	"time"
 )
@@ -75,10 +77,30 @@ func TestInfo(t *testing.T) {
 	})
 }
 
+func TestEmptyLevelFieldName(t *testing.T) {
+	fieldName := LevelFieldName
+	LevelFieldName = ""
+
+	t.Run("empty setting", func(t *testing.T) {
+		out := &bytes.Buffer{}
+		log := New(out)
+		log.Info().
+			Str("foo", "bar").
+			Int("n", 123).
+			Msg("")
+		if got, want := decodeIfBinaryToString(out.Bytes()), `{"foo":"bar","n":123}`+"\n"; got != want {
+			t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+		}
+	})
+	LevelFieldName = fieldName
+}
+
 func TestWith(t *testing.T) {
 	out := &bytes.Buffer{}
 	ctx := New(out).With().
 		Str("string", "foo").
+		Stringer("stringer", net.IP{127, 0, 0, 1}).
+		Stringer("stringer_nil", nil).
 		Bytes("bytes", []byte("bar")).
 		Hex("hex", []byte{0x12, 0xef}).
 		RawJSON("json", []byte(`{"some":"json"}`)).
@@ -102,7 +124,21 @@ func TestWith(t *testing.T) {
 	caller := fmt.Sprintf("%s:%d", file, line+3)
 	log := ctx.Caller().Logger()
 	log.Log().Msg("")
-	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":"foo","bytes":"bar","hex":"12ef","json":{"some":"json"},"error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"float32":11.101,"float64":12.30303,"time":"0001-01-01T00:00:00Z","caller":"`+caller+`"}`+"\n"; got != want {
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":"foo","stringer":"127.0.0.1","stringer_nil":null,"bytes":"bar","hex":"12ef","json":{"some":"json"},"error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"float32":11.101,"float64":12.30303,"time":"0001-01-01T00:00:00Z","caller":"`+caller+`"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+
+	// Validate CallerWithSkipFrameCount.
+	out.Reset()
+	_, file, line, _ = runtime.Caller(0)
+	caller = fmt.Sprintf("%s:%d", file, line+5)
+	log = ctx.CallerWithSkipFrameCount(3).Logger()
+	func() {
+		log.Log().Msg("")
+	}()
+	// The above line is a little contrived, but the line above should be the line due
+	// to the extra frame skip.
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":"foo","stringer":"127.0.0.1","stringer_nil":null,"bytes":"bar","hex":"12ef","json":{"some":"json"},"error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"float32":11.101,"float64":12.30303,"time":"0001-01-01T00:00:00Z","caller":"`+caller+`"}`+"\n"; got != want {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
 }
@@ -164,6 +200,112 @@ 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 TestFieldsSlice(t *testing.T) {
+	out := &bytes.Buffer{}
+	log := New(out)
+	log.Log().Fields([]interface{}{
+		"nil", nil,
+		"string", "foo",
+		"bytes", []byte("bar"),
+		"error", errors.New("some error"),
+		"bool", true,
+		"int", int(1),
+		"int8", int8(2),
+		"int16", int16(3),
+		"int32", int32(4),
+		"int64", int64(5),
+		"uint", uint(6),
+		"uint8", uint8(7),
+		"uint16", uint16(8),
+		"uint32", uint32(9),
+		"uint64", uint64(10),
+		"float32", float32(11),
+		"float64", float64(12),
+		"ipv6", net.IP{0x20, 0x01, 0x0d, 0xb8, 0x85, 0xa3, 0x00, 0x00, 0x00, 0x00, 0x8a, 0x2e, 0x03, 0x70, 0x73, 0x34},
+		"dur", 1 * time.Second,
+		"time", time.Time{},
+		"obj", obj{"a", "b", 1},
+	}).Msg("")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"nil":null,"string":"foo","bytes":"bar","error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"float32":11,"float64":12,"ipv6":"2001:db8:85a3::8a2e:370:7334","dur":1000,"time":"0001-01-01T00:00:00Z","obj":{"Pub":"a","Tag":"b","priv":1}}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+}
+
+func TestFieldsSliceExtraneous(t *testing.T) {
+	out := &bytes.Buffer{}
+	log := New(out)
+	log.Log().Fields([]interface{}{
+		"string", "foo",
+		"error", errors.New("some error"),
+		32, "valueForNonStringKey",
+		"bool", true,
+		"int", int(1),
+		"keyWithoutValue",
+	}).Msg("")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":"foo","error":"some error","bool":true,"int":1}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+}
+
+func TestFieldsNotMapSlice(t *testing.T) {
+	out := &bytes.Buffer{}
+	log := New(out)
+	log.Log().
+		Fields(obj{"a", "b", 1}).
+		Fields("string").
+		Fields(1).
+		Msg("")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{}`+"\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)
@@ -173,9 +315,12 @@ func TestFields(t *testing.T) {
 	log.Log().
 		Caller().
 		Str("string", "foo").
+		Stringer("stringer", net.IP{127, 0, 0, 1}).
+		Stringer("stringer_nil", nil).
 		Bytes("bytes", []byte("bar")).
 		Hex("hex", []byte{0x12, 0xef}).
 		RawJSON("json", []byte(`{"some":"json"}`)).
+		Func(func(e *Event) { e.Str("func", "func_output") }).
 		AnErr("some_err", nil).
 		Err(errors.New("some error")).
 		Bool("bool", true).
@@ -199,7 +344,7 @@ func TestFields(t *testing.T) {
 		Time("time", time.Time{}).
 		TimeDiff("diff", now, now.Add(-10*time.Second)).
 		Msg("")
-	if got, want := decodeIfBinaryToString(out.Bytes()), `{"caller":"`+caller+`","string":"foo","bytes":"bar","hex":"12ef","json":{"some":"json"},"error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"IPv4":"192.168.0.100","IPv6":"2001:db8:85a3::8a2e:370:7334","Mac":"00:14:22:01:23:45","Prefix":"192.168.0.100/24","float32":11.1234,"float64":12.321321321,"dur":1000,"time":"0001-01-01T00:00:00Z","diff":10000}`+"\n"; got != want {
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"caller":"`+caller+`","string":"foo","stringer":"127.0.0.1","stringer_nil":null,"bytes":"bar","hex":"12ef","json":{"some":"json"},"func":"func_output","error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"IPv4":"192.168.0.100","IPv6":"2001:db8:85a3::8a2e:370:7334","Mac":"00:14:22:01:23:45","Prefix":"192.168.0.100/24","float32":11.1234,"float64":12.321321321,"dur":1000,"time":"0001-01-01T00:00:00Z","diff":10000}`+"\n"; got != want {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
 }
@@ -209,6 +354,7 @@ func TestFieldsArrayEmpty(t *testing.T) {
 	log := New(out)
 	log.Log().
 		Strs("string", []string{}).
+		Stringers("stringer", []fmt.Stringer{}).
 		Errs("err", []error{}).
 		Bools("bool", []bool{}).
 		Ints("int", []int{}).
@@ -226,7 +372,7 @@ func TestFieldsArrayEmpty(t *testing.T) {
 		Durs("dur", []time.Duration{}).
 		Times("time", []time.Time{}).
 		Msg("")
-	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":[],"err":[],"bool":[],"int":[],"int8":[],"int16":[],"int32":[],"int64":[],"uint":[],"uint8":[],"uint16":[],"uint32":[],"uint64":[],"float32":[],"float64":[],"dur":[],"time":[]}`+"\n"; got != want {
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":[],"stringer":[],"err":[],"bool":[],"int":[],"int8":[],"int16":[],"int32":[],"int64":[],"uint":[],"uint8":[],"uint16":[],"uint32":[],"uint64":[],"float32":[],"float64":[],"dur":[],"time":[]}`+"\n"; got != want {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
 }
@@ -236,6 +382,7 @@ func TestFieldsArraySingleElement(t *testing.T) {
 	log := New(out)
 	log.Log().
 		Strs("string", []string{"foo"}).
+		Stringers("stringer", []fmt.Stringer{net.IP{127, 0, 0, 1}}).
 		Errs("err", []error{errors.New("some error")}).
 		Bools("bool", []bool{true}).
 		Ints("int", []int{1}).
@@ -251,9 +398,9 @@ func TestFieldsArraySingleElement(t *testing.T) {
 		Floats32("float32", []float32{11}).
 		Floats64("float64", []float64{12}).
 		Durs("dur", []time.Duration{1 * time.Second}).
-		Times("time", []time.Time{time.Time{}}).
+		Times("time", []time.Time{{}}).
 		Msg("")
-	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":["foo"],"err":["some error"],"bool":[true],"int":[1],"int8":[2],"int16":[3],"int32":[4],"int64":[5],"uint":[6],"uint8":[7],"uint16":[8],"uint32":[9],"uint64":[10],"float32":[11],"float64":[12],"dur":[1000],"time":["0001-01-01T00:00:00Z"]}`+"\n"; got != want {
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":["foo"],"stringer":["127.0.0.1"],"err":["some error"],"bool":[true],"int":[1],"int8":[2],"int16":[3],"int32":[4],"int64":[5],"uint":[6],"uint8":[7],"uint16":[8],"uint32":[9],"uint64":[10],"float32":[11],"float64":[12],"dur":[1000],"time":["0001-01-01T00:00:00Z"]}`+"\n"; got != want {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
 }
@@ -263,6 +410,7 @@ func TestFieldsArrayMultipleElement(t *testing.T) {
 	log := New(out)
 	log.Log().
 		Strs("string", []string{"foo", "bar"}).
+		Stringers("stringer", []fmt.Stringer{nil, net.IP{127, 0, 0, 1}}).
 		Errs("err", []error{errors.New("some error"), nil}).
 		Bools("bool", []bool{true, false}).
 		Ints("int", []int{1, 0}).
@@ -278,9 +426,9 @@ func TestFieldsArrayMultipleElement(t *testing.T) {
 		Floats32("float32", []float32{11, 0}).
 		Floats64("float64", []float64{12, 0}).
 		Durs("dur", []time.Duration{1 * time.Second, 0}).
-		Times("time", []time.Time{time.Time{}, time.Time{}}).
+		Times("time", []time.Time{{}, {}}).
 		Msg("")
-	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":["foo","bar"],"err":["some error",null],"bool":[true,false],"int":[1,0],"int8":[2,0],"int16":[3,0],"int32":[4,0],"int64":[5,0],"uint":[6,0],"uint8":[7,0],"uint16":[8,0],"uint32":[9,0],"uint64":[10,0],"float32":[11,0],"float64":[12,0],"dur":[1000,0],"time":["0001-01-01T00:00:00Z","0001-01-01T00:00:00Z"]}`+"\n"; got != want {
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":["foo","bar"],"stringer":[null,"127.0.0.1"],"err":["some error",null],"bool":[true,false],"int":[1,0],"int8":[2,0],"int16":[3,0],"int32":[4,0],"int64":[5,0],"uint":[6,0],"uint8":[7,0],"uint16":[8,0],"uint32":[9,0],"uint64":[10,0],"float32":[11,0],"float64":[12,0],"dur":[1000,0],"time":["0001-01-01T00:00:00Z","0001-01-01T00:00:00Z"]}`+"\n"; got != want {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
 }
@@ -291,10 +439,12 @@ func TestFieldsDisabled(t *testing.T) {
 	now := time.Now()
 	log.Debug().
 		Str("string", "foo").
+		Stringer("stringer", net.IP{127, 0, 0, 1}).
 		Bytes("bytes", []byte("bar")).
 		Hex("hex", []byte{0x12, 0xef}).
 		AnErr("some_err", nil).
 		Err(errors.New("some error")).
+		Func(func(e *Event) { e.Str("func", "func_output") }).
 		Bool("bool", true).
 		Int("int", 1).
 		Int8("int8", 2).
@@ -391,6 +541,24 @@ func TestLevel(t *testing.T) {
 	})
 }
 
+func TestGetLevel(t *testing.T) {
+	levels := []Level{
+		DebugLevel,
+		InfoLevel,
+		WarnLevel,
+		ErrorLevel,
+		FatalLevel,
+		PanicLevel,
+		NoLevel,
+		Disabled,
+	}
+	for _, level := range levels {
+		if got, want := New(nil).Level(level).GetLevel(), level; got != want {
+			t.Errorf("GetLevel() = %v, want: %v", got, want)
+		}
+	}
+}
+
 func TestSampling(t *testing.T) {
 	out := &bytes.Buffer{}
 	log := New(out).Sample(&BasicSampler{N: 2})
@@ -398,7 +566,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)
 	}
 }
@@ -430,32 +613,45 @@ func TestLevelWriter(t *testing.T) {
 			p string
 		}{},
 	}
-	log := New(lw)
+
+	// Allow extra-verbose logs.
+	SetGlobalLevel(TraceLevel - 1)
+	log := New(lw).Level(TraceLevel - 1)
+
+	log.Trace().Msg("0")
 	log.Debug().Msg("1")
 	log.Info().Msg("2")
 	log.Warn().Msg("3")
 	log.Error().Msg("4")
 	log.Log().Msg("nolevel-1")
-	log.WithLevel(DebugLevel).Msg("5")
-	log.WithLevel(InfoLevel).Msg("6")
-	log.WithLevel(WarnLevel).Msg("7")
-	log.WithLevel(ErrorLevel).Msg("8")
+	log.WithLevel(TraceLevel).Msg("5")
+	log.WithLevel(DebugLevel).Msg("6")
+	log.WithLevel(InfoLevel).Msg("7")
+	log.WithLevel(WarnLevel).Msg("8")
+	log.WithLevel(ErrorLevel).Msg("9")
 	log.WithLevel(NoLevel).Msg("nolevel-2")
+	log.WithLevel(-1).Msg("-1") // Same as TraceLevel
+	log.WithLevel(-2).Msg("-2") // Will log
+	log.WithLevel(-3).Msg("-3") // Will not log
 
 	want := []struct {
 		l Level
 		p string
 	}{
+		{TraceLevel, `{"level":"trace","message":"0"}` + "\n"},
 		{DebugLevel, `{"level":"debug","message":"1"}` + "\n"},
 		{InfoLevel, `{"level":"info","message":"2"}` + "\n"},
 		{WarnLevel, `{"level":"warn","message":"3"}` + "\n"},
 		{ErrorLevel, `{"level":"error","message":"4"}` + "\n"},
 		{NoLevel, `{"message":"nolevel-1"}` + "\n"},
-		{DebugLevel, `{"level":"debug","message":"5"}` + "\n"},
-		{InfoLevel, `{"level":"info","message":"6"}` + "\n"},
-		{WarnLevel, `{"level":"warn","message":"7"}` + "\n"},
-		{ErrorLevel, `{"level":"error","message":"8"}` + "\n"},
+		{TraceLevel, `{"level":"trace","message":"5"}` + "\n"},
+		{DebugLevel, `{"level":"debug","message":"6"}` + "\n"},
+		{InfoLevel, `{"level":"info","message":"7"}` + "\n"},
+		{WarnLevel, `{"level":"warn","message":"8"}` + "\n"},
+		{ErrorLevel, `{"level":"error","message":"9"}` + "\n"},
 		{NoLevel, `{"message":"nolevel-2"}` + "\n"},
+		{Level(-1), `{"level":"trace","message":"-1"}` + "\n"},
+		{Level(-2), `{"level":"-2","message":"-2"}` + "\n"},
 	}
 	if got := lw.ops; !reflect.DeepEqual(got, want) {
 		t.Errorf("invalid ops:\ngot:\n%v\nwant:\n%v", got, want)
@@ -521,3 +717,229 @@ 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)
+	}
+}
+
+func TestCallerMarshalFunc(t *testing.T) {
+	out := &bytes.Buffer{}
+	log := New(out)
+
+	// test default behaviour this is really brittle due to the line numbers
+	// actually mattering for validation
+	_, file, line, _ := runtime.Caller(0)
+	caller := fmt.Sprintf("%s:%d", file, line+2)
+	log.Log().Caller().Msg("msg")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"caller":"`+caller+`","message":"msg"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	// test custom behavior. In this case we'll take just the last directory
+	origCallerMarshalFunc := CallerMarshalFunc
+	defer func() { CallerMarshalFunc = origCallerMarshalFunc }()
+	CallerMarshalFunc = func(file string, line int) string {
+		parts := strings.Split(file, "/")
+		if len(parts) > 1 {
+			return strings.Join(parts[len(parts)-2:], "/") + ":" + strconv.Itoa(line)
+		}
+
+		return file + ":" + strconv.Itoa(line)
+	}
+	_, file, line, _ = runtime.Caller(0)
+	caller = CallerMarshalFunc(file, line+2)
+	log.Log().Caller().Msg("msg")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"caller":"`+caller+`","message":"msg"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+}
+
+func TestLevelFieldMarshalFunc(t *testing.T) {
+	origLevelFieldMarshalFunc := LevelFieldMarshalFunc
+	LevelFieldMarshalFunc = func(l Level) string {
+		return strings.ToUpper(l.String())
+	}
+	defer func() {
+		LevelFieldMarshalFunc = origLevelFieldMarshalFunc
+	}()
+	out := &bytes.Buffer{}
+	log := New(out)
+
+	log.Debug().Msg("test")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"DEBUG","message":"test"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	log.Info().Msg("test")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"INFO","message":"test"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	log.Warn().Msg("test")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"WARN","message":"test"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	log.Error().Msg("test")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"ERROR","message":"test"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+}
+
+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)
+	}
+}
+
+func TestUpdateEmptyContext(t *testing.T) {
+	var buf bytes.Buffer
+	log := New(&buf)
+
+	log.UpdateContext(func(c Context) Context {
+		return c.Str("foo", "bar")
+	})
+	log.Info().Msg("no panic")
+
+	want := `{"level":"info","foo":"bar","message":"no panic"}` + "\n"
+
+	if got := decodeIfBinaryToString(buf.Bytes()); got != want {
+		t.Errorf("invalid log output:\ngot:  %q\nwant: %q", got, want)
+	}
+}
+
+func TestLevel_String(t *testing.T) {
+	tests := []struct {
+		name string
+		l    Level
+		want string
+	}{
+		{"trace", TraceLevel, "trace"},
+		{"debug", DebugLevel, "debug"},
+		{"info", InfoLevel, "info"},
+		{"warn", WarnLevel, "warn"},
+		{"error", ErrorLevel, "error"},
+		{"fatal", FatalLevel, "fatal"},
+		{"panic", PanicLevel, "panic"},
+		{"disabled", Disabled, "disabled"},
+		{"nolevel", NoLevel, ""},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			if got := tt.l.String(); got != tt.want {
+				t.Errorf("String() = %v, want %v", got, tt.want)
+			}
+		})
+	}
+}
+
+func TestParseLevel(t *testing.T) {
+	type args struct {
+		levelStr string
+	}
+	tests := []struct {
+		name    string
+		args    args
+		want    Level
+		wantErr bool
+	}{
+		{"trace", args{"trace"}, TraceLevel, false},
+		{"debug", args{"debug"}, DebugLevel, false},
+		{"info", args{"info"}, InfoLevel, false},
+		{"warn", args{"warn"}, WarnLevel, false},
+		{"error", args{"error"}, ErrorLevel, false},
+		{"fatal", args{"fatal"}, FatalLevel, false},
+		{"panic", args{"panic"}, PanicLevel, false},
+		{"disabled", args{"disabled"}, Disabled, false},
+		{"nolevel", args{""}, NoLevel, false},
+		{"-1", args{"-1"}, TraceLevel, false},
+		{"-2", args{"-2"}, Level(-2), false},
+		{"-3", args{"-3"}, Level(-3), false},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			got, err := ParseLevel(tt.args.levelStr)
+			if (err != nil) != tt.wantErr {
+				t.Errorf("ParseLevel() error = %v, wantErr %v", err, tt.wantErr)
+				return
+			}
+			if got != tt.want {
+				t.Errorf("ParseLevel() got = %v, want %v", got, tt.want)
+			}
+		})
+	}
+}

not_go112.go

@@ -0,0 +1,5 @@
+// +build !go1.12
+
+package zerolog
+
+const contextCallerSkipFrameCount = 3

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,57 @@
+// +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 TestLogStackFromContext(t *testing.T) {
+	zerolog.ErrorStackMarshaler = MarshalStack
+
+	out := &bytes.Buffer{}
+	log := zerolog.New(out).With().Stack().Logger() // calling Stack() on log context instead of event
+
+	err := errors.Wrap(errors.New("error message"), "from error")
+	log.Log().Err(err).Msg("") // not explicitly calling Stack()
+
+	got := out.String()
+	want := `\{"stack":\[\{"func":"TestLogStackFromContext","line":"36","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

@@ -38,7 +38,7 @@ func (s RandomSampler) Sample(lvl Level) bool {
 }
 
 // BasicSampler is a sampler that will send every Nth events, regardless of
-// there level.
+// their level.
 type BasicSampler struct {
 	N       uint32
 	counter uint32
@@ -46,8 +46,12 @@ type BasicSampler struct {
 
 // Sample implements the Sampler interface.
 func (s *BasicSampler) Sample(lvl Level) bool {
+	n := s.N
+	if n == 1 {
+		return true
+	}
 	c := atomic.AddUint32(&s.counter, 1)
-	return c%s.N == 0
+	return c%n == 1
 }
 
 // BurstSampler lets Burst events pass per Period then pass the decision to
@@ -100,11 +104,15 @@ func (s *BurstSampler) inc() uint32 {
 
 // LevelSampler applies a different sampler for each level.
 type LevelSampler struct {
-	DebugSampler, InfoSampler, WarnSampler, ErrorSampler Sampler
+	TraceSampler, DebugSampler, InfoSampler, WarnSampler, ErrorSampler Sampler
 }
 
 func (s LevelSampler) Sample(lvl Level) bool {
 	switch lvl {
+	case TraceLevel:
+		if s.TraceSampler != nil {
+			return s.TraceSampler.Sample(lvl)
+		}
 	case DebugLevel:
 		if s.DebugSampler != nil {
 			return s.DebugSampler.Sample(lvl)

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

syslog.go

@@ -7,6 +7,10 @@ import (
 	"io"
 )
 
+// See http://cee.mitre.org/language/1.0-beta1/clt.html#syslog
+// or https://www.rsyslog.com/json-elasticsearch/
+const ceePrefix = "@cee:"
+
 // SyslogWriter is an interface matching a syslog.Writer struct.
 type SyslogWriter interface {
 	io.Writer
@@ -19,39 +23,58 @@ type SyslogWriter interface {
 }
 
 type syslogWriter struct {
-	w SyslogWriter
+	w      SyslogWriter
+	prefix string
 }
 
 // SyslogLevelWriter wraps a SyslogWriter and call the right syslog level
 // method matching the zerolog level.
 func SyslogLevelWriter(w SyslogWriter) LevelWriter {
-	return syslogWriter{w}
+	return syslogWriter{w, ""}
+}
+
+// SyslogCEEWriter wraps a SyslogWriter with a SyslogLevelWriter that adds a
+// MITRE CEE prefix for JSON syslog entries, compatible with rsyslog 
+// and syslog-ng JSON logging support. 
+// See https://www.rsyslog.com/json-elasticsearch/
+func SyslogCEEWriter(w SyslogWriter) LevelWriter {
+	return syslogWriter{w, ceePrefix}
 }
 
 func (sw syslogWriter) Write(p []byte) (n int, err error) {
-	return sw.w.Write(p)
+	var pn int
+	if sw.prefix != "" {
+		pn, err = sw.w.Write([]byte(sw.prefix))
+		if err != nil {
+			return pn, err
+		}
+	}
+	n, err = sw.w.Write(p)
+	return pn + n, err
 }
 
 // WriteLevel implements LevelWriter interface.
 func (sw syslogWriter) WriteLevel(level Level, p []byte) (n int, err error) {
 	switch level {
+	case TraceLevel:
 	case DebugLevel:
-		err = sw.w.Debug(string(p))
+		err = sw.w.Debug(sw.prefix + string(p))
 	case InfoLevel:
-		err = sw.w.Info(string(p))
+		err = sw.w.Info(sw.prefix + string(p))
 	case WarnLevel:
-		err = sw.w.Warning(string(p))
+		err = sw.w.Warning(sw.prefix + string(p))
 	case ErrorLevel:
-		err = sw.w.Err(string(p))
+		err = sw.w.Err(sw.prefix + string(p))
 	case FatalLevel:
-		err = sw.w.Emerg(string(p))
+		err = sw.w.Emerg(sw.prefix + string(p))
 	case PanicLevel:
-		err = sw.w.Crit(string(p))
+		err = sw.w.Crit(sw.prefix + string(p))
 	case NoLevel:
-		err = sw.w.Info(string(p))
+		err = sw.w.Info(sw.prefix + string(p))
 	default:
 		panic("invalid level")
 	}
+	// Any CEE prefix is not part of the message, so we don't include its length
 	n = len(p)
 	return
 }

syslog_test.go

@@ -3,8 +3,12 @@
 
 package zerolog
 
-import "testing"
-import "reflect"
+import (
+	"bytes"
+	"reflect"
+	"strings"
+	"testing"
+)
 
 type syslogEvent struct {
 	level string
@@ -17,6 +21,10 @@ type syslogTestWriter struct {
 func (w *syslogTestWriter) Write(p []byte) (int, error) {
 	return 0, nil
 }
+func (w *syslogTestWriter) Trace(m string) error {
+	w.events = append(w.events, syslogEvent{"Trace", m})
+	return nil
+}
 func (w *syslogTestWriter) Debug(m string) error {
 	w.events = append(w.events, syslogEvent{"Debug", m})
 	return nil
@@ -45,6 +53,7 @@ func (w *syslogTestWriter) Crit(m string) error {
 func TestSyslogWriter(t *testing.T) {
 	sw := &syslogTestWriter{}
 	log := New(SyslogLevelWriter(sw))
+	log.Trace().Msg("trace")
 	log.Debug().Msg("debug")
 	log.Info().Msg("info")
 	log.Warn().Msg("warn")
@@ -61,3 +70,39 @@ func TestSyslogWriter(t *testing.T) {
 		t.Errorf("Invalid syslog message routing: want %v, got %v", want, got)
 	}
 }
+
+type testCEEwriter struct {
+	buf *bytes.Buffer
+}
+
+// Only implement one method as we're just testing the prefixing
+func (c testCEEwriter) Debug(m string) error { return nil }
+
+func (c testCEEwriter) Info(m string) error {
+	_, err := c.buf.Write([]byte(m))
+	return err
+}
+
+func (c testCEEwriter) Warning(m string) error { return nil }
+
+func (c testCEEwriter) Err(m string) error { return nil }
+
+func (c testCEEwriter) Emerg(m string) error { return nil }
+
+func (c testCEEwriter) Crit(m string) error { return nil }
+
+func (c testCEEwriter) Write(b []byte) (int, error) {
+	return c.buf.Write(b)
+}
+
+func TestSyslogWriter_WithCEE(t *testing.T) {
+	var buf bytes.Buffer
+	sw := testCEEwriter{&buf}
+	log := New(SyslogCEEWriter(sw))
+	log.Info().Str("key", "value").Msg("message string")
+	got := string(buf.Bytes())
+	want := "@cee:{"
+	if !strings.HasPrefix(got, want) {
+		t.Errorf("Bad CEE message start: want %v, got %v", want, got)
+	}
+}

writer.go

@@ -1,7 +1,12 @@
 package zerolog
 
 import (
+	"bytes"
 	"io"
+	"path"
+	"runtime"
+	"strconv"
+	"strings"
 	"sync"
 )
 
@@ -26,11 +31,9 @@ type syncWriter struct {
 }
 
 // SyncWriter wraps w so that each call to Write is synchronized with a mutex.
-// This syncer can be the call to writer's Write method is not thread safe.
-// Note that os.File Write operation is using write() syscall which is supposed
-// to be thread-safe on POSIX systems. So there is no need to use this with
-// os.File on such systems as zerolog guaranties to issue a single Write call
-// per log event.
+// This syncer can be used to wrap the call to writer's Write method if it is
+// not thread safe. Note that you do not need this wrapper for os.File Write
+// operations on POSIX and Windows systems as they are already thread-safe.
 func SyncWriter(w io.Writer) io.Writer {
 	if lw, ok := w.(LevelWriter); ok {
 		return &syncWriter{lw: lw}
@@ -58,30 +61,30 @@ type multiLevelWriter struct {
 
 func (t multiLevelWriter) Write(p []byte) (n int, err error) {
 	for _, w := range t.writers {
-		n, err = w.Write(p)
-		if err != nil {
-			return
-		}
-		if n != len(p) {
-			err = io.ErrShortWrite
-			return
+		if _n, _err := w.Write(p); err == nil {
+			n = _n
+			if _err != nil {
+				err = _err
+			} else if _n != len(p) {
+				err = io.ErrShortWrite
+			}
 		}
 	}
-	return len(p), nil
+	return n, err
 }
 
 func (t multiLevelWriter) WriteLevel(l Level, p []byte) (n int, err error) {
 	for _, w := range t.writers {
-		n, err = w.WriteLevel(l, p)
-		if err != nil {
-			return
-		}
-		if n != len(p) {
-			err = io.ErrShortWrite
-			return
+		if _n, _err := w.WriteLevel(l, p); err == nil {
+			n = _n
+			if _err != nil {
+				err = _err
+			} else if _n != len(p) {
+				err = io.ErrShortWrite
+			}
 		}
 	}
-	return len(p), nil
+	return n, err
 }
 
 // MultiLevelWriter creates a writer that duplicates its writes to all the
@@ -98,3 +101,54 @@ func MultiLevelWriter(writers ...io.Writer) LevelWriter {
 	}
 	return multiLevelWriter{lwriters}
 }
+
+// TestingLog is the logging interface of testing.TB.
+type TestingLog interface {
+	Log(args ...interface{})
+	Logf(format string, args ...interface{})
+	Helper()
+}
+
+// TestWriter is a writer that writes to testing.TB.
+type TestWriter struct {
+	T TestingLog
+
+	// Frame skips caller frames to capture the original file and line numbers.
+	Frame int
+}
+
+// NewTestWriter creates a writer that logs to the testing.TB.
+func NewTestWriter(t TestingLog) TestWriter {
+	return TestWriter{T: t}
+}
+
+// Write to testing.TB.
+func (t TestWriter) Write(p []byte) (n int, err error) {
+	t.T.Helper()
+
+	n = len(p)
+
+	// Strip trailing newline because t.Log always adds one.
+	p = bytes.TrimRight(p, "\n")
+
+	// Try to correct the log file and line number to the caller.
+	if t.Frame > 0 {
+		_, origFile, origLine, _ := runtime.Caller(1)
+		_, frameFile, frameLine, ok := runtime.Caller(1 + t.Frame)
+		if ok {
+			erase := strings.Repeat("\b", len(path.Base(origFile))+len(strconv.Itoa(origLine))+3)
+			t.T.Logf("%s%s:%d: %s", erase, path.Base(frameFile), frameLine, p)
+			return n, err
+		}
+	}
+	t.T.Log(string(p))
+
+	return n, err
+}
+
+// ConsoleTestWriter creates an option that correctly sets the file frame depth for testing.TB log.
+func ConsoleTestWriter(t TestingLog) func(w *ConsoleWriter) {
+	return func(w *ConsoleWriter) {
+		w.Out = TestWriter{T: t, Frame: 6}
+	}
+}

writer_test.go

@@ -1,9 +1,13 @@
-// +build !binary_log
-// +build !windows
+//go:build !binary_log && !windows
+// +build !binary_log,!windows
 
 package zerolog
 
 import (
+	"bytes"
+	"errors"
+	"fmt"
+	"io"
 	"reflect"
 	"testing"
 )
@@ -27,3 +31,147 @@ func TestMultiSyslogWriter(t *testing.T) {
 		t.Errorf("Invalid syslog message routing: want %v, got %v", want, got)
 	}
 }
+
+var writeCalls int
+
+type mockedWriter struct {
+	wantErr bool
+}
+
+func (c mockedWriter) Write(p []byte) (int, error) {
+	writeCalls++
+
+	if c.wantErr {
+		return -1, errors.New("Expected error")
+	}
+
+	return len(p), nil
+}
+
+// Tests that a new writer is only used if it actually works.
+func TestResilientMultiWriter(t *testing.T) {
+	tests := []struct {
+		name    string
+		writers []io.Writer
+	}{
+		{
+			name: "All valid writers",
+			writers: []io.Writer{
+				mockedWriter{
+					wantErr: false,
+				},
+				mockedWriter{
+					wantErr: false,
+				},
+			},
+		},
+		{
+			name: "All invalid writers",
+			writers: []io.Writer{
+				mockedWriter{
+					wantErr: true,
+				},
+				mockedWriter{
+					wantErr: true,
+				},
+			},
+		},
+		{
+			name: "First invalid writer",
+			writers: []io.Writer{
+				mockedWriter{
+					wantErr: true,
+				},
+				mockedWriter{
+					wantErr: false,
+				},
+			},
+		},
+		{
+			name: "First valid writer",
+			writers: []io.Writer{
+				mockedWriter{
+					wantErr: false,
+				},
+				mockedWriter{
+					wantErr: true,
+				},
+			},
+		},
+	}
+
+	for _, tt := range tests {
+		writers := tt.writers
+		multiWriter := MultiLevelWriter(writers...)
+
+		logger := New(multiWriter).With().Timestamp().Logger().Level(InfoLevel)
+		logger.Info().Msg("Test msg")
+
+		if len(writers) != writeCalls {
+			t.Errorf("Expected %d writers to have been called but only %d were.", len(writers), writeCalls)
+		}
+		writeCalls = 0
+	}
+}
+
+type testingLog struct {
+	testing.TB
+	buf bytes.Buffer
+}
+
+func (t *testingLog) Log(args ...interface{}) {
+	if _, err := t.buf.WriteString(fmt.Sprint(args...)); err != nil {
+		t.Error(err)
+	}
+}
+
+func (t *testingLog) Logf(format string, args ...interface{}) {
+	if _, err := t.buf.WriteString(fmt.Sprintf(format, args...)); err != nil {
+		t.Error(err)
+	}
+}
+
+func TestTestWriter(t *testing.T) {
+	tests := []struct {
+		name  string
+		write []byte
+		want  []byte
+	}{{
+		name:  "newline",
+		write: []byte("newline\n"),
+		want:  []byte("newline"),
+	}, {
+		name:  "oneline",
+		write: []byte("oneline"),
+		want:  []byte("oneline"),
+	}, {
+		name:  "twoline",
+		write: []byte("twoline\n\n"),
+		want:  []byte("twoline"),
+	}}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			tb := &testingLog{TB: t} // Capture TB log buffer.
+			w := TestWriter{T: tb}
+
+			n, err := w.Write(tt.write)
+			if err != nil {
+				t.Error(err)
+			}
+			if n != len(tt.write) {
+				t.Errorf("Expected %d write length but got %d", len(tt.write), n)
+			}
+			p := tb.buf.Bytes()
+			if !bytes.Equal(tt.want, p) {
+				t.Errorf("Expected %q, got %q.", tt.want, p)
+			}
+
+			log := New(NewConsoleWriter(ConsoleTestWriter(t)))
+			log.Info().Str("name", tt.name).Msg("Success!")
+
+			tb.buf.Reset()
+		})
+	}
+
+}