.github/workflows/test.yml

@@ -14,7 +14,7 @@ jobs:
         go-version: ${{ matrix.go-version }}
     - name: Checkout code
       uses: actions/checkout@v2
-    - uses: actions/cache@v2
+    - uses: actions/cache@v3.0.5
       with:
         path: ~/go/pkg/mod
         key: ${{ runner.os }}-go-${{ hashFiles('**/go.sum') }}

README.md

@@ -625,7 +625,7 @@ Most fields are also available in the slice format (`Strs` for `[]string`, `Errs
 
 ## 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:
+In addition to the default JSON encoding, `zerolog` can produce binary logs using [CBOR](https://cbor.io) encoding. The choice of encoding can be decided at compile time using the build tag `binary_log` as follows:
 
 ```bash
 go build -tags binary_log .

console.go

@@ -74,6 +74,8 @@ type ConsoleWriter struct {
 	FormatFieldValue    Formatter
 	FormatErrFieldName  Formatter
 	FormatErrFieldValue Formatter
+
+	FormatExtra func(map[string]interface{}, *bytes.Buffer) error
 }
 
 // NewConsoleWriter creates and initializes a new ConsoleWriter.
@@ -128,10 +130,18 @@ func (w ConsoleWriter) Write(p []byte) (n int, err error) {
 
 	w.writeFields(evt, buf)
 
+	if w.FormatExtra != nil {
+		err = w.FormatExtra(evt, buf)
+		if err != nil {
+			return n, err
+		}
+	}
+
 	err = buf.WriteByte('\n')
 	if err != nil {
 		return n, err
 	}
+
 	_, err = buf.WriteTo(w.Out)
 	return len(p), err
 }
@@ -221,7 +231,7 @@ func (w ConsoleWriter) writeFields(evt map[string]interface{}, buf *bytes.Buffer
 		case json.Number:
 			buf.WriteString(fv(fValue))
 		default:
-			b, err := json.Marshal(fValue)
+			b, err := InterfaceMarshalFunc(fValue)
 			if err != nil {
 				fmt.Fprintf(buf, colorize("[error: %v]", colorRed, w.NoColor), err)
 			} else {
@@ -331,7 +341,7 @@ func consoleDefaultFormatTimestamp(timeFormat string, noColor bool) Formatter {
 			if err != nil {
 				t = tt
 			} else {
-				t = ts.Format(timeFormat)
+				t = ts.Local().Format(timeFormat)
 			}
 		case json.Number:
 			i, err := tt.Int64()
@@ -347,7 +357,7 @@ func consoleDefaultFormatTimestamp(timeFormat string, noColor bool) Formatter {
 					nsec = int64(time.Duration(i) * time.Microsecond)
 					sec = 0
 				}
-				ts := time.Unix(sec, nsec).UTC()
+				ts := time.Unix(sec, nsec)
 				t = ts.Format(timeFormat)
 			}
 		}

console_test.go

@@ -108,13 +108,14 @@ func TestConsoleWriter(t *testing.T) {
 		buf := &bytes.Buffer{}
 		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
 
-		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
+		ts := time.Unix(0, 0)
+		d := ts.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"
+		expectedOutput := ts.Format(time.Kitchen) + " DBG Foobar foo=bar\n"
 		actualOutput := buf.String()
 		if actualOutput != expectedOutput {
 			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
@@ -136,7 +137,7 @@ func TestConsoleWriter(t *testing.T) {
 			t.Errorf("Unexpected error when writing output: %s", err)
 		}
 
-		expectedOutput := "Jan  1 00:20:34.000 DBG Foobar foo=bar\n"
+		expectedOutput := time.Unix(1234, 0).Format(time.StampMilli) + " DBG Foobar foo=bar\n"
 		actualOutput := buf.String()
 		if actualOutput != expectedOutput {
 			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
@@ -158,7 +159,7 @@ func TestConsoleWriter(t *testing.T) {
 			t.Errorf("Unexpected error when writing output: %s", err)
 		}
 
-		expectedOutput := "Jan  1 00:20:34.567 DBG Foobar foo=bar\n"
+		expectedOutput := time.Unix(1234, 567000000).Format(time.StampMilli) + " DBG Foobar foo=bar\n"
 		actualOutput := buf.String()
 		if actualOutput != expectedOutput {
 			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
@@ -180,7 +181,7 @@ func TestConsoleWriter(t *testing.T) {
 			t.Errorf("Unexpected error when writing output: %s", err)
 		}
 
-		expectedOutput := "Jan  1 00:20:34.567891 DBG Foobar foo=bar\n"
+		expectedOutput := time.Unix(1234, 567891000).Format(time.StampMicro) + " DBG Foobar foo=bar\n"
 		actualOutput := buf.String()
 		if actualOutput != expectedOutput {
 			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
@@ -239,7 +240,8 @@ func TestConsoleWriter(t *testing.T) {
 		buf := &bytes.Buffer{}
 		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
 
-		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
+		ts := time.Unix(0, 0)
+		d := ts.UTC().Format(time.RFC3339)
 		evt := `{"time": "` + d + `", "level": "error", "message": "Foobar", "aaa": "bbb", "error": "Error"}`
 		// t.Log(evt)
 
@@ -248,7 +250,7 @@ func TestConsoleWriter(t *testing.T) {
 			t.Errorf("Unexpected error when writing output: %s", err)
 		}
 
-		expectedOutput := "12:00AM ERR Foobar error=Error aaa=bbb\n"
+		expectedOutput := ts.Format(time.Kitchen) + " ERR Foobar error=Error aaa=bbb\n"
 		actualOutput := buf.String()
 		if actualOutput != expectedOutput {
 			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
@@ -264,7 +266,8 @@ func TestConsoleWriter(t *testing.T) {
 			t.Fatalf("Cannot get working directory: %s", err)
 		}
 
-		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
+		ts := time.Unix(0, 0)
+		d := ts.UTC().Format(time.RFC3339)
 		evt := `{"time": "` + d + `", "level": "debug", "message": "Foobar", "foo": "bar", "caller": "` + cwd + `/foo/bar.go"}`
 		// t.Log(evt)
 
@@ -273,7 +276,7 @@ func TestConsoleWriter(t *testing.T) {
 			t.Errorf("Unexpected error when writing output: %s", err)
 		}
 
-		expectedOutput := "12:00AM DBG foo/bar.go > Foobar foo=bar\n"
+		expectedOutput := ts.Format(time.Kitchen) + " DBG foo/bar.go > Foobar foo=bar\n"
 		actualOutput := buf.String()
 		if actualOutput != expectedOutput {
 			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
@@ -305,15 +308,16 @@ func TestConsoleWriterConfiguration(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)
+		ts := time.Unix(0, 0)
+		d := ts.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"
+		expectedOutput := ts.Format(time.RFC3339) + " INF Foobar\n"
 		actualOutput := buf.String()
 		if actualOutput != expectedOutput {
 			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
@@ -371,6 +375,29 @@ func TestConsoleWriterConfiguration(t *testing.T) {
 			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
 		}
 	})
+
+	t.Run("Sets FormatExtra", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{
+			Out: buf, NoColor: true, PartsOrder: []string{"level", "message"},
+			FormatExtra: func(evt map[string]interface{}, buf *bytes.Buffer) error {
+				buf.WriteString("\nAdditional stacktrace")
+				return nil
+			},
+		}
+
+		evt := `{"level": "info", "message": "Foobar"}`
+		_, err := w.Write([]byte(evt))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "INF Foobar\nAdditional stacktrace\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
 }
 
 func BenchmarkConsoleWriter(b *testing.B) {

event.go

@@ -744,11 +744,11 @@ func (e *Event) caller(skip int) *Event {
 	if e == nil {
 		return e
 	}
-	_, file, line, ok := runtime.Caller(skip + e.skipFrame)
+	pc, file, line, ok := runtime.Caller(skip + e.skipFrame)
 	if !ok {
 		return e
 	}
-	e.buf = enc.AppendString(enc.AppendKey(e.buf, CallerFieldName), CallerMarshalFunc(file, line))
+	e.buf = enc.AppendString(enc.AppendKey(e.buf, CallerFieldName), CallerMarshalFunc(pc, file, line))
 	return e
 }
 

globals.go

@@ -19,6 +19,10 @@ const (
 	// TimeFormatUnixMicro defines a time format that makes time fields to be
 	// serialized as Unix timestamp integers in microseconds.
 	TimeFormatUnixMicro = "UNIXMICRO"
+
+	// TimeFormatUnixNano defines a time format that makes time fields to be
+	// serialized as Unix timestamp integers in nanoseconds.
+	TimeFormatUnixNano = "UNIXNANO"
 )
 
 var (
@@ -61,7 +65,7 @@ var (
 	CallerSkipFrameCount = 2
 
 	// CallerMarshalFunc allows customization of global caller marshaling
-	CallerMarshalFunc = func(file string, line int) string {
+	CallerMarshalFunc = func(pc uintptr, file string, line int) string {
 		return file + ":" + strconv.Itoa(line)
 	}
 
@@ -81,7 +85,7 @@ var (
 	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 a UNIX
+	// TimeFormatUnix, TimeFormatUnixMs, TimeFormatUnixMicro or TimeFormatUnixNano, the time is formatted as a UNIX
 	// timestamp as integer.
 	TimeFieldFormat = time.RFC3339
 

go.mod

@@ -6,5 +6,5 @@ require (
 	github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534
 	github.com/mattn/go-colorable v0.1.12
 	github.com/pkg/errors v0.9.1
-	github.com/rs/xid v1.3.0
+	github.com/rs/xid v1.4.0
 )

go.sum

@@ -1,5 +1,3 @@
-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/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534 h1:rtAn27wIbmOGUs7RIbVgPEjb31ehTVniDwPGXyMxm5U=
 github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
 github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
@@ -9,8 +7,8 @@ github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9
 github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94=
 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/rs/xid v1.4.0 h1:qd7wPTDkN6KQx2VmMBLrpHkiyQwgFXRnkOLacUiaSNY=
+github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
 golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6 h1:foEbQz/B0Oz6YIqu/69kfXPYeFQAuuMYFkjaqXzl5Wo=
 golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=

hlog/hlog.go

@@ -121,6 +121,20 @@ func RefererHandler(fieldKey string) func(next http.Handler) http.Handler {
 	}
 }
 
+// ProtoHandler adds the requests protocol version as a field to the context logger
+// using fieldKey as field Key.
+func ProtoHandler(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) {
+			log := zerolog.Ctx(r.Context())
+			log.UpdateContext(func(c zerolog.Context) zerolog.Context {
+				return c.Str(fieldKey, r.Proto)
+			})
+			next.ServeHTTP(w, r)
+		})
+	}
+}
+
 type idKey struct{}
 
 // IDFromRequest returns the unique id associated to the request if any.

hlog/hlog_test.go

@@ -1,3 +1,4 @@
+//go:build go1.7
 // +build go1.7
 
 package hlog
@@ -200,6 +201,22 @@ func TestCustomHeaderHandler(t *testing.T) {
 	}
 }
 
+func TestProtoHandler(t *testing.T) {
+	out := &bytes.Buffer{}
+	r := &http.Request{
+		Proto: "test",
+	}
+	h := ProtoHandler("proto")(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 := `{"proto":"test"}`+"\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{

internal/json/time.go

@@ -7,9 +7,10 @@ import (
 
 const (
 	// Import from zerolog/global.go
-	timeFormatUnix   = ""
-	timeFormatUnixMs = "UNIXMS"
+	timeFormatUnix      = ""
+	timeFormatUnixMs    = "UNIXMS"
 	timeFormatUnixMicro = "UNIXMICRO"
+	timeFormatUnixNano  = "UNIXNANO"
 )
 
 // AppendTime formats the input time with the given format
@@ -22,6 +23,8 @@ func (e Encoder) AppendTime(dst []byte, t time.Time, format string) []byte {
 		return e.AppendInt64(dst, t.UnixNano()/1000000)
 	case timeFormatUnixMicro:
 		return e.AppendInt64(dst, t.UnixNano()/1000)
+	case timeFormatUnixNano:
+		return e.AppendInt64(dst, t.UnixNano())
 	}
 	return append(t.AppendFormat(append(dst, '"'), format), '"')
 }
@@ -33,7 +36,11 @@ func (Encoder) AppendTimes(dst []byte, vals []time.Time, format string) []byte {
 	case timeFormatUnix:
 		return appendUnixTimes(dst, vals)
 	case timeFormatUnixMs:
-		return appendUnixMsTimes(dst, vals)
+		return appendUnixNanoTimes(dst, vals, 1000000)
+	case timeFormatUnixMicro:
+		return appendUnixNanoTimes(dst, vals, 1000)
+	case timeFormatUnixNano:
+		return appendUnixNanoTimes(dst, vals, 1)
 	}
 	if len(vals) == 0 {
 		return append(dst, '[', ']')
@@ -64,15 +71,15 @@ func appendUnixTimes(dst []byte, vals []time.Time) []byte {
 	return dst
 }
 
-func appendUnixMsTimes(dst []byte, vals []time.Time) []byte {
+func appendUnixNanoTimes(dst []byte, vals []time.Time, div int64) []byte {
 	if len(vals) == 0 {
 		return append(dst, '[', ']')
 	}
 	dst = append(dst, '[')
-	dst = strconv.AppendInt(dst, vals[0].UnixNano()/1000000, 10)
+	dst = strconv.AppendInt(dst, vals[0].UnixNano()/div, 10)
 	if len(vals) > 1 {
 		for _, t := range vals[1:] {
-			dst = strconv.AppendInt(append(dst, ','), t.UnixNano()/1000000, 10)
+			dst = strconv.AppendInt(append(dst, ','), t.UnixNano()/div, 10)
 		}
 	}
 	dst = append(dst, ']')

journald/journald.go

@@ -102,7 +102,7 @@ func (w journalWriter) Write(p []byte) (n int, err error) {
 		case json.Number:
 			args[jKey] = fmt.Sprint(value)
 		default:
-			b, err := json.Marshal(value)
+			b, err := zerolog.InterfaceMarshalFunc(value)
 			if err != nil {
 				args[jKey] = fmt.Sprintf("[error: %v]", err)
 			} else {