diff --git a/array_test.go b/array_test.go index 199e204..a584be8 100644 --- a/array_test.go +++ b/array_test.go @@ -26,6 +26,7 @@ func TestArray(t *testing.T) { Bytes([]byte("b")). Hex([]byte{0x1f}). RawJSON([]byte(`{"some":"json"}`)). + RawJSON([]byte(`{"longer":[1111,2222,3333,4444,5555]}`)). Time(time.Time{}). IPAddr(net.IP{192, 168, 0, 10}). IPPrefix(net.IPNet{IP: net.IP{127, 0, 0, 0}, Mask: net.CIDRMask(24, 32)}). @@ -53,7 +54,7 @@ func TestArray(t *testing.T) { }). Type(3.14) - 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","127.0.0.0/24","01:23:45:67:89:ab",{"Pub":"A","tag":"j"},{"name":"zot","age":-35},0,{"bar":"baz","n":1},null,"failure",{"error":"OOPS"},{"name":"zit","age":-22},"float64"]` + want := `[true,1,2,3,4,5,6,7,8,9,10,11.98122,12.987654321,"a","b","1f",{"some":"json"},{"longer":[1111,2222,3333,4444,5555]},"0001-01-01T00:00:00Z","192.168.0.10","127.0.0.0/24","01:23:45:67:89:ab",{"Pub":"A","tag":"j"},{"name":"zot","age":-35},0,{"bar":"baz","n":1},null,"failure",{"error":"OOPS"},{"name":"zit","age":-22},"float64"]` if got := decodeObjectToStr(a.write([]byte{})); got != want { t.Errorf("Array.write()\ngot: %s\nwant: %s", got, want) } diff --git a/benchmark_test.go b/benchmark_test.go index c526551..5f26097 100644 --- a/benchmark_test.go +++ b/benchmark_test.go @@ -184,6 +184,9 @@ func BenchmarkLogFieldType(b *testing.B) { "Object": func(e *Event) *Event { return e.Object("k", fixtures.Objects[0]) }, + "Objects": func(e *Event) *Event { + return e.Objects("k", fixtures.Objects) + }, "Timestamp": func(e *Event) *Event { return e.Timestamp() }, @@ -309,6 +312,9 @@ func BenchmarkContextFieldType(b *testing.B) { "Object": func(c Context) Context { return c.Object("k", fixtures.Objects[0]) }, + "Objects": func(c Context) Context { + return c.Objects("k", fixtures.Objects) + }, "Timestamp": func(c Context) Context { return c.Timestamp() }, diff --git a/binary_test.go b/binary_test.go index 1494698..f5d77f0 100644 --- a/binary_test.go +++ b/binary_test.go @@ -232,6 +232,7 @@ func (u User) MarshalZerologObject(e *Event) { type Users []User +// User implements LogObjectMarshaler func (uu Users) MarshalZerologArray(a *Array) { for _, u := range uu { a.Object(u) @@ -289,6 +290,25 @@ func ExampleEvent_Object() { // Output: {"foo":"bar","user":{"name":"John","age":35,"created":"0001-01-01T00:00:00Z"},"message":"hello world"} } +func ExampleContext_Objects() { + // In go, arrays are type invariant so even if you have a variable u of type []User array and User implements + // the LogObjectMarshaler interface, you cannot pass that to func that takes an []LogObjectMarshaler array in the + // Objects call. In 1.24+ it allows passing the variadic covariant slice (e.g. u...) but the unit test needs to + // work in earlier versions so we'll declare the array as []LogObjectMarshaler here. + u := []LogObjectMarshaler{User{"John", 35, time.Time{}}, User{"Bob", 55, time.Time{}}} + + dst := bytes.Buffer{} + log := New(&dst).With(). + Str("foo", "bar"). + Objects("users", u). + Logger() + + log.Log().Msg("hello world") + + fmt.Println(decodeIfBinaryToString(dst.Bytes())) + // Output: {"foo":"bar","users":[{"name":"John","age":35,"created":"0001-01-01T00:00:00Z"},{"name":"Bob","age":55,"created":"0001-01-01T00:00:00Z"}],"message":"hello world"} +} + func ExampleEvent_EmbedObject() { price := Price{val: 6449, prec: 2, unit: "$"} diff --git a/context.go b/context.go index fb9ff2a..9e24c16 100644 --- a/context.go +++ b/context.go @@ -64,6 +64,15 @@ func (c Context) Object(key string, obj LogObjectMarshaler) Context { return c } +// Object marshals an object that implement the LogObjectMarshaler interface. +func (c Context) Objects(key string, objs []LogObjectMarshaler) Context { + e := newEvent(LevelWriterAdapter{io.Discard}, 0) + e.Objects(key, objs) + c.l.context = enc.AppendObjectData(c.l.context, e.buf) + putEvent(e) + return c +} + // EmbedObject marshals and Embeds an object that implement the LogObjectMarshaler interface. func (c Context) EmbedObject(obj LogObjectMarshaler) Context { e := newEvent(LevelWriterAdapter{io.Discard}, 0) diff --git a/event.go b/event.go index 3151905..2c95c13 100644 --- a/event.go +++ b/event.go @@ -228,6 +228,22 @@ func (e *Event) Object(key string, obj LogObjectMarshaler) *Event { return e } +// Objects adds the field key with obj as an array of objects that implement the LogObjectMarshaler interface. +func (e *Event) Objects(key string, objs []LogObjectMarshaler) *Event { + if e == nil { + return e + } + e.buf = enc.AppendArrayStart(enc.AppendKey(e.buf, key)) + for i, obj := range objs { + e.buf = appendObject(e.buf, obj) + if i < (len(objs) - 1) { + e.buf = enc.AppendArrayDelim(e.buf) + } + } + e.buf = enc.AppendArrayEnd(e.buf) + return e +} + // 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() { diff --git a/event_test.go b/event_test.go index b5d5751..b601b87 100644 --- a/event_test.go +++ b/event_test.go @@ -5,6 +5,8 @@ package zerolog import ( "bytes" "errors" + "io" + "os" "strings" "testing" ) @@ -169,7 +171,7 @@ func TestEvent_WithNilEvent(t *testing.T) { return e.RawCBOR("k", fixtures.RawCBOR) }, "RawJSON": func() *Event { - return e.RawJSON("k", fixtures.RawJSON) + return e.RawJSON("k", fixtures.RawJSONs[0]) }, "Str": func() *Event { return e.Str("k", fixtures.Strings[0]) @@ -221,6 +223,9 @@ func TestEvent_WithNilEvent(t *testing.T) { "Object": func() *Event { return e.Object("k", fixtures.Objects[0]) }, + "Objects": func() *Event { + return e.Objects("k", fixtures.Objects) + }, "EmbedObject": func() *Event { return e.EmbedObject(fixtures.Objects[0]) }, @@ -301,3 +306,78 @@ func TestEvent_MsgFunc(t *testing.T) { t.Errorf("Event.MsgFunc() = %q, want %q", got, want) } } + +func TestEvent_DoneHandler(t *testing.T) { + e := newEvent(nil, InfoLevel) + + // Set up a done handler to capture calls + var called bool + var capturedMsg string + e.done = func(msg string) { + called = true + capturedMsg = msg + } + + // Trigger msg via Msg + e.Msg("test message") + + // Assert the handler was called with the correct message + if !called { + t.Error("Done handler was not called") + } + if capturedMsg != "test message" { + t.Errorf("Expected message 'test message', got '%s'", capturedMsg) + } +} + +type badLevelWriter struct { + err error +} + +func (w *badLevelWriter) WriteLevel(level Level, p []byte) (n int, err error) { + return 0, w.err +} + +func (w *badLevelWriter) Write(p []byte) (n int, err error) { + return 0, w.err +} + +func TestEvent_Msg_ErrorHandlerNil(t *testing.T) { + // Save original ErrorHandler and restore after test + originalErrorHandler := ErrorHandler + ErrorHandler = nil + defer func() { ErrorHandler = originalErrorHandler }() + + // Create a LevelWriter that always returns an error + mockWriter := &badLevelWriter{err: errors.New("write error")} + + e := newEvent(mockWriter, InfoLevel) + if e == nil { + t.Fatal("Event should not be nil") + } + + // Capture stderr + oldStderr := os.Stderr + r, w, err := os.Pipe() + if err != nil { + t.Fatal(err) + } + os.Stderr = w + + // Call Msg to trigger write error + e.Msg("test message") + + // Restore stderr and read captured output + w.Close() + os.Stderr = oldStderr + captured, err := io.ReadAll(r) + if err != nil { + t.Fatal(err) + } + + // Assert the error message was printed to stderr + expected := "zerolog: could not write event: write error\n" + if string(captured) != expected { + t.Errorf("Expected stderr output %q, got %q", expected, string(captured)) + } +} diff --git a/fields.go b/fields.go index c355079..5f7ef5a 100644 --- a/fields.go +++ b/fields.go @@ -113,6 +113,15 @@ func appendFieldList(dst []byte, kvList []interface{}, stack bool) []byte { } } dst = enc.AppendArrayEnd(dst) + case []LogObjectMarshaler: + dst = enc.AppendArrayStart(dst) + for i, obj := range val { + dst = appendObject(dst, obj) + if i < (len(val) - 1) { + dst = enc.AppendArrayDelim(dst) + } + } + dst = enc.AppendArrayEnd(dst) case bool: dst = enc.AppendBool(dst, val) case int: diff --git a/fixtures_test.go b/fixtures_test.go index 49580d8..a7c32a7 100644 --- a/fixtures_test.go +++ b/fixtures_test.go @@ -47,9 +47,9 @@ type fieldFixtures struct { IPAddrs []net.IP IPPfxs []net.IPNet MACAddr net.HardwareAddr - Objects []fixtureObj + Objects []LogObjectMarshaler RawCBOR []byte - RawJSON []byte + RawJSONs [][]byte Stringers []fmt.Stringer Strings []string Times []time.Time @@ -101,17 +101,17 @@ func makeFieldFixtures() *fieldFixtures { {"I", "b", 3}, {"J", "a", 4}, } - objects := []fixtureObj{ - {"a", "z", 1}, - {"b", "y", 2}, - {"c", "x", 3}, - {"d", "w", 4}, - {"e", "v", 5}, - {"f", "u", 6}, - {"g", "t", 7}, - {"h", "s", 8}, - {"i", "r", 9}, - {"j", "q", 10}, + objects := []LogObjectMarshaler{ + fixtureObj{"a", "z", 1}, + fixtureObj{"b", "y", 2}, + fixtureObj{"c", "x", 3}, + fixtureObj{"d", "w", 4}, + fixtureObj{"e", "v", 5}, + fixtureObj{"f", "u", 6}, + fixtureObj{"g", "t", 7}, + fixtureObj{"h", "s", 8}, + fixtureObj{"i", "r", 9}, + fixtureObj{"j", "q", 10}, } ipAddrV4 := net.IP{192, 168, 0, 1} ipAddrV6 := net.IP{0x20, 0x01, 0x0d, 0xb8, 0x85, 0xa3, 0x00, 0x00, 0x00, 0x00, 0x8a, 0x2e, 0x03, 0x70, 0x73, 0x34} @@ -123,7 +123,7 @@ func makeFieldFixtures() *fieldFixtures { errs := []error{errors.New("a"), errors.New("b"), errors.New("c"), errors.New("d"), errors.New("e"), nil, errorObjectMarshalerImpl{fmt.Errorf("oops")}} ctx := context.Background() stringers := []fmt.Stringer{ipAddrs[0], durations[0]} - rawJSON := []byte(`{"some":"json"}`) + rawJSONs := [][]byte{[]byte(`{"some":"json"}`), []byte(`{"longer":[1111,2222,3333,4444,5555]}`)} rawCBOR := []byte{0xA1, 0x64, 0x73, 0x6F, 0x6D, 0x65, 0x64, 0x61, 0x74, 0x61} // {"some":"data"} return &fieldFixtures{ @@ -150,7 +150,7 @@ func makeFieldFixtures() *fieldFixtures { MACAddr: macAddr, Objects: objects, RawCBOR: rawCBOR, - RawJSON: rawJSON, + RawJSONs: rawJSONs, Stringers: stringers, Strings: strings, Times: times, diff --git a/internal/cbor/string_test.go b/internal/cbor/string_test.go index 439f1ae..aa88d34 100644 --- a/internal/cbor/string_test.go +++ b/internal/cbor/string_test.go @@ -4,6 +4,8 @@ import ( "bytes" "encoding/hex" "testing" + + "github.com/rs/zerolog/internal" ) var encodeStringTests = []struct { @@ -129,13 +131,50 @@ func TestAppendStrings(t *testing.T) { } got = enc.AppendStrings([]byte{}, array) if !bytes.Equal(got, want) { - t.Errorf("AppendStrings(%v)\ngot: 0x%s\nwant: 0x%s", + t.Errorf("AppendStrings(%v)\ngot: %s\nwant: %s", array, hex.EncodeToString(got), hex.EncodeToString(want)) } } +func TestAppendStringer(t *testing.T) { + oldJSONMarshalFunc := JSONMarshalFunc + defer func() { + JSONMarshalFunc = oldJSONMarshalFunc + }() + + JSONMarshalFunc = func(v interface{}) ([]byte, error) { + return internal.InterfaceMarshalFunc(v) + } + + for _, tt := range internal.EncodeStringerTests { + got := enc.AppendStringer([]byte{}, tt.In) + want := []byte(tt.Binary) + if !bytes.Equal(got, want) { + t.Errorf("AppendStrings(%v)\ngot: %s\nwant: %s", + tt.In, + hex.EncodeToString(got), + hex.EncodeToString(want)) + } + } +} + +func TestAppendStringers(t *testing.T) { + for _, tt := range internal.EncodeStringersTests { + want := make([]byte, 0) + want = append(want, []byte(tt.Binary)...) + + got := enc.AppendStringers([]byte{}, tt.In) + if !bytes.Equal(got, want) { + t.Errorf("AppendStrings(%v)\ngot: %s\nwant: %s", + tt, + hex.EncodeToString(got), + hex.EncodeToString(want)) + } + } +} + func TestAppendBytes(t *testing.T) { for _, tt := range encodeByteTests { b := enc.AppendBytes([]byte{}, tt.plain) @@ -155,6 +194,7 @@ func TestAppendBytes(t *testing.T) { t.Errorf("appendString(%q) = %#q, want %#q", inp, got, want) } } + func BenchmarkAppendString(b *testing.B) { tests := map[string]string{ "NoEncoding": `aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa`, diff --git a/internal/testcases.go b/internal/testcases.go index ccfeb2b..654ff1d 100644 --- a/internal/testcases.go +++ b/internal/testcases.go @@ -308,22 +308,24 @@ var EncodeStringsTests = []struct { } var EncodeStringerTests = []struct { - In fmt.Stringer - Out string + In fmt.Stringer + Out string + Binary string }{ - {nil, `null`}, - {fmt.Stringer(nil), `null`}, - {net.IPv4bcast, `"255.255.255.255"`}, + {nil, `null`, "\xf6"}, + {fmt.Stringer(nil), `null`, "\xf6"}, + {net.IPv4bcast, `"255.255.255.255"`, "\x6f\x32\x35\x35\x2e\x32\x35\x35\x2e\x32\x35\x35\x2e\x32\x35\x35"}, } var EncodeStringersTests = []struct { - In []fmt.Stringer - Out string + In []fmt.Stringer + Out string + Binary string }{ - {nil, `[]`}, - {[]fmt.Stringer{}, `[]`}, - {[]fmt.Stringer{net.IPv4bcast}, `["255.255.255.255"]`}, - {[]fmt.Stringer{net.IPv4allsys, net.IPv4allrouter}, `["224.0.0.1","224.0.0.2"]`}, + {nil, `[]`, "\x9f\xff"}, + {[]fmt.Stringer{}, `[]`, "\x9f\xff"}, + {[]fmt.Stringer{net.IPv4bcast}, `["255.255.255.255"]`, "\x9f\x6f255.255.255.255\xff"}, + {[]fmt.Stringer{net.IPv4allsys, net.IPv4allrouter}, `["224.0.0.1","224.0.0.2"]`, "\x9f\x69224.0.0.1\x69224.0.0.2\xff"}, } var TimeIntegerTestcases = []struct { diff --git a/log/log_example_test.go b/log/log_example_test.go index 8ed323b..dbfdab0 100644 --- a/log/log_example_test.go +++ b/log/log_example_test.go @@ -1,8 +1,11 @@ +//go:build !binary_log // +build !binary_log package log_test import ( + "bytes" + "context" "errors" "flag" "os" @@ -119,7 +122,13 @@ func ExampleFatal() { // Outputs: {"level":"fatal","time":1199811905,"error":"A repo man spends his life getting into tense situations","service":"myservice","message":"Cannot start myservice"} } -// TODO: Panic +// Example of a log at a particular "level" (in this case, "panic") +func ExamplePanic() { + setup() + + log.Panic().Msg("Cannot start") + // Outputs: {"level":"panic","time":1199811905,"message":"Cannot start"} then panics +} // This example uses command-line flags to demonstrate various outputs // depending on the chosen log level. @@ -147,16 +156,91 @@ func Example() { // Output: {"level":"info","time":1199811905,"message":"This message appears when log level set to Debug or Info"} } -// TODO: Output +// Example of using the Output function in the log package to change the output destination +func ExampleOutput() { + setup() -// TODO: With + out := &bytes.Buffer{} + tee := log.Output(out) + tee.Info().Msg("hello world") + written := out.Len() -// TODO: Level + log.Info().Int("bytes", written).Msg("wrote") + // Output: {"level":"info","bytes":59,"time":1199811905,"message":"wrote"} +} -// TODO: Sample +// Example of using the With function to add context fields +func ExampleWith() { + setup() -// TODO: Hook + // you have to assign the result of With() to a new Logger and can't inline the level calls + // because they need a *Logger receiver + augmented := log.With().Str("service", "myservice").Logger() + augmented.Info().Msg("hello world") + // Output: {"level":"info","service":"myservice","time":1199811905,"message":"hello world"} +} -// TODO: WithLevel +// Example of using the Level function to set the log level +func ExampleLevel() { + setup() -// TODO: Ctx + // you have to assign the result of Level() to a new Logger and can't inline the level calls + // because they need a *Logger receiver + leveled := log.Level(zerolog.ErrorLevel) + leveled.Info().Msg("hello world") + leveled.Error().Msg("I said HELLO") + // Output: {"level":"error","time":1199811905,"message":"I said HELLO"} +} + +type valueKeyType int + +var valueKey valueKeyType = 42 + +var captainHook = zerolog.HookFunc(func(e *zerolog.Event, l zerolog.Level, msg string) { + e.Interface("key", e.GetCtx().Value(valueKey)) + e.Bool("is_error", l > zerolog.ErrorLevel) + e.Int("msg_len", len(msg)) +}) + +// Example of using the Logger Hook function to add hooks +func ExampleLogger_Hook() { + setup() + + hooked := log.Hook(captainHook) + hooked.Info().Msg("watch out!") + // Output: {"level":"info","time":1199811905,"key":null,"is_error":false,"msg_len":10,"message":"watch out!"} +} + +// Example of using the WithLevel function to set the log level +func ExampleWithLevel() { + setup() + + // you have to assign the result of Level() to a new Logger and can't inline the level calls + // because they need a *Logger receiver + event := log.WithLevel(zerolog.ErrorLevel) + event.Msg("taxes are due") + // Output: {"level":"error","time":1199811905,"message":"taxes are due"} +} + +// Example of using the Ctx function in the log package to log with context +func ExampleCtx() { + setup() + + hooked := log.Hook(captainHook) + ctx := context.WithValue(context.Background(), valueKey, "12345") + logger := hooked.With().Ctx(ctx).Logger() + log.Ctx(logger.WithContext(ctx)).Info().Msg("hello world") + // Output: {"level":"info","time":1199811905,"key":"12345","is_error":false,"msg_len":11,"message":"hello world"} +} + +// Example of using the Sample function in the log package to set a sampler +func ExampleSample() { + setup() + + sampled := log.Sample(&zerolog.BasicSampler{N: 2}) + sampled.Info().Msg("hello world") + sampled.Info().Msg("I said, hello world") + sampled.Info().Msg("Can you here me now world") + // Output: {"level":"info","time":1199811905,"message":"hello world"} + // {"level":"info","time":1199811905,"message":"Can you here me now world"} +} diff --git a/log_example_test.go b/log_example_test.go index 219f691..7b7af53 100644 --- a/log_example_test.go +++ b/log_example_test.go @@ -435,6 +435,20 @@ func ExampleContext_Object() { // Output: {"foo":"bar","user":{"name":"John","age":35,"created":"0001-01-01T00:00:00Z"},"message":"hello world"} } +func ExampleContext_Objects() { + // User implements zerolog.LogObjectMarshaler + u := User{"John", 35, time.Time{}} + u2 := User{"Bono", 54, time.Time{}} + + log := zerolog.New(os.Stdout).With(). + Str("foo", "bar"). + Objects("users", []zerolog.LogObjectMarshaler{u, u2}). + Logger() + + log.Log().Msg("hello world") + + // Output: {"foo":"bar","users":[{"name":"John","age":35,"created":"0001-01-01T00:00:00Z"},{"name":"Bono","age":54,"created":"0001-01-01T00:00:00Z"}],"message":"hello world"} +} func ExampleContext_EmbedObject() { diff --git a/log_test.go b/log_test.go index 3c4ffa8..7efde9f 100644 --- a/log_test.go +++ b/log_test.go @@ -3,6 +3,7 @@ package zerolog import ( "bytes" "context" + "encoding/json" "errors" "fmt" "math" @@ -162,7 +163,7 @@ func TestWithPlurals(t *testing.T) { Strs("strings_nil", nil). Stringers("stringers", []fmt.Stringer{net.IP{127, 0, 0, 1}, nil}). Stringers("stringers_nil", nil). - Errs("errs", []error{errors.New("some error"), errors.New("some other error")}). + Errs("errs", []error{errors.New("some error"), errors.New("some other error"), nil, errorObjectMarshalerImpl{fmt.Errorf("oops")}}). Bools("bool", []bool{true, false}). Ints("int", []int{1, 2}). Ints8("int8", []int8{2, 3}). @@ -181,7 +182,7 @@ func TestWithPlurals(t *testing.T) { log := ctx.Logger() log.Log().Msg("") if got, want := decodeIfBinaryToString(out.Bytes()), - `{"strings":["foo","bar"],"strings_nil":[],"stringers":["127.0.0.1",null],"stringers_nil":null,"errs":["some error","some other error"],"bool":[true,false],"int":[1,2],"int8":[2,3],"int16":[3,4],"int32":[4,5],"int64":[5,6],"uint":[6,7],"uint8":[7,8],"uint16":[8,9],"uint32":[9,10],"uint64":[10,11],"float32":[1.1,2.2],"float64":[2.2,3.3],"time":["0001-02-03T00:00:00Z","0005-06-07T00:00:00Z"],"dur":[1000,2000]}`+"\n"; got != want { + `{"strings":["foo","bar"],"strings_nil":[],"stringers":["127.0.0.1",null],"stringers_nil":null,"errs":["some error","some other error",null,{"error":"OOPS"}],"bool":[true,false],"int":[1,2],"int8":[2,3],"int16":[3,4],"int32":[4,5],"int64":[5,6],"uint":[6,7],"uint8":[7,8],"uint16":[8,9],"uint32":[9,10],"uint64":[10,11],"float32":[1.1,2.2],"float64":[2.2,3.3],"time":["0001-02-03T00:00:00Z","0005-06-07T00:00:00Z"],"dur":[1000,2000]}`+"\n"; got != want { t.Errorf("invalid log output:\ngot: %v\nwant: %v", got, want) } } @@ -228,12 +229,73 @@ func TestFieldsMap(t *testing.T) { "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}, + "ipnet": net.IPNet{IP: net.IP{0x20, 0x01, 0x0d, 0xb8, 0x85, 0xa3, 0x00, 0x00, 0x00, 0x00, 0x8a, 0x2e, 0x03, 0x70, 0x73, 0x34}, Mask: net.CIDRMask(64, 128)}, + "macaddr": net.HardwareAddr{0x00, 0x1A, 0x2B, 0x3C, 0x4D, 0x5E}, "dur": 1 * time.Second, "time": time.Time{}, "obj": fixtureObj{"a", "b", 1}, + "objs": []LogObjectMarshaler{fixtureObj{"a", "b", 1}, fixtureObj{"c", "d", 2}}, "any": struct{ A string }{"test"}, + "raw": json.RawMessage(`{"some":"json"}`), }).Msg("") - if got, want := decodeIfBinaryToString(out.Bytes()), `{"any":{"A":"test"},"bool":true,"bytes":"bar","dur":1000,"error":"some error","float32":11,"float64":12,"int":1,"int16":3,"int32":4,"int64":5,"int8":2,"ipv6":"2001:db8:85a3::8a2e:370:7334","nil":null,"obj":{"Pub":"a","Tag":"b","priv":1},"string":"foo","time":"0001-01-01T00:00:00Z","uint":6,"uint16":8,"uint32":9,"uint64":10,"uint8":7}`+"\n"; got != want { + if got, want := decodeIfBinaryToString(out.Bytes()), `{"any":{"A":"test"},"bool":true,"bytes":"bar","dur":1000,"error":"some error","float32":11,"float64":12,"int":1,"int16":3,"int32":4,"int64":5,"int8":2,"ipnet":"2001:db8:85a3::8a2e:370:7334/64","ipv6":"2001:db8:85a3::8a2e:370:7334","macaddr":"00:1a:2b:3c:4d:5e","nil":null,"obj":{"Pub":"a","Tag":"b","priv":1},"objs":[{"Pub":"a","Tag":"b","priv":1},{"Pub":"c","Tag":"d","priv":2}],"raw":{"some":"json"},"string":"foo","time":"0001-01-01T00:00:00Z","uint":6,"uint16":8,"uint32":9,"uint64":10,"uint8":7}`+"\n"; got != want { + t.Errorf("invalid log output:\ngot: %v\nwant: %v", got, want) + } +} +func TestFieldsMap_Arrays(t *testing.T) { + out := &bytes.Buffer{} + log := New(out) + log.Log().Fields(map[string]interface{}{ + "strings": []string{"foo"}, + "bools": []bool{true}, + "errors": []error{errors.New("some error")}, + "ints": []int{1}, + "ints8": []int8{1}, + "ints16": []int16{3}, + "ints32": []int32{4}, + "ints64": []int64{5}, + "uints": []uint{6}, + "uint8s": []uint8{44}, + "uints16": []uint16{8}, + "uints32": []uint32{9}, + "uints64": []uint64{10}, + "floats32": []float32{11}, + "floats64": []float64{12}, + "ipv6s": []net.IP{{0x20, 0x01, 0x0d, 0xb8, 0x85, 0xa3, 0x00, 0x00, 0x00, 0x00, 0x8a, 0x2e, 0x03, 0x70, 0x73, 0x34}}, + "ipnets": []net.IPNet{{IP: net.IP{0x20, 0x01, 0x0d, 0xb8, 0x85, 0xa3, 0x00, 0x00, 0x00, 0x00, 0x8a, 0x2e, 0x03, 0x70, 0x73, 0x34}, Mask: net.CIDRMask(64, 128)}}, + "macaddrs": []net.HardwareAddr{{0x00, 0x1A, 0x2B, 0x3C, 0x4D, 0x5E}}, + "durs": []time.Duration{1 * time.Second}, + "times": []time.Time{{}}, + "objs": []fixtureObj{{"a", "b", 1}}, + }).Msg("") + // special case: []uint8 is logged as base64 string so we use "," for 44 + if got, want := decodeIfBinaryToString(out.Bytes()), `{"bools":[true],"durs":[1000],"errors":["some error"],"floats32":[11],"floats64":[12],"ints":[1],"ints16":[3],"ints32":[4],"ints64":[5],"ints8":[1],"ipnets":["2001:db8:85a3::8a2e:370:7334/64"],"ipv6s":["2001:db8:85a3::8a2e:370:7334"],"macaddrs":["ABorPE1e"],"objs":[{"Pub":"a","tag":"b"}],"strings":["foo"],"times":["0001-01-01T00:00:00Z"],"uint8s":",","uints":[6],"uints16":[8],"uints32":[9],"uints64":[10]}`+"\n"; got != want { + t.Errorf("invalid log output:\ngot: %v\nwant: %v", got, want) + } +} +func TestFieldsErr(t *testing.T) { + var err error = nil + out := &bytes.Buffer{} + log := New(out) + log.Log().Fields(map[string]interface{}{ + "nil": nil, + "nilerror": err, + "error": errors.New("some error"), + "loggable": loggableError{errors.New("loggable")}, + "marshal": errorObjectMarshalerImpl{fmt.Errorf("oops")}, + }).Msg("") + if got, want := decodeIfBinaryToString(out.Bytes()), `{"error":"some error","loggable":{"message":"loggable loggableError"},"marshal":{"error":"OOPS"},"nil":null,"nilerror":null}`+"\n"; got != want { + t.Errorf("invalid log output:\ngot: %v\nwant: %v", got, want) + } +} +func TestFieldsErrs(t *testing.T) { + var err error = nil + out := &bytes.Buffer{} + log := New(out) + log.Log().Fields(map[string]interface{}{ + "errors": []error{errors.New("some error"), nil, err, loggableError{errors.New("loggable")}, errorObjectMarshalerImpl{fmt.Errorf("oops")}}, + }).Msg("") + if got, want := decodeIfBinaryToString(out.Bytes()), `{"errors":["some error",null,null,{"message":"loggable loggableError"},{"error":"OOPS"}]}`+"\n"; got != want { t.Errorf("invalid log output:\ngot: %v\nwant: %v", got, want) } } @@ -809,7 +871,7 @@ func (l loggableError) MarshalZerologObject(e *Event) { if l.error == nil { return } - e.Str("message", l.error.Error()+": loggableError") + e.Str("message", l.error.Error()+" loggableError") } type nonLoggable struct { @@ -817,62 +879,6 @@ type nonLoggable struct { how int what string } - -func TestErrorMarshalFunc_None(t *testing.T) { - // test default behaviour - testErrorMarshalFunc(t, nil, []string{ - "default", - `{"message":"msg"}`, - `{"error":"err","message":"msg"}`, - `{"error":{"message":"err: loggableError"},"message":"msg"}`, - `{"errs":[],"message":"msg"}`, - `{"errs":["foo","bar"],"message":"msg"}`, - }) -} -func TestErrorMarshalFunc_AppendedString(t *testing.T) { - // test returning an appended string from ErrorMarshalFunc - testErrorMarshalFunc(t, func(err error) interface{} { - if err == nil { - return nil - } - return err.Error() + ": marshaled string" - }, []string{ - "appended string", - `{"message":"msg"}`, - `{"error":"err: marshaled string","message":"msg"}`, - `{"error":"err: marshaled string","message":"msg"}`, - `{"errs":[],"message":"msg"}`, - `{"errs":["foo: marshaled string","bar: marshaled string"],"message":"msg"}`, - }) -} -func TestErrorMarshalFunc_NilError(t *testing.T) { - // test returning an nil error from ErrorMarshalFunc - testErrorMarshalFunc(t, func(err error) interface{} { - return error(nil) - }, []string{ - "nil error", - `{"message":"msg"}`, - `{"message":"msg"}`, - `{"message":"msg"}`, - `{"errs":[],"message":"msg"}`, - `{"errs":[null,null],"message":"msg"}`, - }) -} - -func TestErrorMarshalFunc_UntypedNil(t *testing.T) { - // test returning an untyped nil from ErrorMarshalFunc - testErrorMarshalFunc(t, func(err error) interface{} { - return nil - }, []string{ - "untyped nil", - `{"message":"msg"}`, - `{"message":"msg"}`, - `{"message":"msg"}`, - `{"errs":[],"message":"msg"}`, - `{"errs":[null,null],"message":"msg"}`, - }) -} - type wrappedError struct { error msg string @@ -885,6 +891,81 @@ func (w wrappedError) Error() string { return w.error.Error() + ": " + w.msg } +func TestErrorMarshalFunc_Default(t *testing.T) { + // test default behaviour + testErrorMarshalFunc(t, nil, "default", + "", + "null", + + `"zot"`, + `"zot"`, + + `{"message":"log loggableError"}`, + `{"message":"log loggableError"}`, + + "[]", + `"foo","bar"`, + ) +} +func TestErrorMarshalFunc_AppendedString(t *testing.T) { + // test returning an appended string from ErrorMarshalFunc + testErrorMarshalFunc(t, func(err error) interface{} { + if err == nil { + return nil + } + return err.Error() + ": marshaled" + }, "appended string", + "", + "null", + + `"zot: marshaled"`, + `"zot: marshaled"`, + + `"log: marshaled"`, + `{"message":"log loggableError"}`, + + "[]", + `"foo: marshaled","bar: marshaled"`, + ) +} +func TestErrorMarshalFunc_NilError(t *testing.T) { + // test returning an nil error from ErrorMarshalFunc + testErrorMarshalFunc(t, func(err error) interface{} { + return error(nil) + }, "nil error", + "", + "null", + + "", + "null", + + "", + `{"message":"log loggableError"}`, + + "[]", + "null,null", + ) +} + +func TestErrorMarshalFunc_UntypedNil(t *testing.T) { + // test returning an untyped nil from ErrorMarshalFunc + testErrorMarshalFunc(t, func(err error) interface{} { + return nil + }, "untyped nil", + "", + "null", + + "", + "null", + + "", + `{"message":"log loggableError"}`, + + "[]", + "null,null", + ) +} + func TestErrorMarshalFunc_WrappedError(t *testing.T) { // test returning an wrapped error from ErrorMarshalFunc testErrorMarshalFunc(t, func(err error) interface{} { @@ -895,41 +976,56 @@ func TestErrorMarshalFunc_WrappedError(t *testing.T) { } else { return wrappedError{err, "addendum"} } - }, []string{ - "wrapped error", - `{"message":"msg"}`, - `{"error":"err: addendum","message":"msg"}`, - `{"error":"err: addendum","message":"msg"}`, - `{"errs":[],"message":"msg"}`, - `{"errs":["foo: addendum","bar: addendum"],"message":"msg"}`, - }) + }, "wrapped error", + "", + "null", + + `"zot: addendum"`, + `"zot: addendum"`, + + `"log: addendum"`, + `{"message":"log loggableError"}`, + + "[]", + `"foo: addendum","bar: addendum"`, + ) } func TestErrorMarshalFunc_LoggableType(t *testing.T) { // test returning a loggable type from ErrorMarshalFunc testErrorMarshalFunc(t, func(err error) interface{} { return loggableError{err} - }, []string{ - "loggable type", - `{"error":{},"message":"msg"}`, - `{"error":{"message":"err: loggableError"},"message":"msg"}`, - `{"error":{"message":"err: loggableError"},"message":"msg"}`, - `{"errs":[],"message":"msg"}`, - `{"errs":[{"message":"foo: loggableError"},{"message":"bar: loggableError"}],"message":"msg"}`, - }) + }, "loggable type", + "{}", + "null", + + `{"message":"zot loggableError"}`, + `{"message":"zot loggableError"}`, + + `{"message":"log loggableError"}`, + `{"message":"log loggableError"}`, + + "[]", + `{"message":"foo loggableError"},{"message":"bar loggableError"}`, + ) } func TestErrorMarshalFunc_String(t *testing.T) { // test returning a string type from ErrorMarshalFunc testErrorMarshalFunc(t, func(err error) interface{} { return "i'm an err" // return just a string - }, []string{ - "string type", - `{"error":"i'm an err","message":"msg"}`, - `{"error":"i'm an err","message":"msg"}`, - `{"error":"i'm an err","message":"msg"}`, - `{"errs":[],"message":"msg"}`, - `{"errs":["i'm an err","i'm an err"],"message":"msg"}`, - }) + }, "string type", + `"i'm an err"`, + "null", + + `"i'm an err"`, + `"i'm an err"`, + + `"i'm an err"`, + `{"message":"log loggableError"}`, + + "[]", + `"i'm an err","i'm an err"`, + ) } func TestErrorMarshalFunc_NonLoggableType(t *testing.T) { @@ -939,17 +1035,59 @@ func TestErrorMarshalFunc_NonLoggableType(t *testing.T) { return nil } return nonLoggable{where: "here", how: 42, what: err.Error()} - }, []string{ - "non-loggable type", - `{"message":"msg"}`, - `{"error":{},"message":"msg"}`, - `{"error":{},"message":"msg"}`, - `{"errs":[],"message":"msg"}`, - `{"errs":[{},{}],"message":"msg"}`, - }) + }, "non-loggable type", + "", + "null", + + "{}", + "{}", + + "{}", + `{"message":"log loggableError"}`, + + "[]", + "{},{}", + ) } -func testErrorMarshalFunc(t *testing.T, errFunc func(err error) interface{}, wants []string) { +func TestErrorMarshalFunc_NilMarshal(t *testing.T) { + // test returning a nil from ErrorMarshalFunc + testErrorMarshalFunc(t, func(err error) interface{} { + var nilerr error = nil + return nilerr + }, "nil-marshal", + "", + "null", + + "", + "null", + + "", + `{"message":"log loggableError"}`, + + "[]", + "null,null", + ) +} + +func testErrorMarshalFunc(t *testing.T, + errFunc func(err error) interface{}, + testcase string, + + whenNil string, + whenNilField string, + + hasValue string, + hasValueField string, + + whenLoggable string, + whenLoggableField string, + + errsNilValue string, + errsValue string, +) { + const suffix = `"message":"msg"}` + if errFunc != nil { originalErrorMarshalFunc := ErrorMarshalFunc defer func() { @@ -959,58 +1097,97 @@ func testErrorMarshalFunc(t *testing.T, errFunc func(err error) interface{}, wan ErrorMarshalFunc = errFunc } - testcase := wants[0] var err error + wantNil := `{` + if whenNil != "" { + wantNil = wantNil + `"error":` + whenNil + `,` + } + wantNil = wantNil + suffix + wantNilField := `{"err":` + whenNilField + `,` + suffix err = nil - testContextErrorMarshalFunc(t, testcase+" / ctx.Err(nil)", wants[1], func(ctx Context) Context { + testContextErrorMarshalFunc(t, testcase+" / context.Err(nil)", wantNil, func(ctx Context) Context { ctx = ctx.Err(err) return ctx }) - testEventErrorMarshalFunc(t, testcase+" / e.Err(nil)", wants[1], func(e *Event) *Event { + testEventErrorMarshalFunc(t, testcase+" / event.Err(nil)", wantNil, func(e *Event) *Event { e.Err(err) return e }) + testFieldsErrorMarshalFunc(t, testcase+" / field.Err(nil)", wantNilField, func(e *Event) *Event { + e.Fields(map[string]interface{}{"err": err}) + return e + }) - err = errors.New("err") - testContextErrorMarshalFunc(t, testcase+" / ctx.Err(error)", wants[2], func(ctx Context) Context { + wantErr := `{` + if hasValue != "" { + wantErr = wantErr + `"error":` + hasValue + `,` + } + wantErr = wantErr + suffix + wantErrField := `{"err":` + hasValueField + `,` + suffix + err = errors.New("zot") + testContextErrorMarshalFunc(t, testcase+" / context.Err(error)", wantErr, func(ctx Context) Context { ctx = ctx.Err(err) return ctx }) - testEventErrorMarshalFunc(t, testcase+" / e.Err(error)", wants[2], func(e *Event) *Event { + testEventErrorMarshalFunc(t, testcase+" / event.Err(error)", wantErr, func(e *Event) *Event { e.Err(err) return e }) + testFieldsErrorMarshalFunc(t, testcase+" / field.Err(error)", wantErrField, func(e *Event) *Event { + e.Fields(map[string]interface{}{"err": err}) + return e + }) - err = loggableError{errors.New("err")} - testContextErrorMarshalFunc(t, testcase+" / ctx.Err(loggable)", wants[3], func(ctx Context) Context { + wantLoggable := `{` + if whenLoggable != "" { + wantLoggable = wantLoggable + `"error":` + whenLoggable + `,` + } + wantLoggable = wantLoggable + suffix + wantLoggableField := `{"err":` + whenLoggableField + `,` + suffix + err = loggableError{errors.New("log")} + testContextErrorMarshalFunc(t, testcase+" / context.Err(loggable)", wantLoggable, func(ctx Context) Context { ctx = ctx.Err(err) return ctx }) - testEventErrorMarshalFunc(t, testcase+" / e.Err(loggable)", wants[3], func(e *Event) *Event { + testEventErrorMarshalFunc(t, testcase+" / event.Err(loggable)", wantLoggable, func(e *Event) *Event { e.Err(err) return e }) + testFieldsErrorMarshalFunc(t, testcase+" / field.Err(loggable)", wantLoggableField, func(e *Event) *Event { + e.Fields(map[string]interface{}{"err": err}) + return e + }) + wantErrsNil := `{"errs":` + errsNilValue + `,` + suffix var errs []error = nil - testContextErrorMarshalFunc(t, testcase+" / ctx.Errs(nil)", wants[4], func(ctx Context) Context { + testContextErrorMarshalFunc(t, testcase+" / context.Errs(nil)", wantErrsNil, func(ctx Context) Context { ctx = ctx.Errs("errs", errs) return ctx }) - testEventErrorMarshalFunc(t, testcase+" / e.Errs(nil)", wants[4], func(e *Event) *Event { + testEventErrorMarshalFunc(t, testcase+" / event.Errs(nil)", wantErrsNil, func(e *Event) *Event { e.Errs("errs", errs) return e }) + testFieldsErrorMarshalFunc(t, testcase+" / field.Errs(nil)", wantErrsNil, func(e *Event) *Event { + e.Fields(map[string]interface{}{"errs": errs}) + return e + }) + wantErrs := `{"errs":[` + errsValue + `],` + suffix errs = []error{errors.New("foo"), errors.New("bar")} - testContextErrorMarshalFunc(t, testcase+" / ctx.Errs([])", wants[5], func(ctx Context) Context { + testContextErrorMarshalFunc(t, testcase+" / context.Errs([])", wantErrs, func(ctx Context) Context { ctx = ctx.Errs("errs", []error{errors.New("foo"), errors.New("bar")}) return ctx }) - testEventErrorMarshalFunc(t, testcase+" / e.Errs([])", wants[5], func(e *Event) *Event { + testEventErrorMarshalFunc(t, testcase+" / event.Errs([])", wantErrs, func(e *Event) *Event { e.Errs("errs", errs) return e }) + testFieldsErrorMarshalFunc(t, testcase+" / field.Errs([])", wantErrs, func(e *Event) *Event { + e.Fields(map[string]interface{}{"errs": errs}) + return e + }) } func testEventErrorMarshalFunc(t *testing.T, testcase string, wants string, test func(e *Event) *Event) { @@ -1022,6 +1199,15 @@ func testEventErrorMarshalFunc(t *testing.T, testcase string, wants string, test } } +func testFieldsErrorMarshalFunc(t *testing.T, testcase string, wants string, test func(e *Event) *Event) { + out := &bytes.Buffer{} + logger := New(out) + test(logger.Log()).Msg("msg") + if got, want := decodeIfBinaryToString(out.Bytes()), wants+"\n"; got != want { + t.Errorf("%s output:\ngot: %v\nwant: %v", testcase, got, want) + } +} + func testContextErrorMarshalFunc(t *testing.T, testcase string, wants string, test func(ctx Context) Context) { out := &bytes.Buffer{} ctx := New(out).With()