diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index b9bcccf..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@v2 + - uses: actions/cache@v3.0.5 with: path: ~/go/pkg/mod key: ${{ runner.os }}-go-${{ hashFiles('**/go.sum') }} diff --git a/README.md b/README.md index 8a8d83e..91d4e38 100644 --- a/README.md +++ b/README.md @@ -4,7 +4,6 @@ opinionated defaults on zerolog - # Zero Allocation JSON Logger [![godoc](http://img.shields.io/badge/godoc-reference-blue.svg?style=flat)](https://godoc.org/tuxpa.in/a/zlog) [![license](http://img.shields.io/badge/license-MIT-red.svg?style=flat)](https://raw.githubusercontent.com/rs/zlog/master/LICENSE) [![Build Status](https://travis-ci.org/rs/zlog.svg?branch=master)](https://travis-ci.org/rs/zlog) [![Coverage](http://gocover.io/_badge/tuxpa.in/a/zlog)](http://gocover.io/tuxpa.in/a/zlog) @@ -418,7 +417,7 @@ log.Info().Msg("hello world") Equivalent of `Lshortfile`: ```go -zlog.CallerMarshalFunc = func(file string, line int) string { +zlog.CallerMarshalFunc = func(pc uintptr, file string, line int) string { short := file for i := len(file) - 1; i > 0; i-- { if file[i] == '/' { @@ -632,7 +631,11 @@ Most fields are also available in the slice format (`Strs` for `[]string`, `Errs ## Binary Encoding +<<<<<<< HEAD In addition to the default JSON encoding, `zlog` 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: +>>>>>>> github ```bash go build -tags binary_log . 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) +} diff --git a/console.go b/console.go index fdb3933..a05cec7 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 } @@ -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 { @@ -327,27 +337,31 @@ 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 { - t = ts.Format(timeFormat) + t = ts.Local().Format(timeFormat) } case json.Number: i, err := tt.Int64() 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).UTC() + + ts := time.Unix(sec, nsec) t = ts.Format(timeFormat) } } @@ -375,7 +389,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 { diff --git a/console_test.go b/console_test.go index 7d52c66..d90da79 100644 --- a/console_test.go +++ b/console_test.go @@ -108,13 +108,14 @@ func TestConsoleWriter(t *testing.T) { buf := &bytes.Buffer{} w := zlog.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 := zlog.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 := zlog.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) @@ -371,6 +375,55 @@ 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) + } + }) + + 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) { diff --git a/ctx.go b/ctx.go index 73a384a..067ad77 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 } diff --git a/diode/diode_test.go b/diode/diode_test.go index 36afbf9..3ffb6f8 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 diff --git a/event.go b/event.go index c631ab9..5362872 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 { @@ -744,11 +753,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 a8e8421..b9192b7 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 ( @@ -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 diff --git a/go.sum b/go.sum deleted file mode 100644 index 8cd353d..0000000 --- a/go.sum +++ /dev/null @@ -1,14 +0,0 @@ -github.com/coreos/go-systemd/v22 v22.4.0 h1:y9YHcjnjynCd/DVbg5j9L/33jQM3MxJlbj/zWskzfGU= -github.com/coreos/go-systemd/v22 v22.4.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= -github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= -github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= -github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= -github.com/mattn/go-isatty v0.0.16 h1:bq3VjFmv/sOjHtdEhmkEV4x1AJtvUvOJ2PFAZ5+peKQ= -github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= -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.4.0 h1:qd7wPTDkN6KQx2VmMBLrpHkiyQwgFXRnkOLacUiaSNY= -github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= -golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20220915200043-7b5979e65e41 h1:ohgcoMbSofXygzo6AD2I1kz3BFmW1QArPYTtwEM3UXc= -golang.org/x/sys v0.0.0-20220915200043-7b5979e65e41/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= diff --git a/hlog/hlog.go b/hlog/hlog.go index e91b01f..9cbc028 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 9c52417..06da6b6 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{ diff --git a/internal/json/time.go b/internal/json/time.go index 7a9ca62..e77ab53 100644 --- a/internal/json/time.go +++ b/internal/json/time.go @@ -7,9 +7,10 @@ import ( const ( // Import from zlog/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, ']') 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 diff --git a/journald/journald.go b/journald/journald.go index 4ed87ad..3a14399 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 { diff --git a/log.go b/log.go index 392a90d..08bb689 100644 --- a/log.go +++ b/log.go @@ -104,6 +104,7 @@ import ( "io/ioutil" "os" "strconv" + "strings" ) // Level defines log levels. @@ -159,7 +160,7 @@ func (l Level) String() string { // ParseLevel converts a level string into a zlog 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): diff --git a/log_test.go b/log_test.go index 0c27b41..27a2744 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) @@ -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) + } + }) + } +}