Skip to content

Commit

Permalink
Export zap's internal observing logger (#372)
Browse files Browse the repository at this point in the history
Simplify `internal/observer` and export it as `zaptest/observer`.
  • Loading branch information
billf authored and akshayjshah committed Mar 14, 2017
1 parent 402d056 commit 79e323d
Show file tree
Hide file tree
Showing 10 changed files with 74 additions and 119 deletions.
2 changes: 1 addition & 1 deletion Makefile
Expand Up @@ -3,7 +3,7 @@ export GO15VENDOREXPERIMENT=1
BENCH_FLAGS ?= -cpuprofile=cpu.pprof -memprofile=mem.pprof -benchmem
PKGS ?= $(shell glide novendor)
# Many Go tools take file globs or directories as arguments instead of packages.
PKG_FILES ?= *.go zapcore benchmarks buffer zaptest internal/bufferpool internal/exit internal/multierror internal/observer internal/color
PKG_FILES ?= *.go zapcore benchmarks buffer zaptest zaptest/observer internal/bufferpool internal/exit internal/multierror internal/color

COVERALLS_IGNORE := internal/readme/readme.go

Expand Down
7 changes: 3 additions & 4 deletions common_test.go
Expand Up @@ -24,8 +24,8 @@ import (
"sync"
"testing"

"go.uber.org/zap/internal/observer"
"go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest/observer"
)

