From a4ec5e4cdd4b3ca3ba82b8b7259acdf649010695 Mon Sep 17 00:00:00 2001 From: Robson Roberto Souza Peixoto <124390+robsonpeixoto@users.noreply.github.com> Date: Thu, 5 May 2022 14:17:37 -0300 Subject: [PATCH 01/22] typo: using https to access cbor.io (#439) --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index c22ee2e..95666b3 100644 --- a/README.md +++ b/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 . From 2a1387281776d592a4ced673c4f17be99062cc23 Mon Sep 17 00:00:00 2001 From: Adam Horacek Date: Tue, 28 Jun 2022 16:36:09 -0700 Subject: [PATCH 02/22] remove fields written into "PartsOrder" (#383) --- console.go | 1 + 1 file changed, 1 insertion(+) diff --git a/console.go b/console.go index 25c178b..340ab71 100644 --- a/console.go +++ b/console.go @@ -124,6 +124,7 @@ func (w ConsoleWriter) Write(p []byte) (n int, err error) { for _, p := range w.PartsOrder { w.writePart(buf, evt, p) + delete(evt, p) } w.writeFields(evt, buf) From 60f57432eda7603ef6006be191f61922b58b65ba Mon Sep 17 00:00:00 2001 From: Aniruddha Maru Date: Sat, 16 Jul 2022 12:51:01 -0700 Subject: [PATCH 03/22] Implement encoding.TextUnmarshaler and encoding.TextMarshaler for Level (#440) --- log.go | 16 +++++++++++++ log_test.go | 65 +++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 81 insertions(+) diff --git a/log.go b/log.go index 3ae1b5b..efd2a33 100644 --- a/log.go +++ b/log.go @@ -99,6 +99,7 @@ package zerolog import ( + "errors" "fmt" "io" "io/ioutil" @@ -189,6 +190,21 @@ func ParseLevel(levelStr string) (Level, error) { return Level(i), nil } +// UnmarshalText implements encoding.TextUnmarshaler to allow for easy reading from toml/yaml/json formats +func (l *Level) UnmarshalText(text []byte) error { + if l == nil { + return errors.New("can't unmarshal a nil *Level") + } + var err error + *l, err = ParseLevel(string(text)) + return err +} + +// MarshalText implements encoding.TextMarshaler to allow for easy writing into toml/yaml/json formats +func (l Level) MarshalText() ([]byte, error) { + return []byte(LevelFieldMarshalFunc(l)), 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 guarantee on access diff --git a/log_test.go b/log_test.go index 2ffd47e..e49daea 100644 --- a/log_test.go +++ b/log_test.go @@ -907,6 +907,33 @@ func TestLevel_String(t *testing.T) { } } +func TestLevel_MarshalText(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, err := tt.l.MarshalText(); err != nil { + t.Errorf("MarshalText couldn't marshal: %v", tt.l) + } else if string(got) != tt.want { + t.Errorf("String() = %v, want %v", string(got), tt.want) + } + }) + } +} + func TestParseLevel(t *testing.T) { type args struct { levelStr string @@ -943,3 +970,41 @@ func TestParseLevel(t *testing.T) { }) } } + +func TestUnmarshalTextLevel(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) { + var l Level + err := l.UnmarshalText([]byte(tt.args.levelStr)) + if (err != nil) != tt.wantErr { + t.Errorf("UnmarshalText() error = %v, wantErr %v", err, tt.wantErr) + return + } + if l != tt.want { + t.Errorf("UnmarshalText() got = %v, want %v", l, tt.want) + } + }) + } +} From 5c08a2724f6816f006445ecf6464ae4d932c529a Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Sat, 16 Jul 2022 20:58:58 +0100 Subject: [PATCH 04/22] Bump actions/cache from 2 to 3.0.1 (#432) Bumps [actions/cache](https://github.com/actions/cache) from 2 to 3.0.1. - [Release notes](https://github.com/actions/cache/releases) - [Changelog](https://github.com/actions/cache/blob/main/RELEASES.md) - [Commits](https://github.com/actions/cache/compare/v2...v3.0.1) --- updated-dependencies: - dependency-name: actions/cache dependency-type: direct:production update-type: version-update:semver-major ... Signed-off-by: dependabot[bot] Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com> --- .github/workflows/test.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index b9bcccf..05d9426 100644 --- a/.github/workflows/test.yml +++ b/.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.1 with: path: ~/go/pkg/mod key: ${{ runner.os }}-go-${{ hashFiles('**/go.sum') }} From 68a6bd49b5bdd0ddc4293bdf503462ea2a3c151e Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Sat, 16 Jul 2022 20:59:27 +0100 Subject: [PATCH 05/22] Bump github.com/rs/xid from 1.3.0 to 1.4.0 (#430) Bumps [github.com/rs/xid](https://github.com/rs/xid) from 1.3.0 to 1.4.0. - [Release notes](https://github.com/rs/xid/releases) - [Commits](https://github.com/rs/xid/compare/v1.3.0...v1.4.0) --- updated-dependencies: - dependency-name: github.com/rs/xid dependency-type: direct:production update-type: version-update:semver-minor ... Signed-off-by: dependabot[bot] Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com> --- go.mod | 2 +- go.sum | 6 ++---- 2 files changed, 3 insertions(+), 5 deletions(-) diff --git a/go.mod b/go.mod index 746596d..e5fcd6f 100644 --- a/go.mod +++ b/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 ) diff --git a/go.sum b/go.sum index d8f860b..d32e91d 100644 --- a/go.sum +++ b/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= From b30730fab2c86649b5e93525f114cfdd3a98c866 Mon Sep 17 00:00:00 2001 From: Mitar Date: Sat, 16 Jul 2022 13:02:45 -0700 Subject: [PATCH 06/22] Show local time in console (#415) --- console.go | 4 ++-- console_test.go | 26 +++++++++++++++----------- 2 files changed, 17 insertions(+), 13 deletions(-) diff --git a/console.go b/console.go index 340ab71..1c3391f 100644 --- a/console.go +++ b/console.go @@ -332,7 +332,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() @@ -348,7 +348,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) } } diff --git a/console_test.go b/console_test.go index bd79584..0a6e88a 100644 --- a/console_test.go +++ b/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,7 +308,8 @@ 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)) @@ -313,7 +317,7 @@ func TestConsoleWriterConfiguration(t *testing.T) { 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) From dbdec88d16a2f50ebbdf3a055fe501e075968c91 Mon Sep 17 00:00:00 2001 From: Mitar Date: Sat, 16 Jul 2022 13:03:29 -0700 Subject: [PATCH 07/22] Use everywhere InterfaceMarshalFunc (#414) --- console.go | 2 +- journald/journald.go | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/console.go b/console.go index 1c3391f..1f104e1 100644 --- a/console.go +++ b/console.go @@ -222,7 +222,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 { diff --git a/journald/journald.go b/journald/journald.go index 8f77d0a..5b53490 100644 --- a/journald/journald.go +++ b/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 { From 14d6629e41683140550f25e6706381efda008968 Mon Sep 17 00:00:00 2001 From: xsteadfastx Date: Sat, 16 Jul 2022 22:04:30 +0200 Subject: [PATCH 08/22] hlog: adds ProtoHandler (#396) --- hlog/hlog.go | 14 ++++++++++++++ hlog/hlog_test.go | 17 +++++++++++++++++ 2 files changed, 31 insertions(+) diff --git a/hlog/hlog.go b/hlog/hlog.go index 4f19a08..3773400 100644 --- a/hlog/hlog.go +++ b/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. diff --git a/hlog/hlog_test.go b/hlog/hlog_test.go index 481525b..c584e98 100644 --- a/hlog/hlog_test.go +++ b/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{ From afdf9978ec10b0f5a240f174fcdc6e58e06f0dca Mon Sep 17 00:00:00 2001 From: Olivier Poitrey Date: Sat, 16 Jul 2022 21:17:58 +0100 Subject: [PATCH 09/22] Revert "remove fields written into "PartsOrder" (#383)" This reverts commit 2a1387281776d592a4ced673c4f17be99062cc23. --- console.go | 1 - 1 file changed, 1 deletion(-) diff --git a/console.go b/console.go index 1f104e1..c508ec6 100644 --- a/console.go +++ b/console.go @@ -124,7 +124,6 @@ func (w ConsoleWriter) Write(p []byte) (n int, err error) { for _, p := range w.PartsOrder { w.writePart(buf, evt, p) - delete(evt, p) } w.writeFields(evt, buf) From 43be3013864af78038c42de900a4d78eae0f1d22 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 18 Jul 2022 10:41:56 +0100 Subject: [PATCH 10/22] Bump actions/cache from 3.0.1 to 3.0.5 (#453) --- .github/workflows/test.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 05d9426..2b9ae77 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -14,7 +14,7 @@ jobs: go-version: ${{ matrix.go-version }} - name: Checkout code uses: actions/checkout@v2 - - uses: actions/cache@v3.0.1 + - uses: actions/cache@v3.0.5 with: path: ~/go/pkg/mod key: ${{ runner.os }}-go-${{ hashFiles('**/go.sum') }} From 4c85986254a5d411779c1ec553a12094042f56a0 Mon Sep 17 00:00:00 2001 From: lazarenkovegor <59872605+lazarenkovegor@users.noreply.github.com> Date: Mon, 18 Jul 2022 19:25:16 +0300 Subject: [PATCH 11/22] Unixnano time format support (#454) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Лазаренков Егор Алексеевич --- globals.go | 6 +++++- internal/json/time.go | 19 +++++++++++++------ 2 files changed, 18 insertions(+), 7 deletions(-) diff --git a/globals.go b/globals.go index 9da6ae0..80f036a 100644 --- a/globals.go +++ b/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 ( @@ -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 diff --git a/internal/json/time.go b/internal/json/time.go index 5aff6be..6a8dc91 100644 --- a/internal/json/time.go +++ b/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, ']') From 4099072c03f2f4e61fa08f70adf9a25983f0cd8e Mon Sep 17 00:00:00 2001 From: Mitar Date: Mon, 18 Jul 2022 15:00:50 -0700 Subject: [PATCH 12/22] Support extra arbitrary data at the end of console log (#416) --- console.go | 10 ++++++++++ console_test.go | 23 +++++++++++++++++++++++ 2 files changed, 33 insertions(+) diff --git a/console.go b/console.go index c508ec6..ac34b7e 100644 --- a/console.go +++ b/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 } diff --git a/console_test.go b/console_test.go index 0a6e88a..98a4e27 100644 --- a/console_test.go +++ b/console_test.go @@ -375,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) { From d894f123bc5c2a887c95e90218b9410563141d67 Mon Sep 17 00:00:00 2001 From: Martin Rauscher Date: Fri, 29 Jul 2022 16:29:02 +0200 Subject: [PATCH 13/22] pass program counter to CallerMarshalFunc (#457) --- event.go | 4 ++-- globals.go | 2 +- log_test.go | 10 +++++----- 3 files changed, 8 insertions(+), 8 deletions(-) diff --git a/event.go b/event.go index b9fa138..0e2eaa6 100644 --- a/event.go +++ 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 } diff --git a/globals.go b/globals.go index 80f036a..e1067de 100644 --- a/globals.go +++ b/globals.go @@ -65,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) } diff --git a/log_test.go b/log_test.go index e49daea..aa84750 100644 --- a/log_test.go +++ b/log_test.go @@ -782,7 +782,7 @@ func TestCallerMarshalFunc(t *testing.T) { // test default behaviour this is really brittle due to the line numbers // actually mattering for validation - _, file, line, _ := runtime.Caller(0) + pc, 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 { @@ -793,16 +793,16 @@ func TestCallerMarshalFunc(t *testing.T) { // 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 { + CallerMarshalFunc = func(pc uintptr, 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) + return runtime.FuncForPC(pc).Name() + ":" + file + ":" + strconv.Itoa(line) } - _, file, line, _ = runtime.Caller(0) - caller = CallerMarshalFunc(file, line+2) + pc, file, line, _ = runtime.Caller(0) + caller = CallerMarshalFunc(pc, 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) From c2b9d0e2defd04e1afb9712132a66681d077eb42 Mon Sep 17 00:00:00 2001 From: Uros Marolt Date: Sat, 3 Sep 2022 13:06:22 +0200 Subject: [PATCH 14/22] CLI utility to pipe JSON logs through to pretty print and colorize them (#449) --- cmd/prettylog/README.md | 40 ++++++++++++++++++++++++++++++++++++++ cmd/prettylog/prettylog.go | 26 +++++++++++++++++++++++++ 2 files changed, 66 insertions(+) create mode 100644 cmd/prettylog/README.md create mode 100644 cmd/prettylog/prettylog.go diff --git a/cmd/prettylog/README.md b/cmd/prettylog/README.md new file mode 100644 index 0000000..2412915 --- /dev/null +++ b/cmd/prettylog/README.md @@ -0,0 +1,40 @@ +# Zerolog PrettyLog + +This is a basic CLI utility that will colorize and pretty print your structured JSON logs. + +## Usage + +You can compile it or run it directly. The only issue is that by default Zerolog does not output to `stdout` +but rather to `stderr` so we must pipe `stderr` stream to this CLI tool. + +### Linux + +These commands will redirect `stderr` to our `prettylog` tool and `stdout` will remain unaffected. + +1. Compiled version + +```shell +some_program_with_zerolog 2> >(prettylog) +``` + +2. Run it directly with `go run` + +```shell +some_program_with_zerolog 2> >(go run cmd/prettylog/prettylog.go) +``` + +### Windows + +These commands will redirect `stderr` to `stdout` and then pipe it to our `prettylog` tool. + +1. Compiled version + +```shell +some_program_with_zerolog 2>&1 | prettylog +``` + +2. Run it directly with `go run` + +```shell +some_program_with_zerolog 2>&1 | go run cmd/prettylog/prettylog.go +``` diff --git a/cmd/prettylog/prettylog.go b/cmd/prettylog/prettylog.go new file mode 100644 index 0000000..61bf8b8 --- /dev/null +++ b/cmd/prettylog/prettylog.go @@ -0,0 +1,26 @@ +package main + +import ( + "fmt" + "io" + "os" + + "github.com/rs/zerolog" +) + +func isInputFromPipe() bool { + fileInfo, _ := os.Stdin.Stat() + return fileInfo.Mode()&os.ModeCharDevice == 0 +} + +func main() { + if !isInputFromPipe() { + fmt.Println("The command is intended to work with pipes.") + fmt.Println("Usage: app_with_zerolog | 2> >(prettylog)") + os.Exit(1) + return + } + + writer := zerolog.NewConsoleWriter() + _, _ = io.Copy(writer, os.Stdin) +} From e218d18951a18f1ef4bd3384f95b7e58abd9c90b Mon Sep 17 00:00:00 2001 From: Michael Nikitochkin Date: Fri, 9 Sep 2022 23:18:08 +0200 Subject: [PATCH 15/22] Update example of usage CallerMarshalFunc (#475) There was changes in https://github.com/rs/zerolog/pull/457 pass program counter to CallerMarshalFunc. Update example in README.md --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index 95666b3..e8cbfc2 100644 --- a/README.md +++ b/README.md @@ -411,7 +411,7 @@ log.Info().Msg("hello world") Equivalent of `Lshortfile`: ```go -zerolog.CallerMarshalFunc = func(file string, line int) string { +zerolog.CallerMarshalFunc = func(pc uintptr, file string, line int) string { short := file for i := len(file) - 1; i > 0; i-- { if file[i] == '/' { From 315967f32d4c954447e17a1806045855ebad94d0 Mon Sep 17 00:00:00 2001 From: Donald Nguyen Date: Thu, 15 Sep 2022 01:15:42 -0700 Subject: [PATCH 16/22] Avoid race in diode.Close with waiter (#481) --- diode/diode_test.go | 8 ++++++++ diode/internal/diodes/waiter.go | 5 +++++ 2 files changed, 13 insertions(+) diff --git a/diode/diode_test.go b/diode/diode_test.go index 098bd44..d0d0aff 100644 --- a/diode/diode_test.go +++ b/diode/diode_test.go @@ -30,6 +30,14 @@ func TestNewWriter(t *testing.T) { } } +func TestClose(t *testing.T) { + buf := bytes.Buffer{} + w := diode.NewWriter(&buf, 1000, 0, func(missed int) {}) + log := zerolog.New(w) + log.Print("test") + w.Close() +} + func Benchmark(b *testing.B) { log.SetOutput(ioutil.Discard) defer log.SetOutput(os.Stderr) diff --git a/diode/internal/diodes/waiter.go b/diode/internal/diodes/waiter.go index 7c9bb0c..a4a8e97 100644 --- a/diode/internal/diodes/waiter.go +++ b/diode/internal/diodes/waiter.go @@ -39,7 +39,12 @@ func NewWaiter(d Diode, opts ...WaiterConfigOption) *Waiter { go func() { <-w.ctx.Done() + + // Mutex is strictly necessary here to avoid a race in Next() (between + // w.isDone() and w.c.Wait()) and w.c.Broadcast() here. + w.mu.Lock() w.c.Broadcast() + w.mu.Unlock() }() return w From 55aaf043cf4d84249a6d2344ef18d82279d08955 Mon Sep 17 00:00:00 2001 From: Yuki Furuyama Date: Sun, 18 Sep 2022 23:53:56 +0900 Subject: [PATCH 17/22] Show original level message if it's not predefined value. (#476) --- console.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/console.go b/console.go index ac34b7e..9f6ffbf 100644 --- a/console.go +++ b/console.go @@ -385,7 +385,7 @@ func consoleDefaultFormatLevel(noColor bool) Formatter { case LevelPanicValue: l = colorize(colorize("PNC", colorRed, noColor), colorBold, noColor) default: - l = colorize("???", colorBold, noColor) + l = colorize(ll, colorBold, noColor) } } else { if i == nil { From 89617ff99b2feb29ab2d8b6258fac9d671073792 Mon Sep 17 00:00:00 2001 From: Mario Cormier Date: Mon, 17 Oct 2022 20:51:54 -0400 Subject: [PATCH 18/22] Adding Event.Type(...) method to log the type of an object (#437) Co-authored-by: Mario Cormier --- event.go | 9 +++++++++ internal/json/types.go | 9 +++++++++ internal/json/types_test.go | 22 ++++++++++++++++++++++ 3 files changed, 40 insertions(+) diff --git a/event.go b/event.go index 0e2eaa6..eb5c90d 100644 --- a/event.go +++ b/event.go @@ -719,6 +719,15 @@ func (e *Event) Interface(key string, i interface{}) *Event { return e } +// Type adds the field key with val's type using reflection. +func (e *Event) Type(key string, val interface{}) *Event { + if e == nil { + return e + } + e.buf = enc.AppendType(enc.AppendKey(e.buf, key), val) + 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 { diff --git a/internal/json/types.go b/internal/json/types.go index ad7f7a8..ef3a2a7 100644 --- a/internal/json/types.go +++ b/internal/json/types.go @@ -4,6 +4,7 @@ import ( "fmt" "math" "net" + "reflect" "strconv" ) @@ -369,6 +370,14 @@ func (e Encoder) AppendInterface(dst []byte, i interface{}) []byte { return append(dst, marshaled...) } +// AppendType appends the parameter type (as a string) to the input byte slice. +func (e Encoder) AppendType(dst []byte, i interface{}) []byte { + if i == nil { + return e.AppendString(dst, "") + } + return e.AppendString(dst, reflect.TypeOf(i).String()) +} + // 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 { diff --git a/internal/json/types_test.go b/internal/json/types_test.go index 9a9d668..26dc3e8 100644 --- a/internal/json/types_test.go +++ b/internal/json/types_test.go @@ -166,6 +166,28 @@ func Test_appendMac(t *testing.T) { } } +func Test_appendType(t *testing.T) { + typeTests := []struct { + label string + input interface{} + want []byte + }{ + {"int", 42, []byte(`"int"`)}, + {"MAC", net.HardwareAddr{0x12, 0x34, 0x00, 0x00, 0x90, 0xab}, []byte(`"net.HardwareAddr"`)}, + {"float64", float64(2.50), []byte(`"float64"`)}, + {"nil", nil, []byte(`""`)}, + {"bool", true, []byte(`"bool"`)}, + } + + for _, tt := range typeTests { + t.Run(tt.label, func(t *testing.T) { + if got := enc.AppendType([]byte{}, tt.input); !reflect.DeepEqual(got, tt.want) { + t.Errorf("appendType() = %s, want %s", got, tt.want) + } + }) + } +} + func Test_appendObjectData(t *testing.T) { tests := []struct { dst []byte From a9a8199d2dd3578d37e459618515f34b5e917f8d Mon Sep 17 00:00:00 2001 From: Patrick Scheid Date: Fri, 21 Oct 2022 23:32:46 +0200 Subject: [PATCH 19/22] ConsoleWriter fallbacks to local timezone for missing TZ indicator (#497) Closes issue #483 Before: We use time.Parse which defaults to TZ UTC if there is no time zone indicator specified in the time layout string. During the reparsing in ConsoleWriter we therefore added the TZ difference to UTC twice. After: We use time.ParseInLocal where we need to provide a dedicated fallback TZ as a fallback. Since we now fallback to the local TZ, we don't add the TZ difference to UTC twice. --- console.go | 2 +- console_test.go | 26 ++++++++++++++++++++++++++ 2 files changed, 27 insertions(+), 1 deletion(-) diff --git a/console.go b/console.go index 9f6ffbf..9cc3285 100644 --- a/console.go +++ b/console.go @@ -337,7 +337,7 @@ func consoleDefaultFormatTimestamp(timeFormat string, noColor bool) Formatter { t := "" switch tt := i.(type) { case string: - ts, err := time.Parse(TimeFieldFormat, tt) + ts, err := time.ParseInLocation(TimeFieldFormat, tt, time.Local) if err != nil { t = tt } else { diff --git a/console_test.go b/console_test.go index 98a4e27..18c2db7 100644 --- a/console_test.go +++ b/console_test.go @@ -398,6 +398,32 @@ func TestConsoleWriterConfiguration(t *testing.T) { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) + + t.Run("Uses local time for console writer without time zone", func(t *testing.T) { + // Regression test for issue #483 (check there for more details) + + timeFormat := "2006-01-02 15:04:05" + expectedOutput := "2022-10-20 20:24:50 INF Foobar\n" + evt := `{"time": "2022-10-20 20:24:50", "level": "info", "message": "Foobar"}` + + of := zerolog.TimeFieldFormat + defer func() { + zerolog.TimeFieldFormat = of + }() + zerolog.TimeFieldFormat = timeFormat + + buf := &bytes.Buffer{} + w := zerolog.ConsoleWriter{Out: buf, NoColor: true, TimeFormat: timeFormat} + _, err := w.Write([]byte(evt)) + if err != nil { + t.Errorf("Unexpected error when writing output: %s", err) + } + + actualOutput := buf.String() + if actualOutput != expectedOutput { + t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) + } + }) } func BenchmarkConsoleWriter(b *testing.B) { From e3027a573295768ea9478da3f0599083cf344a32 Mon Sep 17 00:00:00 2001 From: Tim Peoples Date: Sat, 22 Oct 2022 10:29:38 -0700 Subject: [PATCH 20/22] Fix docs and behavior of WithContext (#499) --- ctx.go | 19 ++++++++++--------- 1 file changed, 10 insertions(+), 9 deletions(-) diff --git a/ctx.go b/ctx.go index 44d3f4b..60432d1 100644 --- a/ctx.go +++ b/ctx.go @@ -14,10 +14,15 @@ func init() { type ctxKey struct{} -// WithContext returns a copy of ctx with l associated. If an instance of Logger -// is already in the context, the context is not updated. +// WithContext returns a copy of ctx with the receiver attached. The Logger +// attached to the provided Context (if any) will not be effected. If the +// receiver's log level is Disabled it will only be attached to the returned +// Context if the provided Context has a previously attached Logger. If the +// provided Context has no attached Logger, a Disabled Logger will not be +// attached. // -// For instance, to add a field to an existing logger in the context, use this +// Note: to modify the existing Logger attached to a Context (instead of +// replacing it in a new Context), use UpdateContext with the following // notation: // // ctx := r.Context() @@ -25,13 +30,9 @@ type ctxKey struct{} // 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 { - if lp == &l { - // Do not store same logger. - return ctx - } - } else if l.level == Disabled { + if _, ok := ctx.Value(ctxKey{}).(*Logger); !ok && l.level == Disabled { // Do not store disabled logger. return ctx } From 5bdc93f7eb6ae1e8a973d3b92b98c0d918b0fd03 Mon Sep 17 00:00:00 2001 From: Ted Lilley Date: Wed, 2 Nov 2022 20:35:19 -0400 Subject: [PATCH 21/22] Fix console formatter for timestampunixnano (#502) Co-authored-by: Ted Lilley --- console.go | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/console.go b/console.go index 9cc3285..8b0e0c6 100644 --- a/console.go +++ b/console.go @@ -348,15 +348,19 @@ func consoleDefaultFormatTimestamp(timeFormat string, noColor bool) Formatter { if err != nil { t = tt.String() } else { - var sec, nsec int64 = i, 0 + var sec, nsec int64 + switch TimeFieldFormat { - case TimeFormatUnixMs: - nsec = int64(time.Duration(i) * time.Millisecond) - sec = 0 + case TimeFormatUnixNano: + sec, nsec = 0, i case TimeFormatUnixMicro: - nsec = int64(time.Duration(i) * time.Microsecond) - sec = 0 + sec, nsec = 0, int64(time.Duration(i)*time.Microsecond) + case TimeFormatUnixMs: + sec, nsec = 0, int64(time.Duration(i)*time.Millisecond) + default: + sec, nsec = i, 0 } + ts := time.Unix(sec, nsec) t = ts.Format(timeFormat) } From 3543e9d94bc5ed088dd2d9ad1d19c7ccd0fa65f5 Mon Sep 17 00:00:00 2001 From: Pavel Gryaznov Date: Fri, 11 Nov 2022 14:15:40 +0100 Subject: [PATCH 22/22] parsing CAPS log levels (#506) --- log.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/log.go b/log.go index efd2a33..c8dbc42 100644 --- a/log.go +++ b/log.go @@ -105,6 +105,7 @@ import ( "io/ioutil" "os" "strconv" + "strings" ) // Level defines log levels. @@ -160,7 +161,7 @@ func (l Level) String() string { // 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 { + switch strings.ToLower(levelStr) { case LevelFieldMarshalFunc(TraceLevel): return TraceLevel, nil case LevelFieldMarshalFunc(DebugLevel):