observer_test.go

Documentation: go.uber.org/zap/zaptest/observer

     1  // Copyright (c) 2016-2022 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  
    21  package observer_test
    22  
    23  import (
    24  	"testing"
    25  	"time"
    26  
    27  	"github.com/stretchr/testify/assert"
    28  	"github.com/stretchr/testify/require"
    29  
    30  	"go.uber.org/zap"
    31  	"go.uber.org/zap/zapcore"
    32  
    33  	//revive:disable:dot-imports
    34  	. "go.uber.org/zap/zaptest/observer"
    35  )
    36  
    37  func assertEmpty(t testing.TB, logs *ObservedLogs) {
    38  	assert.Equal(t, 0, logs.Len(), "Expected empty ObservedLogs to have zero length.")
    39  	assert.Equal(t, []LoggedEntry{}, logs.All(), "Unexpected LoggedEntries in empty ObservedLogs.")
    40  }
    41  
    42  func TestObserver(t *testing.T) {
    43  	observer, logs := New(zap.InfoLevel)
    44  	assertEmpty(t, logs)
    45  
    46  	t.Run("LevelOf", func(t *testing.T) {
    47  		assert.Equal(t, zap.InfoLevel, zapcore.LevelOf(observer), "Observer reported the wrong log level.")
    48  	})
    49  
    50  	assert.NoError(t, observer.Sync(), "Unexpected failure in no-op Sync")
    51  
    52  	obs := zap.New(observer).With(zap.Int("i", 1))
    53  	obs.Info("foo")
    54  	obs.Debug("bar")
    55  	want := []LoggedEntry{{
    56  		Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "foo"},
    57  		Context: []zapcore.Field{zap.Int("i", 1)},
    58  	}}
    59  
    60  	assert.Equal(t, 1, logs.Len(), "Unexpected observed logs Len.")
    61  	assert.Equal(t, want, logs.AllUntimed(), "Unexpected contents from AllUntimed.")
    62  
    63  	all := logs.All()
    64  	require.Equal(t, 1, len(all), "Unexpected number of LoggedEntries returned from All.")
    65  	assert.NotEqual(t, time.Time{}, all[0].Time, "Expected non-zero time on LoggedEntry.")
    66  
    67  	// copy & zero time for stable assertions
    68  	untimed := append([]LoggedEntry{}, all...)
    69  	untimed[0].Time = time.Time{}
    70  	assert.Equal(t, want, untimed, "Unexpected LoggedEntries from All.")
    71  
    72  	assert.Equal(t, all, logs.TakeAll(), "Expected All and TakeAll to return identical results.")
    73  	assertEmpty(t, logs)
    74  }
    75  
    76  func TestObserverWith(t *testing.T) {
    77  	sf1, logs := New(zap.InfoLevel)
    78  
    79  	// need to pad out enough initial fields so that the underlying slice cap()
    80  	// gets ahead of its len() so that the sf3/4 With append's could choose
    81  	// not to copy (if the implementation doesn't force them)
    82  	sf1 = sf1.With([]zapcore.Field{zap.Int("a", 1), zap.Int("b", 2)})
    83  
    84  	sf2 := sf1.With([]zapcore.Field{zap.Int("c", 3)})
    85  	sf3 := sf2.With([]zapcore.Field{zap.Int("d", 4)})
    86  	sf4 := sf2.With([]zapcore.Field{zap.Int("e", 5)})
    87  	ent := zapcore.Entry{Level: zap.InfoLevel, Message: "hello"}
    88  
    89  	for i, core := range []zapcore.Core{sf2, sf3, sf4} {
    90  		if ce := core.Check(ent, nil); ce != nil {
    91  			ce.Write(zap.Int("i", i))
    92  		}
    93  	}
    94  
    95  	assert.Equal(t, []LoggedEntry{
    96  		{
    97  			Entry: ent,
    98  			Context: []zapcore.Field{
    99  				zap.Int("a", 1),
   100  				zap.Int("b", 2),
   101  				zap.Int("c", 3),
   102  				zap.Int("i", 0),
   103  			},
   104  		},
   105  		{
   106  			Entry: ent,
   107  			Context: []zapcore.Field{
   108  				zap.Int("a", 1),
   109  				zap.Int("b", 2),
   110  				zap.Int("c", 3),
   111  				zap.Int("d", 4),
   112  				zap.Int("i", 1),
   113  			},
   114  		},
   115  		{
   116  			Entry: ent,
   117  			Context: []zapcore.Field{
   118  				zap.Int("a", 1),
   119  				zap.Int("b", 2),
   120  				zap.Int("c", 3),
   121  				zap.Int("e", 5),
   122  				zap.Int("i", 2),
   123  			},
   124  		},
   125  	}, logs.All(), "expected no field sharing between With siblings")
   126  }
   127  
   128  func TestFilters(t *testing.T) {
   129  	logs := []LoggedEntry{
   130  		{
   131  			Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "log a"},
   132  			Context: []zapcore.Field{zap.String("fStr", "1"), zap.Int("a", 1)},
   133  		},
   134  		{
   135  			Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "log a"},
   136  			Context: []zapcore.Field{zap.String("fStr", "2"), zap.Int("b", 2)},
   137  		},
   138  		{
   139  			Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "log b"},
   140  			Context: []zapcore.Field{zap.Int("a", 1), zap.Int("b", 2)},
   141  		},
   142  		{
   143  			Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "log c"},
   144  			Context: []zapcore.Field{zap.Int("a", 1), zap.Namespace("ns"), zap.Int("a", 2)},
   145  		},
   146  		{
   147  			Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "msg 1"},
   148  			Context: []zapcore.Field{zap.Int("a", 1), zap.Namespace("ns")},
   149  		},
   150  		{
   151  			Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "any map"},
   152  			Context: []zapcore.Field{zap.Any("map", map[string]string{"a": "b"})},
   153  		},
   154  		{
   155  			Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "any slice"},
   156  			Context: []zapcore.Field{zap.Any("slice", []string{"a"})},
   157  		},
   158  		{
   159  			Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "msg 2"},
   160  			Context: []zapcore.Field{zap.Int("b", 2), zap.Namespace("filterMe")},
   161  		},
   162  		{
   163  			Entry:   zapcore.Entry{Level: zap.InfoLevel, Message: "any slice"},
   164  			Context: []zapcore.Field{zap.Any("filterMe", []string{"b"})},
   165  		},
   166  		{
   167  			Entry:   zapcore.Entry{Level: zap.WarnLevel, Message: "danger will robinson"},
   168  			Context: []zapcore.Field{zap.Int("b", 42)},
   169  		},
   170  		{
   171  			Entry:   zapcore.Entry{Level: zap.ErrorLevel, Message: "warp core breach"},
   172  			Context: []zapcore.Field{zap.Int("b", 42)},
   173  		},
   174  	}
   175  
   176  	logger, sink := New(zap.InfoLevel)
   177  	for _, log := range logs {
   178  		assert.NoError(t, logger.Write(log.Entry, log.Context), "Unexpected error writing log entry.")
   179  	}
   180  
   181  	tests := []struct {
   182  		msg      string
   183  		filtered *ObservedLogs
   184  		want     []LoggedEntry
   185  	}{
   186  		{
   187  			msg:      "filter by message",
   188  			filtered: sink.FilterMessage("log a"),
   189  			want:     logs[0:2],
   190  		},
   191  		{
   192  			msg:      "filter by field",
   193  			filtered: sink.FilterField(zap.String("fStr", "1")),
   194  			want:     logs[0:1],
   195  		},
   196  		{
   197  			msg:      "filter by message and field",
   198  			filtered: sink.FilterMessage("log a").FilterField(zap.Int("b", 2)),
   199  			want:     logs[1:2],
   200  		},
   201  		{
   202  			msg:      "filter by field with duplicate fields",
   203  			filtered: sink.FilterField(zap.Int("a", 2)),
   204  			want:     logs[3:4],
   205  		},
   206  		{
   207  			msg:      "filter doesn't match any messages",
   208  			filtered: sink.FilterMessage("no match"),
   209  			want:     []LoggedEntry{},
   210  		},
   211  		{
   212  			msg:      "filter by snippet",
   213  			filtered: sink.FilterMessageSnippet("log"),
   214  			want:     logs[0:4],
   215  		},
   216  		{
   217  			msg:      "filter by snippet and field",
   218  			filtered: sink.FilterMessageSnippet("a").FilterField(zap.Int("b", 2)),
   219  			want:     logs[1:2],
   220  		},
   221  		{
   222  			msg:      "filter for map",
   223  			filtered: sink.FilterField(zap.Any("map", map[string]string{"a": "b"})),
   224  			want:     logs[5:6],
   225  		},
   226  		{
   227  			msg:      "filter for slice",
   228  			filtered: sink.FilterField(zap.Any("slice", []string{"a"})),
   229  			want:     logs[6:7],
   230  		},
   231  		{
   232  			msg:      "filter field key",
   233  			filtered: sink.FilterFieldKey("filterMe"),
   234  			want:     logs[7:9],
   235  		},
   236  		{
   237  			msg: "filter by arbitrary function",
   238  			filtered: sink.Filter(func(e LoggedEntry) bool {
   239  				return len(e.Context) > 1
   240  			}),
   241  			want: func() []LoggedEntry {
   242  				// Do not modify logs slice.
   243  				w := make([]LoggedEntry, 0, len(logs))
   244  				w = append(w, logs[0:5]...)
   245  				w = append(w, logs[7])
   246  				return w
   247  			}(),
   248  		},
   249  		{
   250  			msg:      "filter level",
   251  			filtered: sink.FilterLevelExact(zap.WarnLevel),
   252  			want:     logs[9:10],
   253  		},
   254  	}
   255  
   256  	for _, tt := range tests {
   257  		got := tt.filtered.AllUntimed()
   258  		assert.Equal(t, tt.want, got, tt.msg)
   259  	}
   260  }
   261
View as plain text