global_test.go 9.1 KB

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