zaptest: Add testing.TB compatible logger

zaptest/logger.go

@@ -0,0 +1,124 @@
+// Copyright (c) 2017 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 zaptest
+
+import (
+	"bytes"
+
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+)
+
+// LoggerOption configures the test logger built by NewLogger.
+type LoggerOption interface {
+	applyLoggerOption(*loggerOptions)
+}
+
+type loggerOptions struct {
+	Level zapcore.LevelEnabler
+}
+
+type loggerOptionFunc func(*loggerOptions)
+
+func (f loggerOptionFunc) applyLoggerOption(opts *loggerOptions) {
+	f(opts)
+}
+
+// Level controls which messages are logged by a test Logger built by
+// NewLogger.
+func Level(enab zapcore.LevelEnabler) LoggerOption {
+	return loggerOptionFunc(func(opts *loggerOptions) {
+		opts.Level = enab
+	})
+}
+
+// NewLogger builds a new Logger that logs all messages to the given
+// testing.TB.
+//
+//   logger := zaptest.NewLogger(t)
+//
+// Use this with a *testing.T or *testing.B to get logs which get printed only
+// if a test fails or if you ran go test -v.
+//
+// The returned logger defaults to logging debug level messages and above.
+// This may be changd by passing a zaptest.Level during construction.
+//
+//   logger := zaptest.NewLogger(t, zaptest.Level(zap.WarnLevel))
+func NewLogger(t TestingT, opts ...LoggerOption) *zap.Logger {
+	cfg := loggerOptions{
+		Level: zapcore.DebugLevel,
+	}
+	for _, o := range opts {
+		o.applyLoggerOption(&cfg)
+	}
+
+	writer := newTestingWriter(t)
+	return zap.New(
+		zapcore.NewCore(
+			zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig()),
+			writer,
+			cfg.Level,
+		),
+
+		// Send zap errors to the same writer and mark the test as failed if
+		// that happens.
+		zap.ErrorOutput(writer.WithMarkFailed(true)),
+	)
+}
+
+// testingWriter is a WriteSyncer that writes to the given testing.TB.
+type testingWriter struct {
+	t TestingT
+
+	// If true, the test will be marked as failed if this testingWriter is
+	// ever used.
+	markFailed bool
+}
+
+func newTestingWriter(t TestingT) testingWriter {
+	return testingWriter{t: t}
+}
+
+// WithMarkFailed returns a copy of this testingWriter with markFailed set to
+// the provided value.
+func (w testingWriter) WithMarkFailed(v bool) testingWriter {
+	w.markFailed = v
+	return w
+}
+
+func (w testingWriter) Write(p []byte) (n int, err error) {
+	n = len(p)
+
+	// Strip trailing newline because t.Log always adds one.
+	p = bytes.TrimRight(p, "\n")
+
+	// Note: t.Log is safe for concurrent use.
+	w.t.Logf("%s", p)
+	if w.markFailed {
+		w.t.Fail()
+	}
+
+	return n, nil
+}
+
+func (w testingWriter) Sync() error {
+	return nil
+}

zaptest/logger_test.go

