diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 82a75a4..816f164 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -9,7 +9,7 @@ jobs: runs-on: ${{ matrix.os }} steps: - name: Install Go - uses: actions/setup-go@v3 + uses: actions/setup-go@v4 with: go-version: ${{ matrix.go-version }} - name: Checkout code diff --git a/README.md b/README.md index 91d4e38..c243eb4 100644 --- a/README.md +++ b/README.md @@ -30,7 +30,7 @@ Find out [who uses zlog](https://tuxpa.in/a/zlog/wiki/Who-uses-zlog) and add you * [Sampling](#log-sampling) * [Hooks](#hooks) * [Contextual fields](#contextual-logging) -* `context.Context` integration +* [`context.Context` integration](#contextcontext-integration) * [Integration with `net/http`](#integration-with-nethttp) * [JSON and CBOR encoding formats](#binary-encoding) * [Pretty logging for development](#pretty-logging) @@ -505,7 +505,7 @@ log.Ctx(ctx).Info().Msg("hello world") ### Set as standard logger output ```go -log := zlog.New(os.Stdout).With(). +stdlog := zlog.New(os.Stdout).With(). Str("foo", "bar"). Logger() @@ -517,6 +517,30 @@ stdlog.Print("hello world") // Output: {"foo":"bar","message":"hello world"} ``` +### context.Context integration + +The `Logger` instance could be attached to `context.Context` values with `logger.WithContext(ctx)` +and extracted from it using `zerolog.Ctx(ctx)`. + +Example to add logger to context: +```go +// this code attach logger instance to context fields +ctx := context.Background() +logger := zerolog.New(os.Stdout) +ctx = logger.WithContext(ctx) +someFunc(ctx) +``` + +Extracting logger from context: +```go +func someFunc(ctx context.Context) { + // get logger from context. if it's nill, then `zerolog.DefaultContextLogger` is returned, + // if `DefaultContextLogger` is nil, then disabled logger returned. + logger := zerolog.Ctx(ctx) + logger.Info().Msg("Hello") +} +``` + ### Integration with `net/http` The `tuxpa.in/a/zlog/hlog` package provides some helpers to integrate zlog with `http.Handler`. diff --git a/context.go b/context.go index 9eafce5..3bd039e 100644 --- a/context.go +++ b/context.go @@ -329,8 +329,9 @@ func (ts timestampHook) Run(e *Event, level Level, msg string) { var th = timestampHook{} -// Timestamp adds the current local time as UNIX timestamp to the logger context with the "time" key. +// Timestamp adds the current local time to the logger context with the "time" key, formatted using zlog.TimeFieldFormat. // To customize the key name, change zlog.TimestampFieldName. +// To customize the time format, change zlog.TimeFieldFormat. // // NOTE: It won't dedupe the "time" key if the *Context has one already. func (c Context) Timestamp() Context { diff --git a/encoder_cbor.go b/encoder_cbor.go index 4c5d909..cfc3187 100644 --- a/encoder_cbor.go +++ b/encoder_cbor.go @@ -24,6 +24,9 @@ func init() { func appendJSON(dst []byte, j []byte) []byte { return cbor.AppendEmbeddedJSON(dst, j) } +func appendCBOR(dst []byte, c []byte) []byte { + return cbor.AppendEmbeddedCBOR(dst, c) +} // decodeIfBinaryToString - converts a binary formatted log msg to a // JSON formatted String Log message. diff --git a/encoder_json.go b/encoder_json.go index 0750f06..141f65e 100644 --- a/encoder_json.go +++ b/encoder_json.go @@ -1,3 +1,4 @@ +//go:build !binary_log // +build !binary_log package zlog @@ -6,6 +7,7 @@ package zlog // JSON encoded byte stream. import ( + "encoding/base64" "tuxpa.in/a/zlog/internal/json" ) @@ -25,6 +27,17 @@ func init() { func appendJSON(dst []byte, j []byte) []byte { return append(dst, j...) } +func appendCBOR(dst []byte, cbor []byte) []byte { + dst = append(dst, []byte("\"data:application/cbor;base64,")...) + l := len(dst) + enc := base64.StdEncoding + n := enc.EncodedLen(len(cbor)) + for i := 0; i < n; i++ { + dst = append(dst, '.') + } + enc.Encode(dst[l:], cbor) + return append(dst, '"') +} func decodeIfBinaryToString(in []byte) string { return string(in) diff --git a/event.go b/event.go index 029da04..fa845ac 100644 --- a/event.go +++ b/event.go @@ -318,6 +318,18 @@ func (e *Event) RawJSON(key string, b []byte) *Event { return e } +// RawCBOR adds already encoded CBOR to the log line under key. +// +// No sanity check is performed on b +// Note: The full featureset of CBOR is supported as data will not be mapped to json but stored as data-url +func (e *Event) RawCBOR(key string, b []byte) *Event { + if e == nil { + return e + } + e.buf = appendCBOR(enc.AppendKey(e.buf, key), b) + return e +} + // AnErr adds the field key with serialized err to the *Event context. // If err is nil, no field is added. func (e *Event) AnErr(key string, err error) *Event { diff --git a/go.mod b/go.mod index 613a242..79ba7ac 100644 --- a/go.mod +++ b/go.mod @@ -6,7 +6,7 @@ require ( github.com/coreos/go-systemd/v22 v22.5.0 github.com/mattn/go-colorable v0.1.12 github.com/pkg/errors v0.9.1 - github.com/rs/xid v1.4.0 + github.com/rs/xid v1.5.0 github.com/rs/zerolog v1.28.0 golang.org/x/sys v0.0.0-20220915200043-7b5979e65e41 // indirect ) diff --git a/go.sum b/go.sum index 45c1743..a8a1372 100644 --- a/go.sum +++ b/go.sum @@ -8,8 +8,9 @@ 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.4.0 h1:qd7wPTDkN6KQx2VmMBLrpHkiyQwgFXRnkOLacUiaSNY= github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/xid v1.5.0 h1:mKX4bl4iPYJtEIxp6CYiUuLQ/8DYMoz0PUdtGgMFRVc= +github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= github.com/rs/zerolog v1.28.0 h1:MirSo27VyNi7RJYP3078AA1+Cyzd2GB66qy3aUHvsWY= github.com/rs/zerolog v1.28.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6usyD0= golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= diff --git a/internal/cbor/cbor.go b/internal/cbor/cbor.go index bc54e37..1bf1443 100644 --- a/internal/cbor/cbor.go +++ b/internal/cbor/cbor.go @@ -26,7 +26,8 @@ const ( additionalTypeBreak byte = 31 // Tag Sub-types. - additionalTypeTimestamp byte = 01 + additionalTypeTimestamp byte = 01 + additionalTypeEmbeddedCBOR byte = 63 // Extended Tags - from https://www.iana.org/assignments/cbor-tags/cbor-tags.xhtml additionalTypeTagNetworkAddr uint16 = 260 diff --git a/internal/cbor/decode_stream.go b/internal/cbor/decode_stream.go index fc16f98..616bed6 100644 --- a/internal/cbor/decode_stream.go +++ b/internal/cbor/decode_stream.go @@ -5,6 +5,7 @@ package cbor import ( "bufio" "bytes" + "encoding/base64" "fmt" "io" "math" @@ -213,6 +214,31 @@ func decodeString(src *bufio.Reader, noQuotes bool) []byte { } return append(result, '"') } +func decodeStringToDataUrl(src *bufio.Reader, mimeType string) []byte { + pb := readByte(src) + major := pb & maskOutAdditionalType + minor := pb & maskOutMajorType + if major != majorTypeByteString { + panic(fmt.Errorf("Major type is: %d in decodeString", major)) + } + length := decodeIntAdditionalType(src, minor) + l := int(length) + enc := base64.StdEncoding + lEnc := enc.EncodedLen(l) + result := make([]byte, len("\"data:;base64,\"")+len(mimeType)+lEnc) + dest := result + u := copy(dest, "\"data:") + dest = dest[u:] + u = copy(dest, mimeType) + dest = dest[u:] + u = copy(dest, ";base64,") + dest = dest[u:] + pbs := readNBytes(src, l) + enc.Encode(dest, pbs) + dest = dest[lEnc:] + dest[0] = '"' + return result +} func decodeUTF8String(src *bufio.Reader) []byte { pb := readByte(src) @@ -349,6 +375,20 @@ func decodeTagData(src *bufio.Reader) []byte { switch minor { case additionalTypeTimestamp: return decodeTimeStamp(src) + case additionalTypeIntUint8: + val := decodeIntAdditionalType(src, minor) + switch byte(val) { + case additionalTypeEmbeddedCBOR: + pb := readByte(src) + dataMajor := pb & maskOutAdditionalType + if dataMajor != majorTypeByteString { + panic(fmt.Errorf("Unsupported embedded Type: %d in decodeEmbeddedCBOR", dataMajor)) + } + src.UnreadByte() + return decodeStringToDataUrl(src, "application/cbor") + default: + panic(fmt.Errorf("Unsupported Additional Tag Type: %d in decodeTagData", val)) + } // Tag value is larger than 256 (so uint16). case additionalTypeIntUint16: diff --git a/internal/cbor/string.go b/internal/cbor/string.go index a33890a..9fc9a4f 100644 --- a/internal/cbor/string.go +++ b/internal/cbor/string.go @@ -93,3 +93,25 @@ func AppendEmbeddedJSON(dst, s []byte) []byte { } return append(dst, s...) } + +// AppendEmbeddedCBOR adds a tag and embeds input CBOR as such. +func AppendEmbeddedCBOR(dst, s []byte) []byte { + major := majorTypeTags + minor := additionalTypeEmbeddedCBOR + + // Append the TAG to indicate this is Embedded JSON. + dst = append(dst, major|additionalTypeIntUint8) + dst = append(dst, minor) + + // Append the CBOR Object as Byte String. + major = majorTypeByteString + + l := len(s) + if l <= additionalMax { + lb := byte(l) + dst = append(dst, major|lb) + } else { + dst = appendCborTypePrefix(dst, major, uint64(l)) + } + return append(dst, s...) +} diff --git a/log.go b/log.go index b81717c..7fca083 100644 --- a/log.go +++ b/log.go @@ -308,7 +308,9 @@ func (l Logger) Sample(s Sampler) Logger { // Hook returns a logger with the h Hook. func (l Logger) Hook(h Hook) Logger { - l.hooks = append(l.hooks, h) + newHooks := make([]Hook, len(l.hooks), len(l.hooks)+1) + copy(newHooks, l.hooks) + l.hooks = append(newHooks, h) return l } diff --git a/log_test.go b/log_test.go index 27a2744..4927a12 100644 --- a/log_test.go +++ b/log_test.go @@ -320,6 +320,7 @@ func TestFields(t *testing.T) { Bytes("bytes", []byte("bar")). Hex("hex", []byte{0x12, 0xef}). RawJSON("json", []byte(`{"some":"json"}`)). + RawCBOR("cbor", []byte{0x83, 0x01, 0x82, 0x02, 0x03, 0x82, 0x04, 0x05}). Func(func(e *Event) { e.Str("func", "func_output") }). AnErr("some_err", nil). Err(errors.New("some error")). @@ -344,7 +345,7 @@ func TestFields(t *testing.T) { Time("time", time.Time{}). TimeDiff("diff", now, now.Add(-10*time.Second)). Msg("") - if got, want := decodeIfBinaryToString(out.Bytes()), `{"caller":"`+caller+`","string":"foo","stringer":"127.0.0.1","stringer_nil":null,"bytes":"bar","hex":"12ef","json":{"some":"json"},"func":"func_output","error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"IPv4":"192.168.0.100","IPv6":"2001:db8:85a3::8a2e:370:7334","Mac":"00:14:22:01:23:45","Prefix":"192.168.0.100/24","float32":11.1234,"float64":12.321321321,"dur":1000,"time":"0001-01-01T00:00:00Z","diff":10000}`+"\n"; got != want { + if got, want := decodeIfBinaryToString(out.Bytes()), `{"caller":"`+caller+`","string":"foo","stringer":"127.0.0.1","stringer_nil":null,"bytes":"bar","hex":"12ef","json":{"some":"json"},"cbor":"data:application/cbor;base64,gwGCAgOCBAU=","func":"func_output","error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"IPv4":"192.168.0.100","IPv6":"2001:db8:85a3::8a2e:370:7334","Mac":"00:14:22:01:23:45","Prefix":"192.168.0.100/24","float32":11.1234,"float64":12.321321321,"dur":1000,"time":"0001-01-01T00:00:00Z","diff":10000}`+"\n"; got != want { t.Errorf("invalid log output:\ngot: %v\nwant: %v", got, want) } } diff --git a/pkgerrors/stacktrace.go b/pkgerrors/stacktrace.go index 9a7e8f7..ea6f759 100644 --- a/pkgerrors/stacktrace.go +++ b/pkgerrors/stacktrace.go @@ -42,15 +42,32 @@ func frameField(f errors.Frame, s *state, c rune) string { // MarshalStack implements pkg/errors stack trace marshaling. // -// zlog.ErrorStackMarshaler = MarshalStack +// zlog.ErrorStackMarshaler = MarshalStack func MarshalStack(err error) interface{} { type stackTracer interface { StackTrace() errors.StackTrace } - sterr, ok := err.(stackTracer) - if !ok { + var sterr stackTracer + var ok bool + for err != nil { + sterr, ok = err.(stackTracer) + if ok { + break + } + + u, ok := err.(interface { + Unwrap() error + }) + if !ok { + return nil + } + + err = u.Unwrap() + } + if sterr == nil { return nil } + st := sterr.StackTrace() s := &state{} out := make([]map[string]string, 0, len(st)) diff --git a/pkgerrors/stacktrace_test.go b/pkgerrors/stacktrace_test.go index 6d20976..2254131 100644 --- a/pkgerrors/stacktrace_test.go +++ b/pkgerrors/stacktrace_test.go @@ -4,6 +4,7 @@ package pkgerrors import ( "bytes" + "fmt" "regexp" "testing" @@ -17,11 +18,11 @@ func TestLogStack(t *testing.T) { out := &bytes.Buffer{} log := zlog.New(out) - err := errors.Wrap(errors.New("error message"), "from error") + err := fmt.Errorf("from error: %w", errors.New("error message")) log.Log().Stack().Err(err).Msg("") got := out.String() - want := `\{"stack":\[\{"func":"TestLogStack","line":"20","source":"stacktrace_test.go"\},.*\],"error":"from error: error message"\}\n` + want := `\{"stack":\[\{"func":"TestLogStack","line":"21","source":"stacktrace_test.go"\},.*\],"error":"from error: error message"\}\n` if ok, _ := regexp.MatchString(want, got); !ok { t.Errorf("invalid log output:\ngot: %v\nwant: %v", got, want) } @@ -33,11 +34,11 @@ func TestLogStackFromContext(t *testing.T) { out := &bytes.Buffer{} log := zlog.New(out).With().Stack().Logger() // calling Stack() on log context instead of event - err := errors.Wrap(errors.New("error message"), "from error") + err := fmt.Errorf("from error: %w", errors.New("error message")) log.Log().Err(err).Msg("") // not explicitly calling Stack() got := out.String() - want := `\{"stack":\[\{"func":"TestLogStackFromContext","line":"36","source":"stacktrace_test.go"\},.*\],"error":"from error: error message"\}\n` + want := `\{"stack":\[\{"func":"TestLogStackFromContext","line":"37","source":"stacktrace_test.go"\},.*\],"error":"from error: error message"\}\n` if ok, _ := regexp.MatchString(want, got); !ok { t.Errorf("invalid log output:\ngot: %v\nwant: %v", got, want) }