From d0cfcbbafef392b32fabde3cb62d8937df170e2a Mon Sep 17 00:00:00 2001 From: Olivier Poitrey Date: Fri, 19 May 2017 19:43:59 -0700 Subject: [PATCH] Write directly into a single shared buffer per event for even better perf --- README.md | 10 +-- benchmark_test.go | 13 +-- context.go | 76 +++++++++------- event.go | 214 ++++++++++++++++++++++---------------------- field.go | 211 +++++++++++++++++-------------------------- json.go | 78 ++++++++++------ log.go | 68 +++++++------- log/log.go | 14 +-- log_example_test.go | 2 +- 9 files changed, 339 insertions(+), 347 deletions(-) diff --git a/README.md b/README.md index a87ae8a..809b31c 100644 --- a/README.md +++ b/README.md @@ -15,11 +15,11 @@ The zerolog package provides a fast and simple logger dedicated to JSON output. All operations are allocation free (those numbers *include* JSON encoding): ``` -BenchmarkLogEmpty-8 50000000 22 ns/op 0 B/op 0 allocs/op -BenchmarkDisabled-8 100000000 9 ns/op 0 B/op 0 allocs/op -BenchmarkInfo-8 10000000 210 ns/op 0 B/op 0 allocs/op -BenchmarkContextFields-8 10000000 254 ns/op 0 B/op 0 allocs/op -BenchmarkLogFields-8 5000000 377 ns/op 0 B/op 0 allocs/op +BenchmarkLogEmpty-8 50000000 19.8 ns/op 0 B/op 0 allocs/op +BenchmarkDisabled-8 100000000 4.73 ns/op 0 B/op 0 allocs/op +BenchmarkInfo-8 10000000 85.1 ns/op 0 B/op 0 allocs/op +BenchmarkContextFields-8 10000000 81.9 ns/op 0 B/op 0 allocs/op +BenchmarkLogFields-8 5000000 247 ns/op 0 B/op 0 allocs/op ``` ## Usage diff --git a/benchmark_test.go b/benchmark_test.go index 926f0d4..c0f1fb1 100644 --- a/benchmark_test.go +++ b/benchmark_test.go @@ -4,6 +4,7 @@ import ( "errors" "io/ioutil" "testing" + "time" ) var ( @@ -44,9 +45,9 @@ func BenchmarkInfo(b *testing.B) { func BenchmarkContextFields(b *testing.B) { logger := New(ioutil.Discard).With(). Str("string", "four!"). - Str("time", "now"). // XXX - Str("duration", "123"). //XXX - Str("another string", "done!"). + Time("time", time.Time{}). + Int("int", 123). + Float32("float", -2.203230293249593). Logger() b.ResetTimer() b.RunParallel(func(pb *testing.PB) { @@ -63,9 +64,9 @@ func BenchmarkLogFields(b *testing.B) { for pb.Next() { logger.Info(). Str("string", "four!"). - Str("time", "now"). // XXX - Str("duration", "123"). //XXX - Str("another string", "done!"). + Time("time", time.Time{}). + Int("int", 123). + Float32("float", -2.203230293249593). Msg(fakeMessage) } }) diff --git a/context.go b/context.go index cdd7fff..9eceee2 100644 --- a/context.go +++ b/context.go @@ -12,108 +12,118 @@ func (c Context) Logger() Logger { return c.l } -func (c Context) append(f field) Context { - return Context{ - l: Logger{ - parent: c.l, - w: c.l.w, - field: f.compileJSON(), - level: c.l.level, - sample: c.l.sample, - counter: c.l.counter, - }, - } -} - // Dict adds the field key with the dict to the logger context. -func (c Context) Dict(key string, dict Event) Context { - dict.buf.WriteByte('}') - return c.append(fRaw(key, dict.buf.String())) +func (c Context) Dict(key string, dict *Event) Context { + dict.buf = append(dict.buf, '}') + c.l.context = append(appendKey(c.l.context, key), dict.buf...) + eventPool.Put(dict) + return c } // Str adds the field key with val as a string to the logger context. func (c Context) Str(key, val string) Context { - return c.append(fStr(key, val)) + c.l.context = appendString(c.l.context, key, val) + return c } // Err adds the field "error" with err as a string to the logger context. // To customize the key name, change zerolog.ErrorFieldName. func (c Context) Err(err error) Context { - return c.append(fErr(err)) + c.l.context = appendError(c.l.context, err) + return c } // Bool adds the field key with val as a Boolean to the logger context. func (c Context) Bool(key string, b bool) Context { - return c.append(fBool(key, b)) + c.l.context = appendBool(c.l.context, key, b) + return c } // Int adds the field key with i as a int to the logger context. func (c Context) Int(key string, i int) Context { - return c.append(fInt(key, i)) + c.l.context = appendInt(c.l.context, key, i) + return c } // Int8 adds the field key with i as a int8 to the logger context. func (c Context) Int8(key string, i int8) Context { - return c.append(fInt8(key, i)) + c.l.context = appendInt8(c.l.context, key, i) + return c } // Int16 adds the field key with i as a int16 to the logger context. func (c Context) Int16(key string, i int16) Context { - return c.append(fInt16(key, i)) + c.l.context = appendInt16(c.l.context, key, i) + return c } // Int32 adds the field key with i as a int32 to the logger context. func (c Context) Int32(key string, i int32) Context { - return c.append(fInt32(key, i)) + c.l.context = appendInt32(c.l.context, key, i) + return c } // Int64 adds the field key with i as a int64 to the logger context. func (c Context) Int64(key string, i int64) Context { - return c.append(fInt64(key, i)) + c.l.context = appendInt64(c.l.context, key, i) + return c } // Uint adds the field key with i as a uint to the logger context. func (c Context) Uint(key string, i uint) Context { - return c.append(fUint(key, i)) + c.l.context = appendUint(c.l.context, key, i) + return c } // Uint8 adds the field key with i as a uint8 to the logger context. func (c Context) Uint8(key string, i uint8) Context { - return c.append(fUint8(key, i)) + c.l.context = appendUint8(c.l.context, key, i) + return c } // Uint16 adds the field key with i as a uint16 to the logger context. func (c Context) Uint16(key string, i uint16) Context { - return c.append(fUint16(key, i)) + c.l.context = appendUint16(c.l.context, key, i) + return c } // Uint32 adds the field key with i as a uint32 to the logger context. func (c Context) Uint32(key string, i uint32) Context { - return c.append(fUint32(key, i)) + c.l.context = appendUint32(c.l.context, key, i) + return c } // Uint64 adds the field key with i as a uint64 to the logger context. func (c Context) Uint64(key string, i uint64) Context { - return c.append(fUint64(key, i)) + c.l.context = appendUint64(c.l.context, key, i) + return c } // Float32 adds the field key with f as a float32 to the logger context. func (c Context) Float32(key string, f float32) Context { - return c.append(fFloat32(key, f)) + c.l.context = appendFloat32(c.l.context, key, f) + return c } // Float64 adds the field key with f as a float64 to the logger context. func (c Context) Float64(key string, f float64) Context { - return c.append(fFloat64(key, f)) + c.l.context = appendFloat64(c.l.context, key, f) + return c } // Timestamp adds the current local time as UNIX timestamp to the logger context with the "time" key. // To customize the key name, change zerolog.TimestampFieldName. func (c Context) Timestamp() Context { - return c.append(fTimestamp()) + if len(c.l.context) > 0 { + c.l.context[0] = 1 + } else { + c.l.context = append(c.l.context, 1) + } + return c } // Time adds the field key with t formated as string using zerolog.TimeFieldFormat. func (c Context) Time(key string, t time.Time) Context { - return c.append(fTime(key, t)) + c.l.context = appendTime(c.l.context, key, t) + return c } diff --git a/event.go b/event.go index d0bcd2f..2eca670 100644 --- a/event.go +++ b/event.go @@ -1,83 +1,69 @@ package zerolog import ( - "bytes" "fmt" - "io" "io/ioutil" "sync" "time" ) -var pool = &sync.Pool{ +var eventPool = &sync.Pool{ New: func() interface{} { - return bytes.NewBuffer(make([]byte, 500)) + return &Event{ + buf: make([]byte, 0, 500), + } }, } // Event represents a log event. It is instancied by one of the level method of // Logger and finalized by the Msg or Msgf method. type Event struct { - buf *bytes.Buffer + buf []byte w LevelWriter level Level enabled bool done func(msg string) } -func newEvent(w LevelWriter, level Level, enabled bool) Event { +func newEvent(w LevelWriter, level Level, enabled bool) *Event { if !enabled { - return Event{} + return &Event{} } - buf := pool.Get().(*bytes.Buffer) - buf.Reset() - buf.WriteByte('{') - return Event{ - buf: buf, - w: w, - level: level, - enabled: true, - } -} - -func (e Event) write() (n int, err error) { - if !e.enabled { - return 0, nil - } - e.buf.WriteByte('}') - e.buf.WriteByte('\n') - n, err = e.w.WriteLevel(e.level, e.buf.Bytes()) - pool.Put(e.buf) - return -} - -func (e Event) append(f field) Event { - if !e.enabled { - return e - } - if e.buf.Len() > 1 { - e.buf.WriteByte(',') - } - f.writeJSON(e.buf) + e := eventPool.Get().(*Event) + e.buf = e.buf[:1] + e.buf[0] = '{' + e.w = w + e.level = level + e.enabled = true return e } -// Enabled return false if the event is going to be filtered out by +func (e *Event) write() (n int, err error) { + if !e.enabled { + return 0, nil + } + e.buf = append(e.buf, '}', '\n') + n, err = e.w.WriteLevel(e.level, e.buf) + eventPool.Put(e) + return +} + +// Enabled return false if the *Event is going to be filtered out by // log level or sampling. -func (e Event) Enabled() bool { +func (e *Event) Enabled() bool { return e.enabled } -// Msg sends the event with msg added as the message field if not empty. +// Msg sends the *Event with msg added as the message field if not empty. // -// NOTICE: once this methid is called, the Event should be disposed. +// NOTICE: once this methid is called, the *Event should be disposed. // Calling Msg twice can have unexpected result. -func (e Event) Msg(msg string) (n int, err error) { +func (e *Event) Msg(msg string) (n int, err error) { if !e.enabled { return 0, nil } if msg != "" { - e.append(fStr(MessageFieldName, msg)) + e.buf = appendString(e.buf, MessageFieldName, msg) } if e.done != nil { defer e.done(msg) @@ -85,17 +71,17 @@ func (e Event) Msg(msg string) (n int, err error) { return e.write() } -// Msgf sends the event with formated msg added as the message field if not empty. +// Msgf sends the *Event with formated msg added as the message field if not empty. // -// NOTICE: once this methid is called, the Event should be disposed. +// NOTICE: once this methid is called, the *Event should be disposed. // Calling Msg twice can have unexpected result. -func (e Event) Msgf(format string, v ...interface{}) (n int, err error) { +func (e *Event) Msgf(format string, v ...interface{}) (n int, err error) { if !e.enabled { return 0, nil } msg := fmt.Sprintf(format, v...) if msg != "" { - e.append(fStr(MessageFieldName, msg)) + e.buf = appendString(e.buf, MessageFieldName, msg) } if e.done != nil { defer e.done(msg) @@ -103,161 +89,175 @@ func (e Event) Msgf(format string, v ...interface{}) (n int, err error) { return e.write() } -// Dict adds the field key with a dict to the event context. +// Dict adds the field key with a dict to the *Event context. // Use zerolog.Dict() to create the dictionary. -func (e Event) Dict(key string, dict Event) Event { +func (e *Event) Dict(key string, dict *Event) *Event { if !e.enabled { return e } - if e.buf.Len() > 1 { - e.buf.WriteByte(',') - } - io.Copy(e.buf, dict.buf) - e.buf.WriteByte('}') + e.buf = append(append(appendKey(e.buf, key), dict.buf...), '}') + eventPool.Put(dict) return e } -// Dict creates an Event to be used with the event.Dict method. +// Dict creates an Event to be used with the *Event.Dict method. // Call usual field methods like Str, Int etc to add fields to this -// event and give it as argument the event.Dict method. -func Dict() Event { +// event and give it as argument the *Event.Dict method. +func Dict() *Event { return newEvent(levelWriterAdapter{ioutil.Discard}, 0, true) } -// Str adds the field key with val as a string to the event context. -func (e Event) Str(key, val string) Event { +// Str adds the field key with val as a string to the *Event context. +func (e *Event) Str(key, val string) *Event { if !e.enabled { return e } - return e.append(fStr(key, val)) + e.buf = appendString(e.buf, key, val) + return e } -// Err adds the field "error" with err as a string to the event context. +// Err adds the field "error" with err as a string to the *Event context. // To customize the key name, change zerolog.ErrorFieldName. -func (e Event) Err(err error) Event { +func (e *Event) Err(err error) *Event { if !e.enabled { return e } - return e.append(fErr(err)) + e.buf = appendError(e.buf, err) + return e } -// Bool adds the field key with val as a Boolean to the event context. -func (e Event) Bool(key string, b bool) Event { +// Bool adds the field key with val as a Boolean to the *Event context. +func (e *Event) Bool(key string, b bool) *Event { if !e.enabled { return e } - return e.append(fBool(key, b)) + e.buf = appendBool(e.buf, key, b) + return e } -// Int adds the field key with i as a int to the event context. -func (e Event) Int(key string, i int) Event { +// Int adds the field key with i as a int to the *Event context. +func (e *Event) Int(key string, i int) *Event { if !e.enabled { return e } - return e.append(fInt(key, i)) + e.buf = appendInt(e.buf, key, i) + return e } -// Int8 adds the field key with i as a int8 to the event context. -func (e Event) Int8(key string, i int8) Event { +// Int8 adds the field key with i as a int8 to the *Event context. +func (e *Event) Int8(key string, i int8) *Event { if !e.enabled { return e } - return e.append(fInt8(key, i)) + e.buf = appendInt8(e.buf, key, i) + return e } -// Int16 adds the field key with i as a int16 to the event context. -func (e Event) Int16(key string, i int16) Event { +// Int16 adds the field key with i as a int16 to the *Event context. +func (e *Event) Int16(key string, i int16) *Event { if !e.enabled { return e } - return e.append(fInt16(key, i)) + e.buf = appendInt16(e.buf, key, i) + return e } -// Int32 adds the field key with i as a int32 to the event context. -func (e Event) Int32(key string, i int32) Event { +// Int32 adds the field key with i as a int32 to the *Event context. +func (e *Event) Int32(key string, i int32) *Event { if !e.enabled { return e } - return e.append(fInt32(key, i)) + e.buf = appendInt32(e.buf, key, i) + return e } -// Int64 adds the field key with i as a int64 to the event context. -func (e Event) Int64(key string, i int64) Event { +// Int64 adds the field key with i as a int64 to the *Event context. +func (e *Event) Int64(key string, i int64) *Event { if !e.enabled { return e } - return e.append(fInt64(key, i)) + e.buf = appendInt64(e.buf, key, i) + return e } -// Uint adds the field key with i as a uint to the event context. -func (e Event) Uint(key string, i uint) Event { +// Uint adds the field key with i as a uint to the *Event context. +func (e *Event) Uint(key string, i uint) *Event { if !e.enabled { return e } - return e.append(fUint(key, i)) + e.buf = appendUint(e.buf, key, i) + return e } -// Uint8 adds the field key with i as a uint8 to the event context. -func (e Event) Uint8(key string, i uint8) Event { +// Uint8 adds the field key with i as a uint8 to the *Event context. +func (e *Event) Uint8(key string, i uint8) *Event { if !e.enabled { return e } - return e.append(fUint8(key, i)) + e.buf = appendUint8(e.buf, key, i) + return e } -// Uint16 adds the field key with i as a uint16 to the event context. -func (e Event) Uint16(key string, i uint16) Event { +// Uint16 adds the field key with i as a uint16 to the *Event context. +func (e *Event) Uint16(key string, i uint16) *Event { if !e.enabled { return e } - return e.append(fUint16(key, i)) + e.buf = appendUint16(e.buf, key, i) + return e } -// Uint32 adds the field key with i as a uint32 to the event context. -func (e Event) Uint32(key string, i uint32) Event { +// Uint32 adds the field key with i as a uint32 to the *Event context. +func (e *Event) Uint32(key string, i uint32) *Event { if !e.enabled { return e } - return e.append(fUint32(key, i)) + e.buf = appendUint32(e.buf, key, i) + return e } -// Uint64 adds the field key with i as a uint64 to the event context. -func (e Event) Uint64(key string, i uint64) Event { +// Uint64 adds the field key with i as a uint64 to the *Event context. +func (e *Event) Uint64(key string, i uint64) *Event { if !e.enabled { return e } - return e.append(fUint64(key, i)) + e.buf = appendUint64(e.buf, key, i) + return e } -// Float32 adds the field key with f as a float32 to the event context. -func (e Event) Float32(key string, f float32) Event { +// Float32 adds the field key with f as a float32 to the *Event context. +func (e *Event) Float32(key string, f float32) *Event { if !e.enabled { return e } - return e.append(fFloat32(key, f)) + e.buf = appendFloat32(e.buf, key, f) + return e } -// Float64 adds the field key with f as a float64 to the event context. -func (e Event) Float64(key string, f float64) Event { +// Float64 adds the field key with f as a float64 to the *Event context. +func (e *Event) Float64(key string, f float64) *Event { if !e.enabled { return e } - return e.append(fFloat64(key, f)) + e.buf = appendFloat64(e.buf, key, f) + return e } -// Timestamp adds the current local time as UNIX timestamp to the event context with the "time" key. +// Timestamp adds the current local time as UNIX timestamp to the *Event context with the "time" key. // To customize the key name, change zerolog.TimestampFieldName. -func (e Event) Timestamp() Event { +func (e *Event) Timestamp() *Event { if !e.enabled { return e } - return e.append(fTimestamp()) + e.buf = appendTimestamp(e.buf) + return e } // Time adds the field key with t formated as string using zerolog.TimeFieldFormat. -func (e Event) Time(key string, t time.Time) Event { +func (e *Event) Time(key string, t time.Time) *Event { if !e.enabled { return e } - return e.append(fTime(key, t)) + e.buf = appendTime(e.buf, key, t) + return e } diff --git a/field.go b/field.go index ec9940b..97d08ab 100644 --- a/field.go +++ b/field.go @@ -1,141 +1,94 @@ package zerolog import ( - "bytes" + "encoding/json" + "fmt" "strconv" "time" ) var now = time.Now -type fieldMode uint8 - -const ( - zeroFieldMode fieldMode = iota - rawFieldMode - quotedFieldMode - precomputedFieldMode - timestampFieldMode -) - -// field define a logger field. -type field struct { - key string - mode fieldMode - val string - json []byte -} - -func (f field) writeJSON(buf *bytes.Buffer) { - switch f.mode { - case zeroFieldMode: - return - case precomputedFieldMode: - buf.Write(f.json) - return - case timestampFieldMode: - writeJSONString(buf, TimestampFieldName) - buf.WriteByte(':') - buf.WriteString(strconv.FormatInt(now().Unix(), 10)) - return +func appendKey(dst []byte, key string) []byte { + if len(dst) > 1 { + dst = append(dst, ',') } - writeJSONString(buf, f.key) - buf.WriteByte(':') - switch f.mode { - case quotedFieldMode: - writeJSONString(buf, f.val) - case rawFieldMode: - buf.WriteString(f.val) - default: - panic("unknown field mode") + dst = appendJSONString(dst, key) + return append(dst, ':') +} + +func appendString(dst []byte, key, val string) []byte { + return appendJSONString(appendKey(dst, key), val) +} + +func appendError(dst []byte, err error) []byte { + return appendJSONString(appendKey(dst, ErrorFieldName), err.Error()) +} + +func appendBool(dst []byte, key string, val bool) []byte { + return strconv.AppendBool(appendKey(dst, key), val) +} + +func appendInt(dst []byte, key string, val int) []byte { + return strconv.AppendInt(appendKey(dst, key), int64(val), 10) +} + +func appendInt8(dst []byte, key string, val int8) []byte { + return strconv.AppendInt(appendKey(dst, key), int64(val), 10) +} + +func appendInt16(dst []byte, key string, val int16) []byte { + return strconv.AppendInt(appendKey(dst, key), int64(val), 10) +} + +func appendInt32(dst []byte, key string, val int32) []byte { + return strconv.AppendInt(appendKey(dst, key), int64(val), 10) +} + +func appendInt64(dst []byte, key string, val int64) []byte { + return strconv.AppendInt(appendKey(dst, key), int64(val), 10) +} + +func appendUint(dst []byte, key string, val uint) []byte { + return strconv.AppendUint(appendKey(dst, key), uint64(val), 10) +} + +func appendUint8(dst []byte, key string, val uint8) []byte { + return strconv.AppendUint(appendKey(dst, key), uint64(val), 10) +} + +func appendUint16(dst []byte, key string, val uint16) []byte { + return strconv.AppendUint(appendKey(dst, key), uint64(val), 10) +} + +func appendUint32(dst []byte, key string, val uint32) []byte { + return strconv.AppendUint(appendKey(dst, key), uint64(val), 10) +} + +func appendUint64(dst []byte, key string, val uint64) []byte { + return strconv.AppendUint(appendKey(dst, key), uint64(val), 10) +} + +func appendFloat32(dst []byte, key string, val float32) []byte { + return strconv.AppendFloat(appendKey(dst, key), float64(val), 'f', -1, 32) +} + +func appendFloat64(dst []byte, key string, val float64) []byte { + return strconv.AppendFloat(appendKey(dst, key), float64(val), 'f', -1, 32) +} + +func appendTime(dst []byte, key string, t time.Time) []byte { + return append(t.AppendFormat(append(appendKey(dst, key), '"'), TimeFieldFormat), '"') +} + +func appendTimestamp(dst []byte) []byte { + return appendInt64(dst, TimestampFieldName, now().Unix()) +} + +func appendObject(dst []byte, key string, obj interface{}) []byte { + marshaled, err := json.Marshal(obj) + if err != nil { + return appendString(dst, key, fmt.Sprintf("marshaling error: %v", err)) } -} - -func (f field) compileJSON() field { - switch f.mode { - case zeroFieldMode, precomputedFieldMode, timestampFieldMode: - return f - } - buf := &bytes.Buffer{} - f.writeJSON(buf) - cf := field{ - mode: precomputedFieldMode, - json: buf.Bytes(), - } - return cf -} - -func fStr(key, val string) field { - return field{key, quotedFieldMode, val, nil} -} - -func fErr(err error) field { - return field{ErrorFieldName, quotedFieldMode, err.Error(), nil} -} - -func fBool(key string, b bool) field { - if b { - return field{key, rawFieldMode, "true", nil} - } - return field{key, rawFieldMode, "false", nil} -} - -func fInt(key string, i int) field { - return field{key, rawFieldMode, strconv.FormatInt(int64(i), 10), nil} -} - -func fInt8(key string, i int8) field { - return field{key, rawFieldMode, strconv.FormatInt(int64(i), 10), nil} -} - -func fInt16(key string, i int16) field { - return field{key, rawFieldMode, strconv.FormatInt(int64(i), 10), nil} -} - -func fInt32(key string, i int32) field { - return field{key, rawFieldMode, strconv.FormatInt(int64(i), 10), nil} -} - -func fInt64(key string, i int64) field { - return field{key, rawFieldMode, strconv.FormatInt(i, 10), nil} -} - -func fUint(key string, i uint) field { - return field{key, rawFieldMode, strconv.FormatUint(uint64(i), 10), nil} -} - -func fUint8(key string, i uint8) field { - return field{key, rawFieldMode, strconv.FormatUint(uint64(i), 10), nil} -} - -func fUint16(key string, i uint16) field { - return field{key, rawFieldMode, strconv.FormatUint(uint64(i), 10), nil} -} - -func fUint32(key string, i uint32) field { - return field{key, rawFieldMode, strconv.FormatUint(uint64(i), 10), nil} -} - -func fUint64(key string, i uint64) field { - return field{key, rawFieldMode, strconv.FormatUint(i, 10), nil} -} - -func fFloat32(key string, f float32) field { - return field{key, rawFieldMode, strconv.FormatFloat(float64(f), 'f', -1, 32), nil} -} - -func fFloat64(key string, f float64) field { - return field{key, rawFieldMode, strconv.FormatFloat(f, 'f', -1, 64), nil} -} - -func fTimestamp() field { - return field{mode: timestampFieldMode} -} - -func fTime(key string, t time.Time) field { - return field{key, quotedFieldMode, t.Format(TimeFieldFormat), nil} -} - -func fRaw(key string, raw string) field { - return field{key, rawFieldMode, raw, nil} + return append(appendKey(dst, key), marshaled...) } diff --git a/json.go b/json.go index 1d1d628..f3971d1 100644 --- a/json.go +++ b/json.go @@ -1,42 +1,31 @@ package zerolog -import ( - "bytes" - "unicode/utf8" -) +import "unicode/utf8" const hex = "0123456789abcdef" -func writeJSONString(buf *bytes.Buffer, s string) { - buf.WriteByte('"') +func appendJSONString(dst []byte, s string) []byte { + dst = append(dst, '"') for i := 0; i < len(s); { if b := s[i]; b < utf8.RuneSelf { switch b { case '"', '\\': - buf.WriteByte('\\') - buf.WriteByte(b) + dst = append(dst, '\\', b) case '\b': - buf.WriteByte('\\') - buf.WriteByte('b') + dst = append(dst, '\\', 'b') case '\f': - buf.WriteByte('\\') - buf.WriteByte('f') + dst = append(dst, '\\', 'f') case '\n': - buf.WriteByte('\\') - buf.WriteByte('n') + dst = append(dst, '\\', 'n') case '\r': - buf.WriteByte('\\') - buf.WriteByte('r') + dst = append(dst, '\\', 'r') case '\t': - buf.WriteByte('\\') - buf.WriteByte('t') + dst = append(dst, '\\', 't') default: if b >= 0x20 { - buf.WriteByte(b) + dst = append(dst, b) } else { - buf.WriteString(`\u00`) - buf.WriteByte(hex[b>>4]) - buf.WriteByte(hex[b&0xF]) + dst = append(dst, '\\', 'u', '0', '0', hex[b>>4], hex[b&0xF]) } } i++ @@ -44,12 +33,51 @@ func writeJSONString(buf *bytes.Buffer, s string) { } r, size := utf8.DecodeRuneInString(s[i:]) if r == utf8.RuneError && size == 1 { - buf.WriteString(`\ufffd`) + dst = append(dst, `\ufffd`...) i++ continue } - buf.WriteString(s[i : i+size]) + dst = append(dst, s[i:i+size]...) i += size } - buf.WriteByte('"') + return append(dst, '"') +} + +func appendJSONBytes(dst []byte, s []byte) []byte { + dst = append(dst, '"') + for i := 0; i < len(s); { + if b := s[i]; b < utf8.RuneSelf { + switch b { + case '"', '\\': + dst = append(dst, '\\', b) + case '\b': + dst = append(dst, '\\', 'b') + case '\f': + dst = append(dst, '\\', 'f') + case '\n': + dst = append(dst, '\\', 'n') + case '\r': + dst = append(dst, '\\', 'r') + case '\t': + dst = append(dst, '\\', 't') + default: + if b >= 0x20 { + dst = append(dst, b) + } else { + dst = append(dst, '\\', 'u', '0', '0', hex[b>>4], hex[b&0xF]) + } + } + i++ + continue + } + r, size := utf8.DecodeRune(s[i:]) + if r == utf8.RuneError && size == 1 { + dst = append(dst, `\ufffd`...) + i++ + continue + } + dst = append(dst, s[i:i+size]...) + i += size + } + return append(dst, '"') } diff --git a/log.go b/log.go index d95d3a5..94fbaca 100644 --- a/log.go +++ b/log.go @@ -74,10 +74,6 @@ import ( "sync/atomic" ) -type parentLogger interface { - addContextField(Event) -} - // Level defines log levels. type Level uint8 @@ -133,13 +129,11 @@ var disabledEvent = newEvent(levelWriterAdapter{ioutil.Discard}, 0, false) // serialization to the Writer. If your Writer is not thread safe, // you may consider a sync wrapper. type Logger struct { - root bool - parent parentLogger w LevelWriter - field field level Level sample uint32 counter *uint32 + context []byte } // New creates a root logger with given output writer. If the output writer implements @@ -157,25 +151,30 @@ func New(w io.Writer) Logger { if !ok { lw = levelWriterAdapter{w} } - return Logger{ - root: true, - w: lw, - } + return Logger{w: lw} } // With creates a child logger with the field added to its context. func (l Logger) With() Context { + context := l.context + l.context = make([]byte, 0, 500) + if context != nil { + l.context = append(l.context, context...) + } else { + // first byte of context is presence of timestamp or not + l.context = append(l.context, 0) + } return Context{l} } // Level crestes a child logger with the minium accepted level set to level. func (l Logger) Level(lvl Level) Logger { return Logger{ - parent: l, w: l.w, level: lvl, sample: l.sample, counter: l.counter, + context: l.context, } } @@ -184,45 +183,45 @@ func (l Logger) Sample(every int) Logger { if every == 0 { // Create a child with no sampling. return Logger{ - parent: l, - w: l.w, - level: l.level, + w: l.w, + level: l.level, + context: l.context, } } return Logger{ - parent: l, w: l.w, level: l.level, sample: uint32(every), counter: new(uint32), + context: l.context, } } // Debug starts a new message with debug level. // // You must call Msg on the returned event in order to send the event. -func (l Logger) Debug() Event { +func (l Logger) Debug() *Event { return l.newEvent(DebugLevel, true, nil) } // Info starts a new message with info level. // // You must call Msg on the returned event in order to send the event. -func (l Logger) Info() Event { +func (l Logger) Info() *Event { return l.newEvent(InfoLevel, true, nil) } // Warn starts a new message with warn level. // // You must call Msg on the returned event in order to send the event. -func (l Logger) Warn() Event { +func (l Logger) Warn() *Event { return l.newEvent(WarnLevel, true, nil) } // Error starts a new message with error level. // // You must call Msg on the returned event in order to send the event. -func (l Logger) Error() Event { +func (l Logger) Error() *Event { return l.newEvent(ErrorLevel, true, nil) } @@ -230,7 +229,7 @@ func (l Logger) Error() Event { // is called by the Msg method. // // You must call Msg on the returned event in order to send the event. -func (l Logger) Fatal() Event { +func (l Logger) Fatal() *Event { return l.newEvent(FatalLevel, true, func(msg string) { os.Exit(1) }) } @@ -238,7 +237,7 @@ func (l Logger) Fatal() Event { // to the panic function. // // You must call Msg on the returned event in order to send the event. -func (l Logger) Panic() Event { +func (l Logger) Panic() *Event { return l.newEvent(PanicLevel, true, func(msg string) { panic(msg) }) } @@ -246,11 +245,11 @@ func (l Logger) Panic() Event { // will still disable events produced by this method. // // You must call Msg on the returned event in order to send the event. -func (l Logger) Log() Event { +func (l Logger) Log() *Event { return l.newEvent(ErrorLevel, false, nil) } -func (l Logger) newEvent(level Level, addLevelField bool, done func(string)) Event { +func (l Logger) newEvent(level Level, addLevelField bool, done func(string)) *Event { enabled := l.should(level) if !enabled { return disabledEvent @@ -266,7 +265,17 @@ func (l Logger) newEvent(level Level, addLevelField bool, done func(string)) Eve if l.sample > 0 && SampleFieldName != "" { e.Uint32(SampleFieldName, l.sample) } - l.addContextField(e) + if l.context != nil && len(l.context) > 0 { + if l.context[0] > 0 { // ts flag + e.buf = appendTimestamp(e.buf) + } + if len(l.context) > 1 { + if len(e.buf) > 1 { + e.buf = append(e.buf, ',') + } + e.buf = append(e.buf, l.context[1:]...) + } + } return e } @@ -281,12 +290,3 @@ func (l Logger) should(lvl Level) bool { } return true } - -func (l Logger) addContextField(e Event) { - if !l.root { - l.parent.addContextField(e) - } - if l.field.mode != zeroFieldMode { - e.append(l.field) - } -} diff --git a/log/log.go b/log/log.go index 86dd032..c516dd0 100644 --- a/log/log.go +++ b/log/log.go @@ -28,28 +28,28 @@ func Sample(every int) zerolog.Logger { // Debug starts a new message with debug level. // // You must call Msg on the returned event in order to send the event. -func Debug() zerolog.Event { +func Debug() *zerolog.Event { return Logger.Debug() } // Info starts a new message with info level. // // You must call Msg on the returned event in order to send the event. -func Info() zerolog.Event { +func Info() *zerolog.Event { return Logger.Info() } // Warn starts a new message with warn level. // // You must call Msg on the returned event in order to send the event. -func Warn() zerolog.Event { +func Warn() *zerolog.Event { return Logger.Warn() } // Error starts a new message with error level. // // You must call Msg on the returned event in order to send the event. -func Error() zerolog.Event { +func Error() *zerolog.Event { return Logger.Error() } @@ -57,7 +57,7 @@ func Error() zerolog.Event { // is called by the Msg method. // // You must call Msg on the returned event in order to send the event. -func Fatal() zerolog.Event { +func Fatal() *zerolog.Event { return Logger.Fatal() } @@ -65,7 +65,7 @@ func Fatal() zerolog.Event { // to the panic function. // // You must call Msg on the returned event in order to send the event. -func Panic() zerolog.Event { +func Panic() *zerolog.Event { return Logger.Panic() } @@ -73,6 +73,6 @@ func Panic() zerolog.Event { // zerlog.Disabled will still disable events produced by this method. // // You must call Msg on the returned event in order to send the event. -func Log() zerolog.Event { +func Log() *zerolog.Event { return Logger.Log() } diff --git a/log_example_test.go b/log_example_test.go index 22b0e6a..d1f5484 100644 --- a/log_example_test.go +++ b/log_example_test.go @@ -111,7 +111,7 @@ func ExampleEvent_Dict() { ). Msg("hello world") - // Output: {"foo":"bar",{"bar":"baz","n":1},"message":"hello world"} + // Output: {"foo":"bar","dict":{"bar":"baz","n":1},"message":"hello world"} } func ExampleContext_Dict() {