@@ -0,0 +1,169 @@
+// Copyright (c) 2017 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 zaptest
+
+import (
+	"errors"
+	"fmt"
+	"io"
+	"strings"
+	"testing"
+
+	"go.uber.org/zap"
+	"go.uber.org/zap/internal/ztest"
+	"go.uber.org/zap/zapcore"
+
+	"github.com/stretchr/testify/assert"
+)
+
+func TestTestLogger(t *testing.T) {
+	ts := newTestLogSpy(t)
+	defer ts.AssertPassed()
+
+	log := NewLogger(ts)
+
+	log.Info("received work order")
+	log.Debug("starting work")
+	log.Warn("work may fail")
+	log.Error("work failed", zap.Error(errors.New("great sadness")))
+
+	assert.Panics(t, func() {
+		log.Panic("failed to do work")
+	}, "log.Panic should panic")
+
+	ts.AssertMessages(
+		"INFO	received work order",
+		"DEBUG	starting work",
+		"WARN	work may fail",
+		`ERROR	work failed	{"error": "great sadness"}`,
+		"PANIC	failed to do work",
+	)
+}
+
+func TestTestLoggerSupportsLevels(t *testing.T) {
+	ts := newTestLogSpy(t)
+	defer ts.AssertPassed()
+
+	log := NewLogger(ts, Level(zap.WarnLevel))
+
+	log.Info("received work order")
+	log.Debug("starting work")
+	log.Warn("work may fail")
+	log.Error("work failed", zap.Error(errors.New("great sadness")))
+
+	assert.Panics(t, func() {
+		log.Panic("failed to do work")
+	}, "log.Panic should panic")
+
+	ts.AssertMessages(
+		"WARN	work may fail",
+		`ERROR	work failed	{"error": "great sadness"}`,
+		"PANIC	failed to do work",
+	)
+}
+
+func TestTestingWriter(t *testing.T) {
+	ts := newTestLogSpy(t)
+	w := newTestingWriter(ts)
+
+	n, err := io.WriteString(w, "hello\n\n")
+	assert.NoError(t, err, "WriteString must not fail")
+	assert.Equal(t, 7, n)
+}
+
+func TestTestLoggerErrorOutput(t *testing.T) {
+	// This test verifies that the test logger logs internal messages to the
+	// testing.T and marks the test as failed.
+
+	ts := newTestLogSpy(t)
+	defer ts.AssertFailed()
+
+	log := NewLogger(ts)
+
+	// Replace with a core that fails.
+	log = log.WithOptions(zap.WrapCore(func(zapcore.Core) zapcore.Core {
+		return zapcore.NewCore(
+			zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig()),
+			zapcore.Lock(zapcore.AddSync(ztest.FailWriter{})),
+			zapcore.DebugLevel,
+		)
+	}))
+
+	log.Info("foo") // this fails
+
+	if assert.Len(t, ts.Messages, 1, "expected a log message") {
+		assert.Regexp(t, `write error: failed`, ts.Messages[0])
+	}
+}
+
+// testLogSpy is a testing.TB that captures logged messages.
+type testLogSpy struct {
+	testing.TB
+
+	failed   bool
+	Messages []string
+}
+
+func newTestLogSpy(t testing.TB) *testLogSpy {
+	return &testLogSpy{TB: t}
+}
+
+func (t *testLogSpy) Fail() {
+	t.failed = true
+}
+
+func (t *testLogSpy) Failed() bool {
+	return t.failed
+}
+
+func (t *testLogSpy) FailNow() {
+	t.Fail()
+	t.TB.FailNow()
+}
+
+func (t *testLogSpy) Logf(format string, args ...interface{}) {
+	// Log messages are in the format,
+	//
+	//   2017-10-27T13:03:01.000-0700	DEBUG	your message here	{data here}
+	//
+	// We strip the first part of these messages because we can't really test
+	// for the timestamp from these tests.
+	m := fmt.Sprintf(format, args...)
+	m = m[strings.IndexByte(m, '\t')+1:]
+	t.Messages = append(t.Messages, m)
+	t.TB.Log(m)
+}
+
+func (t *testLogSpy) AssertMessages(msgs ...string) {
+	assert.Equal(t.TB, msgs, t.Messages, "logged messages did not match")
+}
+
+func (t *testLogSpy) AssertPassed() {
+	t.assertFailed(false, "expected test to pass")
+}
+
+func (t *testLogSpy) AssertFailed() {
+	t.assertFailed(true, "expected test to fail")
+}
+
+func (t *testLogSpy) assertFailed(v bool, msg string) {
+	assert.Equal(t.TB, v, t.failed, msg)
+}

zaptest/testingt.go

@@ -0,0 +1,47 @@
+// Copyright (c) 2017 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 zaptest
+
+// TestingT is a subset of the API provided by all *testing.T and *testing.B
+// objects.
+type TestingT interface {
+	// Logs the given message without failing the test.
+	Logf(string, ...interface{})
+
+	// Logs the given message and marks the test as failed.
+	Errorf(string, ...interface{})
+
+	// Marks the test as failed.
+	Fail()
+
+	// Returns true if the test has been marked as failed.
+	Failed() bool
+
+	// Returns the name of the test.
+	Name() string
+
+	// Marks the test as failed and stops execution of that test.
+	FailNow()
+}
+
+// Note: We currently only rely on Logf. We are including Errorf and FailNow
+// in the interface in anticipation of future need since we can't extend the
+// interface without a breaking change.

zaptest/testingt_test.go

@@ -0,0 +1,29 @@
+// Copyright (c) 2017 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 zaptest
+
+import "testing"
+
+// Just a compile-time test to ensure that TestingT matches the testing.TB
+// interface. We could do this in testingt.go but that would put a dependency
+// on the "testing" package from zaptest.
+
+var _ TestingT = (testing.TB)(nil)