1// Copyright (c) 2017 Uber Technologies, Inc.
2//
3// Permission is hereby granted, free of charge, to any person obtaining a copy
4// of this software and associated documentation files (the "Software"), to deal
5// in the Software without restriction, including without limitation the rights
6// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
7// copies of the Software, and to permit persons to whom the Software is
8// furnished to do so, subject to the following conditions:
9//
10// The above copyright notice and this permission notice shall be included in
11// all copies or substantial portions of the Software.
12//
13// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
14// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
15// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
16// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
17// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
18// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
19// THE SOFTWARE.
20
21package zaptest
22
23import (
24	"errors"
25	"fmt"
26	"io"
27	"strings"
28	"testing"
29
30	"go.uber.org/zap"
31	"go.uber.org/zap/internal/ztest"
32	"go.uber.org/zap/zapcore"
33
34	"github.com/stretchr/testify/assert"
35)
36
37func TestTestLogger(t *testing.T) {
38	ts := newTestLogSpy(t)
39	defer ts.AssertPassed()
40
41	log := NewLogger(ts)
42
43	log.Info("received work order")
44	log.Debug("starting work")
45	log.Warn("work may fail")
46	log.Error("work failed", zap.Error(errors.New("great sadness")))
47
48	assert.Panics(t, func() {
49		log.Panic("failed to do work")
50	}, "log.Panic should panic")
51
52	ts.AssertMessages(
53		"INFO	received work order",
54		"DEBUG	starting work",
55		"WARN	work may fail",
56		`ERROR	work failed	{"error": "great sadness"}`,
57		"PANIC	failed to do work",
58	)
59}
60
61func TestTestLoggerSupportsLevels(t *testing.T) {
62	ts := newTestLogSpy(t)
63	defer ts.AssertPassed()
64
65	log := NewLogger(ts, Level(zap.WarnLevel))
66
67	log.Info("received work order")
68	log.Debug("starting work")
69	log.Warn("work may fail")
70	log.Error("work failed", zap.Error(errors.New("great sadness")))
71
72	assert.Panics(t, func() {
73		log.Panic("failed to do work")
74	}, "log.Panic should panic")
75
76	ts.AssertMessages(
77		"WARN	work may fail",
78		`ERROR	work failed	{"error": "great sadness"}`,
79		"PANIC	failed to do work",
80	)
81}
82
83func TestTestLoggerSupportsWrappedZapOptions(t *testing.T) {
84	ts := newTestLogSpy(t)
85	defer ts.AssertPassed()
86
87	log := NewLogger(ts, WrapOptions(zap.AddCaller(), zap.Fields(zap.String("k1", "v1"))))
88
89	log.Info("received work order")
90	log.Debug("starting work")
91	log.Warn("work may fail")
92	log.Error("work failed", zap.Error(errors.New("great sadness")))
93
94	assert.Panics(t, func() {
95		log.Panic("failed to do work")
96	}, "log.Panic should panic")
97
98	ts.AssertMessages(
99		`INFO	zaptest/logger_test.go:89	received work order	{"k1": "v1"}`,
100		`DEBUG	zaptest/logger_test.go:90	starting work	{"k1": "v1"}`,
101		`WARN	zaptest/logger_test.go:91	work may fail	{"k1": "v1"}`,
102		`ERROR	zaptest/logger_test.go:92	work failed	{"k1": "v1", "error": "great sadness"}`,
103		`PANIC	zaptest/logger_test.go:95	failed to do work	{"k1": "v1"}`,
104	)
105}
106
107func TestTestingWriter(t *testing.T) {
108	ts := newTestLogSpy(t)
109	w := newTestingWriter(ts)
110
111	n, err := io.WriteString(w, "hello\n\n")
112	assert.NoError(t, err, "WriteString must not fail")
113	assert.Equal(t, 7, n)
114}
115
116func TestTestLoggerErrorOutput(t *testing.T) {
117	// This test verifies that the test logger logs internal messages to the
118	// testing.T and marks the test as failed.
119
120	ts := newTestLogSpy(t)
121	defer ts.AssertFailed()
122
123	log := NewLogger(ts)
124
125	// Replace with a core that fails.
126	log = log.WithOptions(zap.WrapCore(func(zapcore.Core) zapcore.Core {
127		return zapcore.NewCore(
128			zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig()),
129			zapcore.Lock(zapcore.AddSync(ztest.FailWriter{})),
130			zapcore.DebugLevel,
131		)
132	}))
133
134	log.Info("foo") // this fails
135
136	if assert.Len(t, ts.Messages, 1, "expected a log message") {
137		assert.Regexp(t, `write error: failed`, ts.Messages[0])
138	}
139}
140
141// testLogSpy is a testing.TB that captures logged messages.
142type testLogSpy struct {
143	testing.TB
144
145	failed   bool
146	Messages []string
147}
148
149func newTestLogSpy(t testing.TB) *testLogSpy {
150	return &testLogSpy{TB: t}
151}
152
153func (t *testLogSpy) Fail() {
154	t.failed = true
155}
156
157func (t *testLogSpy) Failed() bool {
158	return t.failed
159}
160
161func (t *testLogSpy) FailNow() {
162	t.Fail()
163	t.TB.FailNow()
164}
165
166func (t *testLogSpy) Logf(format string, args ...interface{}) {
167	// Log messages are in the format,
168	//
169	//   2017-10-27T13:03:01.000-0700	DEBUG	your message here	{data here}
170	//
171	// We strip the first part of these messages because we can't really test
172	// for the timestamp from these tests.
173	m := fmt.Sprintf(format, args...)
174	m = m[strings.IndexByte(m, '\t')+1:]
175	t.Messages = append(t.Messages, m)
176	t.TB.Log(m)
177}
178
179func (t *testLogSpy) AssertMessages(msgs ...string) {
180	assert.Equal(t.TB, msgs, t.Messages, "logged messages did not match")
181}
182
183func (t *testLogSpy) AssertPassed() {
184	t.assertFailed(false, "expected test to pass")
185}
186
187func (t *testLogSpy) AssertFailed() {
188	t.assertFailed(true, "expected test to fail")
189}
190
191func (t *testLogSpy) assertFailed(v bool, msg string) {
192	assert.Equal(t.TB, v, t.failed, msg)
193}
194