Skip to content

Commit

Permalink
Merge branch 'dev' into sugar
Browse files Browse the repository at this point in the history
  • Loading branch information
akshayjshah committed Jan 13, 2017
2 parents 834748b + 6bbe2f0 commit 2706003
Show file tree
Hide file tree
Showing 13 changed files with 565 additions and 514 deletions.
8 changes: 5 additions & 3 deletions common_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ import (
"sync"
"testing"

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

Expand All @@ -33,10 +34,11 @@ 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, *zapcore.ObservedLogs)) {
fac, logs := zapcore.NewObserver(e, 1024)
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)
log := New(fac, opts...)
f(log, logs)
f(log, &logs)
}

func withSugar(t testing.TB, e zapcore.LevelEnabler, opts []Option, f func(*SugaredLogger, *zapcore.ObservedLogs)) {
Expand Down
4 changes: 3 additions & 1 deletion http_handler_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@ import (
"testing"

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

"github.com/stretchr/testify/assert"
Expand All @@ -39,7 +40,8 @@ import (

func newHandler() (AtomicLevel, Logger) {
lvl := DynamicLevel()
fac, _ := zapcore.NewObserver(lvl, 1)
// XXX should be a discard facility
fac := observer.New(lvl, func(observer.LoggedEntry) error { return nil }, false)
logger := New(fac)
return lvl, logger
}
Expand Down
145 changes: 145 additions & 0 deletions internal/observer/observer.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,145 @@
// Copyright (c) 2016 Uber Technologies, Inc.
//
// Permission is hereby granted, free of charge, to any person obtaining a copy
// of this software and associated documentation files (the "Software"), to deal
// in the Software without restriction, including without limitation the rights
// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
// copies of the Software, and to permit persons to whom the Software is
// furnished to do so, subject to the following conditions:
//
// The above copyright notice and this permission notice shall be included in
// all copies or substantial portions of the Software.
//
// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
// THE SOFTWARE.

package observer

import (
"sync"
"time"

"go.uber.org/zap/zapcore"
)

// An LoggedEntry is an encoding-agnostic representation of a log message.
// Field availability is context dependant.
type LoggedEntry struct {
zapcore.Entry
Context []zapcore.Field
}

// ObservedLogs is a concurrency-safe, ordered collection of observed logs.
type ObservedLogs struct {
mu sync.RWMutex
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()
n := len(o.logs)
o.mu.RUnlock()
return n
}

// All returns a copy of all the observed logs.
func (o *ObservedLogs) All() []LoggedEntry {
o.mu.RLock()
ret := make([]LoggedEntry, len(o.logs))
for i := range o.logs {
ret[i] = o.logs[i]
}
o.mu.RUnlock()
return ret
}

// AllUntimed returns a copy of all the observed logs, but overwrites the
// observed timestamps with time.Time's zero value. This is useful when making
// assertions in tests.
func (o *ObservedLogs) AllUntimed() []LoggedEntry {
ret := o.All()
for i := range ret {
ret[i].Time = time.Time{}
}
return ret
}

type observer struct {
zapcore.LevelEnabler
sink func(LoggedEntry) error
}

// New creates a new facility that buffers logs in memory (without any
// encoding). It's particularly useful in tests, though it can serve a variety
// of other purposes as well. This constructor returns the facility itself and
// a function to retrieve the observed logs.
func New(enab zapcore.LevelEnabler, sink func(LoggedEntry) error, withContext bool) zapcore.Facility {
if withContext {
return &contextObserver{
LevelEnabler: enab,
sink: sink,
}
}
return &observer{
LevelEnabler: enab,
sink: sink,
}
}

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

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

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

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

func (co *contextObserver) Check(ent zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry {
if co.Enabled(ent.Level) {
return ce.AddFacility(ent, co)
}
return ce
}

func (co *contextObserver) With(fields []zapcore.Field) zapcore.Facility {
return &contextObserver{
LevelEnabler: co.LevelEnabler,
sink: co.sink,
context: append(co.context[:len(co.context):len(co.context)], fields...),
}
}

func (co *contextObserver) Write(ent zapcore.Entry, fields []zapcore.Field) error {
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})
}
45 changes: 23 additions & 22 deletions logger_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ import (
"testing"

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

Expand All @@ -35,7 +36,7 @@ func TestLoggerDynamicLevel(t *testing.T) {
// Test that the DynamicLevel applys to all ancestors and descendants.
dl := DynamicLevel()

withLogger(t, dl, nil, func(grandparent Logger, _ *zapcore.ObservedLogs) {
withLogger(t, dl, nil, func(grandparent Logger, _ *observer.ObservedLogs) {
parent := grandparent.With(Int("generation", 1))
child := parent.With(Int("generation", 2))

Expand Down Expand Up @@ -72,11 +73,11 @@ func TestLoggerDynamicLevel(t *testing.T) {

func TestLoggerInitialFields(t *testing.T) {
fieldOpts := opts(Fields(Int("foo", 42), String("bar", "baz")))
withLogger(t, DebugLevel, fieldOpts, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, fieldOpts, func(logger Logger, logs *observer.ObservedLogs) {
logger.Info("")
assert.Equal(
t,
zapcore.ObservedLog{Context: []zapcore.Field{Int("foo", 42), String("bar", "baz")}},
observer.LoggedEntry{Context: []zapcore.Field{Int("foo", 42), String("bar", "baz")}},
logs.AllUntimed()[0],
"Unexpected output with initial fields set.",
)
Expand All @@ -85,14 +86,14 @@ func TestLoggerInitialFields(t *testing.T) {

func TestLoggerWith(t *testing.T) {
fieldOpts := opts(Fields(Int("foo", 42)))
withLogger(t, DebugLevel, fieldOpts, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, fieldOpts, func(logger Logger, logs *observer.ObservedLogs) {
// Child loggers should have copy-on-write semantics, so two children
// shouldn't stomp on each other's fields or affect the parent's fields.
logger.With(String("one", "two")).Info("")
logger.With(String("three", "four")).Info("")
logger.Info("")

assert.Equal(t, []zapcore.ObservedLog{
assert.Equal(t, []observer.LoggedEntry{
{Context: []zapcore.Field{Int("foo", 42), String("one", "two")}},
{Context: []zapcore.Field{Int("foo", 42), String("three", "four")}},
{Context: []zapcore.Field{Int("foo", 42)}},
Expand All @@ -109,7 +110,7 @@ func TestLoggerLogPanic(t *testing.T) {
{func(logger Logger) { logger.Check(PanicLevel, "bar").Write() }, true, "bar"},
{func(logger Logger) { logger.Panic("baz") }, true, "baz"},
} {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *observer.ObservedLogs) {
if tt.should {
assert.Panics(t, func() { tt.do(logger) }, "Expected panic")
} else {
Expand Down Expand Up @@ -137,7 +138,7 @@ func TestLoggerLogFatal(t *testing.T) {
{func(logger Logger) { logger.Check(FatalLevel, "bar").Write() }, "bar"},
{func(logger Logger) { logger.Fatal("baz") }, "baz"},
} {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *observer.ObservedLogs) {
stub := exit.WithStub(func() {
tt.do(logger)
})
Expand All @@ -156,7 +157,7 @@ func TestLoggerLogFatal(t *testing.T) {
}

func TestLoggerLeveledMethods(t *testing.T) {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *observer.ObservedLogs) {
tests := []struct {
method func(string, ...zapcore.Field)
expectedLevel zapcore.Level
Expand Down Expand Up @@ -184,7 +185,7 @@ func TestLoggerLeveledMethods(t *testing.T) {
func TestLoggerAlwaysPanics(t *testing.T) {
// Users can disable writing out panic-level logs, but calls to logger.Panic()
// should still call panic().
withLogger(t, FatalLevel, nil, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, FatalLevel, nil, func(logger Logger, logs *observer.ObservedLogs) {
msg := "Even if output is disabled, logger.Panic should always panic."
assert.Panics(t, func() { logger.Panic("foo") }, msg)
assert.Panics(t, func() {
Expand All @@ -199,7 +200,7 @@ func TestLoggerAlwaysPanics(t *testing.T) {
func TestLoggerAlwaysFatals(t *testing.T) {
// Users can disable writing out fatal-level logs, but calls to logger.Fatal()
// should still terminate the process.
withLogger(t, FatalLevel+1, nil, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, FatalLevel+1, nil, func(logger Logger, logs *observer.ObservedLogs) {
stub := exit.WithStub(func() { logger.Fatal("") })
assert.True(t, stub.Exited, "Expected calls to logger.Fatal to terminate process.")

Expand All @@ -215,32 +216,32 @@ func TestLoggerAlwaysFatals(t *testing.T) {
}

func TestLoggerDPanic(t *testing.T) {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *observer.ObservedLogs) {
assert.NotPanics(t, func() { logger.DPanic("") })
assert.Equal(
t,
[]zapcore.ObservedLog{{Entry: zapcore.Entry{Level: DPanicLevel}, Context: []zapcore.Field{}}},
[]observer.LoggedEntry{{Entry: zapcore.Entry{Level: DPanicLevel}, Context: []zapcore.Field{}}},
logs.AllUntimed(),
"Unexpected log output from DPanic in production mode.",
)
})
withLogger(t, DebugLevel, opts(Development()), func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, opts(Development()), func(logger Logger, logs *observer.ObservedLogs) {
assert.Panics(t, func() { logger.DPanic("") })
assert.Equal(
t,
[]zapcore.ObservedLog{{Entry: zapcore.Entry{Level: DPanicLevel}, Context: []zapcore.Field{}}},
[]observer.LoggedEntry{{Entry: zapcore.Entry{Level: DPanicLevel}, Context: []zapcore.Field{}}},
logs.AllUntimed(),
"Unexpected log output from DPanic in development mode.",
)
})
}

func TestLoggerNoOpsDisabledLevels(t *testing.T) {
withLogger(t, WarnLevel, nil, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, WarnLevel, nil, func(logger Logger, logs *observer.ObservedLogs) {
logger.Info("silence!")
assert.Equal(
t,
[]zapcore.ObservedLog{},
[]observer.LoggedEntry{},
logs.AllUntimed(),
"Expected logging at a disabled level to produce no output.",
)
Expand Down Expand Up @@ -275,7 +276,7 @@ func TestLoggerAddCaller(t *testing.T) {
{opts(AddCaller(), AddCallerSkip(1), AddCallerSkip(3)), `.+/src/runtime/.*:[\d]+$`},
}
for _, tt := range tests {
withLogger(t, DebugLevel, tt.options, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, tt.options, func(logger Logger, logs *observer.ObservedLogs) {
logger.Info("")
output := logs.AllUntimed()
assert.Equal(t, 1, len(output), "Unexpected number of logs written out.")
Expand All @@ -291,7 +292,7 @@ func TestLoggerAddCaller(t *testing.T) {

func TestLoggerAddCallerFail(t *testing.T) {
errBuf := &testutils.Buffer{}
withLogger(t, DebugLevel, opts(AddCaller(), ErrorOutput(errBuf)), func(log Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, opts(AddCaller(), ErrorOutput(errBuf)), func(log Logger, logs *observer.ObservedLogs) {
// TODO: Use AddCallerSkip
logImpl := log.(*logger)
logImpl.callerSkip = 1e3
Expand All @@ -312,11 +313,11 @@ func TestLoggerAddCallerFail(t *testing.T) {
}

func TestLoggerAddStacks(t *testing.T) {
assertHasStack := func(t testing.TB, obs zapcore.ObservedLog) {
assertHasStack := func(t testing.TB, obs observer.LoggedEntry) {
assert.Contains(t, obs.Entry.Stack, "zap.TestLoggerAddStacks", "Expected to find test function in stacktrace.")
}

withLogger(t, DebugLevel, opts(AddStacks(InfoLevel)), func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, opts(AddStacks(InfoLevel)), func(logger Logger, logs *observer.ObservedLogs) {
logger.Debug("")
assert.Empty(
t,
Expand All @@ -333,7 +334,7 @@ func TestLoggerAddStacks(t *testing.T) {
}

func TestLoggerConcurrent(t *testing.T) {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *zapcore.ObservedLogs) {
withLogger(t, DebugLevel, nil, func(logger Logger, logs *observer.ObservedLogs) {
child := logger.With(String("foo", "bar"))

wg := &sync.WaitGroup{}
Expand All @@ -351,7 +352,7 @@ func TestLoggerConcurrent(t *testing.T) {
for _, obs := range logs.AllUntimed() {
assert.Equal(
t,
zapcore.ObservedLog{
observer.LoggedEntry{
Entry: zapcore.Entry{Level: InfoLevel},
Context: []zapcore.Field{String("foo", "bar")},
},
Expand Down
Loading

0 comments on commit 2706003

Please sign in to comment.