1// Copyright (c) 2016 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 zap 22 23import ( 24 "log" 25 "sync" 26 "testing" 27 "time" 28 29 "go.uber.org/zap/internal/exit" 30 "go.uber.org/zap/internal/ztest" 31 32 "go.uber.org/zap/zapcore" 33 "go.uber.org/zap/zaptest/observer" 34 35 "github.com/stretchr/testify/assert" 36 "github.com/stretchr/testify/require" 37 "go.uber.org/atomic" 38) 39 40func TestReplaceGlobals(t *testing.T) { 41 initialL := *L() 42 initialS := *S() 43 44 withLogger(t, DebugLevel, nil, func(l *Logger, logs *observer.ObservedLogs) { 45 L().Info("no-op") 46 S().Info("no-op") 47 assert.Equal(t, 0, logs.Len(), "Expected initial logs to go to default no-op global.") 48 49 defer ReplaceGlobals(l)() 50 51 L().Info("captured") 52 S().Info("captured") 53 expected := observer.LoggedEntry{ 54 Entry: zapcore.Entry{Message: "captured"}, 55 Context: []Field{}, 56 } 57 assert.Equal( 58 t, 59 []observer.LoggedEntry{expected, expected}, 60 logs.AllUntimed(), 61 "Unexpected global log output.", 62 ) 63 }) 64 65 assert.Equal(t, initialL, *L(), "Expected func returned from ReplaceGlobals to restore initial L.") 66 assert.Equal(t, initialS, *S(), "Expected func returned from ReplaceGlobals to restore initial S.") 67} 68 69func TestGlobalsConcurrentUse(t *testing.T) { 70 var ( 71 stop atomic.Bool 72 wg sync.WaitGroup 73 ) 74 75 for i := 0; i < 100; i++ { 76 wg.Add(2) 77 go func() { 78 for !stop.Load() { 79 ReplaceGlobals(NewNop()) 80 } 81 wg.Done() 82 }() 83 go func() { 84 for !stop.Load() { 85 L().With(Int("foo", 42)).Named("main").WithOptions(Development()).Info("") 86 S().Info("") 87 } 88 wg.Done() 89 }() 90 } 91 92 ztest.Sleep(100 * time.Millisecond) 93 stop.Toggle() 94 wg.Wait() 95} 96 97func TestNewStdLog(t *testing.T) { 98 withLogger(t, DebugLevel, []Option{AddCaller()}, func(l *Logger, logs *observer.ObservedLogs) { 99 std := NewStdLog(l) 100 std.Print("redirected") 101 checkStdLogMessage(t, "redirected", logs) 102 }) 103} 104 105func TestNewStdLogAt(t *testing.T) { 106 // include DPanicLevel here, but do not include Development in options 107 levels := []zapcore.Level{DebugLevel, InfoLevel, WarnLevel, ErrorLevel, DPanicLevel} 108 for _, level := range levels { 109 withLogger(t, DebugLevel, []Option{AddCaller()}, func(l *Logger, logs *observer.ObservedLogs) { 110 std, err := NewStdLogAt(l, level) 111 require.NoError(t, err, "Unexpected error.") 112 std.Print("redirected") 113 checkStdLogMessage(t, "redirected", logs) 114 }) 115 } 116} 117 118func TestNewStdLogAtPanics(t *testing.T) { 119 // include DPanicLevel here and enable Development in options 120 levels := []zapcore.Level{DPanicLevel, PanicLevel} 121 for _, level := range levels { 122 withLogger(t, DebugLevel, []Option{AddCaller(), Development()}, func(l *Logger, logs *observer.ObservedLogs) { 123 std, err := NewStdLogAt(l, level) 124 require.NoError(t, err, "Unexpected error") 125 assert.Panics(t, func() { std.Print("redirected") }, "Expected log to panic.") 126 checkStdLogMessage(t, "redirected", logs) 127 }) 128 } 129} 130 131func TestNewStdLogAtFatal(t *testing.T) { 132 withLogger(t, DebugLevel, []Option{AddCaller()}, func(l *Logger, logs *observer.ObservedLogs) { 133 stub := exit.WithStub(func() { 134 std, err := NewStdLogAt(l, FatalLevel) 135 require.NoError(t, err, "Unexpected error.") 136 std.Print("redirected") 137 checkStdLogMessage(t, "redirected", logs) 138 }) 139 assert.True(t, true, stub.Exited, "Expected Fatal logger call to terminate process.") 140 stub.Unstub() 141 }) 142} 143 144func TestNewStdLogAtInvalid(t *testing.T) { 145 _, err := NewStdLogAt(NewNop(), zapcore.Level(99)) 146 assert.Error(t, err, "Expected to get error.") 147 assert.Contains(t, err.Error(), "99", "Expected level code in error message") 148} 149 150func TestRedirectStdLog(t *testing.T) { 151 initialFlags := log.Flags() 152 initialPrefix := log.Prefix() 153 154 withLogger(t, DebugLevel, nil, func(l *Logger, logs *observer.ObservedLogs) { 155 defer RedirectStdLog(l)() 156 log.Print("redirected") 157 158 assert.Equal(t, []observer.LoggedEntry{{ 159 Entry: zapcore.Entry{Message: "redirected"}, 160 Context: []Field{}, 161 }}, logs.AllUntimed(), "Unexpected global log output.") 162 }) 163 164 assert.Equal(t, initialFlags, log.Flags(), "Expected to reset initial flags.") 165 assert.Equal(t, initialPrefix, log.Prefix(), "Expected to reset initial prefix.") 166} 167 168func TestRedirectStdLogCaller(t *testing.T) { 169 withLogger(t, DebugLevel, []Option{AddCaller()}, func(l *Logger, logs *observer.ObservedLogs) { 170 defer RedirectStdLog(l)() 171 log.Print("redirected") 172 entries := logs.All() 173 require.Len(t, entries, 1, "Unexpected number of logs.") 174 assert.Contains(t, entries[0].Entry.Caller.File, "global_test.go", "Unexpected caller annotation.") 175 }) 176} 177 178func TestRedirectStdLogAt(t *testing.T) { 179 initialFlags := log.Flags() 180 initialPrefix := log.Prefix() 181 182 // include DPanicLevel here, but do not include Development in options 183 levels := []zapcore.Level{DebugLevel, InfoLevel, WarnLevel, ErrorLevel, DPanicLevel} 184 for _, level := range levels { 185 withLogger(t, DebugLevel, nil, func(l *Logger, logs *observer.ObservedLogs) { 186 restore, err := RedirectStdLogAt(l, level) 187 require.NoError(t, err, "Unexpected error.") 188 defer restore() 189 log.Print("redirected") 190 191 assert.Equal(t, []observer.LoggedEntry{{ 192 Entry: zapcore.Entry{Level: level, Message: "redirected"}, 193 Context: []Field{}, 194 }}, logs.AllUntimed(), "Unexpected global log output.") 195 }) 196 } 197 198 assert.Equal(t, initialFlags, log.Flags(), "Expected to reset initial flags.") 199 assert.Equal(t, initialPrefix, log.Prefix(), "Expected to reset initial prefix.") 200} 201 202func TestRedirectStdLogAtCaller(t *testing.T) { 203 // include DPanicLevel here, but do not include Development in options 204 levels := []zapcore.Level{DebugLevel, InfoLevel, WarnLevel, ErrorLevel, DPanicLevel} 205 for _, level := range levels { 206 withLogger(t, DebugLevel, []Option{AddCaller()}, func(l *Logger, logs *observer.ObservedLogs) { 207 restore, err := RedirectStdLogAt(l, level) 208 require.NoError(t, err, "Unexpected error.") 209 defer restore() 210 log.Print("redirected") 211 entries := logs.All() 212 require.Len(t, entries, 1, "Unexpected number of logs.") 213 assert.Contains(t, entries[0].Entry.Caller.File, "global_test.go", "Unexpected caller annotation.") 214 }) 215 } 216} 217 218func TestRedirectStdLogAtPanics(t *testing.T) { 219 initialFlags := log.Flags() 220 initialPrefix := log.Prefix() 221 222 // include DPanicLevel here and enable Development in options 223 levels := []zapcore.Level{DPanicLevel, PanicLevel} 224 for _, level := range levels { 225 withLogger(t, DebugLevel, []Option{AddCaller(), Development()}, func(l *Logger, logs *observer.ObservedLogs) { 226 restore, err := RedirectStdLogAt(l, level) 227 require.NoError(t, err, "Unexpected error.") 228 defer restore() 229 assert.Panics(t, func() { log.Print("redirected") }, "Expected log to panic.") 230 checkStdLogMessage(t, "redirected", logs) 231 }) 232 } 233 234 assert.Equal(t, initialFlags, log.Flags(), "Expected to reset initial flags.") 235 assert.Equal(t, initialPrefix, log.Prefix(), "Expected to reset initial prefix.") 236} 237 238func TestRedirectStdLogAtFatal(t *testing.T) { 239 initialFlags := log.Flags() 240 initialPrefix := log.Prefix() 241 242 withLogger(t, DebugLevel, []Option{AddCaller()}, func(l *Logger, logs *observer.ObservedLogs) { 243 stub := exit.WithStub(func() { 244 restore, err := RedirectStdLogAt(l, FatalLevel) 245 require.NoError(t, err, "Unexpected error.") 246 defer restore() 247 log.Print("redirected") 248 checkStdLogMessage(t, "redirected", logs) 249 }) 250 assert.True(t, true, stub.Exited, "Expected Fatal logger call to terminate process.") 251 stub.Unstub() 252 }) 253 254 assert.Equal(t, initialFlags, log.Flags(), "Expected to reset initial flags.") 255 assert.Equal(t, initialPrefix, log.Prefix(), "Expected to reset initial prefix.") 256} 257 258func TestRedirectStdLogAtInvalid(t *testing.T) { 259 restore, err := RedirectStdLogAt(NewNop(), zapcore.Level(99)) 260 defer func() { 261 if restore != nil { 262 restore() 263 } 264 }() 265 require.Error(t, err, "Expected to get error.") 266 assert.Contains(t, err.Error(), "99", "Expected level code in error message") 267} 268 269func checkStdLogMessage(t *testing.T, msg string, logs *observer.ObservedLogs) { 270 require.Equal(t, 1, logs.Len(), "Expected exactly one entry to be logged") 271 entry := logs.AllUntimed()[0] 272 assert.Equal(t, []Field{}, entry.Context, "Unexpected entry context.") 273 assert.Equal(t, "redirected", entry.Entry.Message, "Unexpected entry message.") 274 assert.Regexp( 275 t, 276 `/global_test.go:\d+$`, 277 entry.Entry.Caller.String(), 278 "Unexpected caller annotation.", 279 ) 280} 281