func opts(opts ...Option) []Option {
Expand All @@ -35,10 +35,9 @@ func opts(opts ...Option) []Option {
// Here specifically to introduce an easily-identifiable filename for testing
// stacktraces and caller skips.
func withLogger(t testing.TB, e zapcore.LevelEnabler, opts []Option, f func(*Logger, *observer.ObservedLogs)) {
var logs observer.ObservedLogs
fac := observer.New(e, logs.Add, true)
fac, logs := observer.New(e)
log := New(fac, opts...)
f(log, &logs)
f(log, logs)
}

func withSugar(t testing.TB, e zapcore.LevelEnabler, opts []Option, f func(*SugaredLogger, *observer.ObservedLogs)) {
Expand Down
2 changes: 1 addition & 1 deletion global_test.go
Expand Up @@ -26,9 +26,9 @@ import (
"testing"
"time"

"go.uber.org/zap/internal/observer"
"go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest"
"go.uber.org/zap/zaptest/observer"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
Expand Down
2 changes: 1 addition & 1 deletion logger_test.go
Expand Up @@ -26,9 +26,9 @@ import (
"testing"

"go.uber.org/zap/internal/exit"
"go.uber.org/zap/internal/observer"
"go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest"
"go.uber.org/zap/zaptest/observer"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
Expand Down
8 changes: 4 additions & 4 deletions sugar_test.go
Expand Up @@ -23,13 +23,13 @@ package zap
import (
"testing"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"

"go.uber.org/zap/internal/exit"
"go.uber.org/zap/internal/observer"
"go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest"
"go.uber.org/zap/zaptest/observer"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)

func TestSugarWith(t *testing.T) {
Expand Down
9 changes: 4 additions & 5 deletions zapcore/hook_test.go
Expand Up @@ -23,10 +23,10 @@ package zapcore_test
import (
"testing"

"github.com/stretchr/testify/assert"

"go.uber.org/zap/internal/observer"
. "go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest/observer"

"github.com/stretchr/testify/assert"
)

func TestHooks(t *testing.T) {
Expand All @@ -41,8 +41,7 @@ func TestHooks(t *testing.T) {
}

for _, tt := range tests {
var logs observer.ObservedLogs
fac := observer.New(tt.coreLevel, logs.Add, true)
fac, logs := observer.New(tt.coreLevel)
intField := makeInt64Field("foo", 42)
ent := Entry{Message: "bar", Level: tt.entryLevel}

Expand Down
13 changes: 6 additions & 7 deletions zapcore/sampler_test.go
Expand Up @@ -26,20 +26,19 @@ import (
"testing"
"time"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"

"go.uber.org/atomic"
"go.uber.org/zap/internal/observer"
. "go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest"
"go.uber.org/zap/zaptest/observer"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)

func fakeSampler(lvl LevelEnabler, tick time.Duration, first, thereafter int) (Core, *observer.ObservedLogs) {
var logs observer.ObservedLogs
core := observer.New(lvl, logs.Add, true)
core, logs := observer.New(lvl)
core = NewSampler(core, tick, first, thereafter)
return core, &logs
return core, logs
}

func assertSequence(t testing.TB, logs []observer.LoggedEntry, lvl Level, seq ...int64) {
Expand Down
28 changes: 12 additions & 16 deletions zapcore/tee_test.go
Expand Up @@ -24,26 +24,24 @@ import (
"errors"
"testing"

"go.uber.org/zap/internal/observer"
. "go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest"
"go.uber.org/zap/zaptest/observer"

"github.com/stretchr/testify/assert"
)

func withTee(f func(core Core, debugLogs, warnLogs *observer.ObservedLogs)) {
var debugLogs, warnLogs observer.ObservedLogs
tee := NewTee(
observer.New(DebugLevel, debugLogs.Add, true),
observer.New(WarnLevel, warnLogs.Add, true),
)
f(tee, &debugLogs, &warnLogs)
debugLogger, debugLogs := observer.New(DebugLevel)
warnLogger, warnLogs := observer.New(WarnLevel)
tee := NewTee(debugLogger, warnLogger)
f(tee, debugLogs, warnLogs)
}

func TestTeeUnusualInput(t *testing.T) {
// Verify that Tee handles receiving one and no inputs correctly.
t.Run("one input", func(t *testing.T) {
obs := observer.New(DebugLevel, nil, true)
obs, _ := observer.New(DebugLevel)
assert.Equal(t, obs, NewTee(obs), "Expected to return single inputs unchanged.")
})
t.Run("no input", func(t *testing.T) {
Expand Down Expand Up @@ -114,10 +112,9 @@ func TestTeeWith(t *testing.T) {
}

func TestTeeEnabled(t *testing.T) {
tee := NewTee(
observer.New(InfoLevel, nil, false),
observer.New(WarnLevel, nil, false),
)
infoLogger, _ := observer.New(InfoLevel)
warnLogger, _ := observer.New(WarnLevel)
tee := NewTee(infoLogger, warnLogger)
tests := []struct {
lvl Level
enabled bool
Expand All @@ -137,10 +134,9 @@ func TestTeeEnabled(t *testing.T) {
}

func TestTeeSync(t *testing.T) {
tee := NewTee(
observer.New(InfoLevel, nil, false),
observer.New(WarnLevel, nil, false),
)
infoLogger, _ := observer.New(InfoLevel)
warnLogger, _ := observer.New(WarnLevel)
tee := NewTee(infoLogger, warnLogger)
assert.NoError(t, tee.Sync(), "Unexpected error from Syncing a tee.")

sink := &zaptest.Discarder{}
Expand Down
57 changes: 13 additions & 44 deletions internal/observer/observer.go → zaptest/observer/observer.go
Expand Up @@ -40,15 +40,6 @@ type ObservedLogs struct {
logs []LoggedEntry
}

// Add appends a new observed log to the collection. It always returns nil
// error, but does so that it can be used as an observer sink function.
func (o *ObservedLogs) Add(log LoggedEntry) error {
o.mu.Lock()
o.logs = append(o.logs, log)
o.mu.Unlock()
return nil
}

// Len returns the number of items in the collection.
func (o *ObservedLogs) Len() int {
o.mu.RLock()
Expand Down Expand Up @@ -89,48 +80,25 @@ func (o *ObservedLogs) AllUntimed() []LoggedEntry {
return ret
}

type observer struct {
zapcore.LevelEnabler
sink func(LoggedEntry) error
func (o *ObservedLogs) add(log LoggedEntry) {
o.mu.Lock()
o.logs = append(o.logs, log)
o.mu.Unlock()
}

// New creates a new Core that buffers logs in memory (without any encoding).
// It's particularly useful in tests.
func New(enab zapcore.LevelEnabler, sink func(LoggedEntry) error, withContext bool) zapcore.Core {
if withContext {
return &contextObserver{
LevelEnabler: enab,
sink: sink,
}
}
return &observer{
func New(enab zapcore.LevelEnabler) (zapcore.Core, *ObservedLogs) {
ol := &ObservedLogs{}
return &contextObserver{
LevelEnabler: enab,
sink: sink,
}
}

func (o *observer) Check(ent zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry {
if o.Enabled(ent.Level) {
return ce.AddCore(ent, o)
}
return ce
}

func (o *observer) With(fields []zapcore.Field) zapcore.Core {
return &observer{LevelEnabler: o.LevelEnabler, sink: o.sink}
}

func (o *observer) Write(ent zapcore.Entry, fields []zapcore.Field) error {
return o.sink(LoggedEntry{ent, fields})
}

func (o *observer) Sync() error {
return nil
logs: ol,
}, ol
}

type contextObserver struct {
zapcore.LevelEnabler
sink func(LoggedEntry) error
logs *ObservedLogs
context []zapcore.Field
}

Expand All @@ -144,7 +112,7 @@ func (co *contextObserver) Check(ent zapcore.Entry, ce *zapcore.CheckedEntry) *z
func (co *contextObserver) With(fields []zapcore.Field) zapcore.Core {
return &contextObserver{
LevelEnabler: co.LevelEnabler,
sink: co.sink,
logs: co.logs,
context: append(co.context[:len(co.context):len(co.context)], fields...),
}
}
Expand All @@ -153,7 +121,8 @@ func (co *contextObserver) Write(ent zapcore.Entry, fields []zapcore.Field) erro
all := make([]zapcore.Field, 0, len(fields)+len(co.context))
all = append(all, co.context...)
all = append(all, fields...)
return co.sink(LoggedEntry{ent, all})
co.logs.add(LoggedEntry{ent, all})
return nil
}

func (co *contextObserver) Sync() error {
Expand Down
Expand Up @@ -21,16 +21,15 @@
package observer_test

import (
"fmt"
"testing"
"time"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"

"go.uber.org/zap"
. "go.uber.org/zap/internal/observer"
"go.uber.org/zap/zapcore"
. "go.uber.org/zap/zaptest/observer"
)

func assertEmpty(t testing.TB, logs *ObservedLogs) {
Expand All @@ -39,43 +38,37 @@ func assertEmpty(t testing.TB, logs *ObservedLogs) {
}

func TestObserver(t *testing.T) {
for _, includeContext := range []bool{false, true} {
t.Run(fmt.Sprint("withContext ", includeContext), func(t *testing.T) {
logs := &ObservedLogs{}
assertEmpty(t, logs)

obs := zap.New(New(zap.InfoLevel, logs.Add, includeContext)).With(zap.Int("i", 1))
obs.Info("foo")
obs.Debug("bar")
want := []LoggedEntry{{
Entry: zapcore.Entry{Level: zap.InfoLevel, Message: "foo"},
Context: nil,
}}
if includeContext {
want[0].Context = []zapcore.Field{zap.Int("i", 1)}
}

assert.Equal(t, 1, logs.Len(), "Unexpected observed logs Len.")
assert.Equal(t, want, logs.AllUntimed(), "Unexpected contents from AllUntimed.")

all := logs.All()
require.Equal(t, 1, len(all), "Unexpected numbed of LoggedEntries returned from All.")
assert.NotEqual(t, time.Time{}, all[0].Time, "Expected non-zero time on LoggedEntry.")

// copy & zero time for stable assertions
untimed := append([]LoggedEntry{}, all...)
untimed[0].Time = time.Time{}
assert.Equal(t, want, untimed, "Unexpected LoggedEntries from All.")

assert.Equal(t, all, logs.TakeAll(), "Expected All and TakeAll to return identical results.")
assertEmpty(t, logs)
})
}
observer, logs := New(zap.InfoLevel)
assertEmpty(t, logs)

assert.NoError(t, observer.Sync(), "Unexpected failure in no-op Sync")

obs := zap.New(observer).With(zap.Int("i", 1))
obs.Info("foo")
obs.Debug("bar")
want := []LoggedEntry{{
Entry: zapcore.Entry{Level: zap.InfoLevel, Message: "foo"},
Context: []zapcore.Field{zap.Int("i", 1)},
}}

assert.Equal(t, 1, logs.Len(), "Unexpected observed logs Len.")
assert.Equal(t, want, logs.AllUntimed(), "Unexpected contents from AllUntimed.")

all := logs.All()
require.Equal(t, 1, len(all), "Unexpected numbed of LoggedEntries returned from All.")
assert.NotEqual(t, time.Time{}, all[0].Time, "Expected non-zero time on LoggedEntry.")

// copy & zero time for stable assertions
untimed := append([]LoggedEntry{}, all...)
untimed[0].Time = time.Time{}
assert.Equal(t, want, untimed, "Unexpected LoggedEntries from All.")

assert.Equal(t, all, logs.TakeAll(), "Expected All and TakeAll to return identical results.")
assertEmpty(t, logs)
}

func TestObserverWith(t *testing.T) {
var logs ObservedLogs
sf1 := New(zap.InfoLevel, logs.Add, true)
sf1, logs := New(zap.InfoLevel)

// need to pad out enough initial fields so that the underlying slice cap()
// gets ahead of its len() so that the sf3/4 With append's could choose
Expand Down

0 comments on commit 79e323d

Please sign in to comment.