logs_test.go 9.5 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458
  1. package logx
  2. import (
  3. "encoding/json"
  4. "errors"
  5. "fmt"
  6. "io"
  7. "io/ioutil"
  8. "log"
  9. "os"
  10. "runtime"
  11. "strings"
  12. "sync"
  13. "sync/atomic"
  14. "testing"
  15. "time"
  16. "github.com/stretchr/testify/assert"
  17. )
  18. var (
  19. s = []byte("Sending #11 notification (id: 1451875113812010473) in #1 connection")
  20. pool = make(chan []byte, 1)
  21. )
  22. type mockWriter struct {
  23. lock sync.Mutex
  24. builder strings.Builder
  25. }
  26. func (mw *mockWriter) Write(data []byte) (int, error) {
  27. mw.lock.Lock()
  28. defer mw.lock.Unlock()
  29. return mw.builder.Write(data)
  30. }
  31. func (mw *mockWriter) Close() error {
  32. return nil
  33. }
  34. func (mw *mockWriter) Contains(text string) bool {
  35. mw.lock.Lock()
  36. defer mw.lock.Unlock()
  37. return strings.Contains(mw.builder.String(), text)
  38. }
  39. func (mw *mockWriter) Reset() {
  40. mw.lock.Lock()
  41. defer mw.lock.Unlock()
  42. mw.builder.Reset()
  43. }
  44. func (mw *mockWriter) String() string {
  45. mw.lock.Lock()
  46. defer mw.lock.Unlock()
  47. return mw.builder.String()
  48. }
  49. func TestFileLineFileMode(t *testing.T) {
  50. writer := new(mockWriter)
  51. errorLog = writer
  52. atomic.StoreUint32(&initialized, 1)
  53. file, line := getFileLine()
  54. Error("anything")
  55. assert.True(t, writer.Contains(fmt.Sprintf("%s:%d", file, line+1)))
  56. writer.Reset()
  57. file, line = getFileLine()
  58. Errorf("anything %s", "format")
  59. assert.True(t, writer.Contains(fmt.Sprintf("%s:%d", file, line+1)))
  60. }
  61. func TestFileLineConsoleMode(t *testing.T) {
  62. writer := new(mockWriter)
  63. writeConsole = true
  64. errorLog = newLogWriter(log.New(writer, "[ERROR] ", flags))
  65. atomic.StoreUint32(&initialized, 1)
  66. file, line := getFileLine()
  67. Error("anything")
  68. assert.True(t, writer.Contains(fmt.Sprintf("%s:%d", file, line+1)))
  69. writer.Reset()
  70. file, line = getFileLine()
  71. Errorf("anything %s", "format")
  72. assert.True(t, writer.Contains(fmt.Sprintf("%s:%d", file, line+1)))
  73. }
  74. func TestStructedLogAlert(t *testing.T) {
  75. doTestStructedLog(t, levelAlert, func(writer io.WriteCloser) {
  76. errorLog = writer
  77. }, func(v ...interface{}) {
  78. Alert(fmt.Sprint(v...))
  79. })
  80. }
  81. func TestStructedLogError(t *testing.T) {
  82. doTestStructedLog(t, levelError, func(writer io.WriteCloser) {
  83. errorLog = writer
  84. }, func(v ...interface{}) {
  85. Error(v...)
  86. })
  87. }
  88. func TestStructedLogErrorf(t *testing.T) {
  89. doTestStructedLog(t, levelError, func(writer io.WriteCloser) {
  90. errorLog = writer
  91. }, func(v ...interface{}) {
  92. Errorf("%s", fmt.Sprint(v...))
  93. })
  94. }
  95. func TestStructedLogErrorv(t *testing.T) {
  96. doTestStructedLog(t, levelError, func(writer io.WriteCloser) {
  97. errorLog = writer
  98. }, func(v ...interface{}) {
  99. Errorv(fmt.Sprint(v...))
  100. })
  101. }
  102. func TestStructedLogInfo(t *testing.T) {
  103. doTestStructedLog(t, levelInfo, func(writer io.WriteCloser) {
  104. infoLog = writer
  105. }, func(v ...interface{}) {
  106. Info(v...)
  107. })
  108. }
  109. func TestStructedLogInfof(t *testing.T) {
  110. doTestStructedLog(t, levelInfo, func(writer io.WriteCloser) {
  111. infoLog = writer
  112. }, func(v ...interface{}) {
  113. Infof("%s", fmt.Sprint(v...))
  114. })
  115. }
  116. func TestStructedLogInfov(t *testing.T) {
  117. doTestStructedLog(t, levelInfo, func(writer io.WriteCloser) {
  118. infoLog = writer
  119. }, func(v ...interface{}) {
  120. Infov(fmt.Sprint(v...))
  121. })
  122. }
  123. func TestStructedLogSlow(t *testing.T) {
  124. doTestStructedLog(t, levelSlow, func(writer io.WriteCloser) {
  125. slowLog = writer
  126. }, func(v ...interface{}) {
  127. Slow(v...)
  128. })
  129. }
  130. func TestStructedLogSlowf(t *testing.T) {
  131. doTestStructedLog(t, levelSlow, func(writer io.WriteCloser) {
  132. slowLog = writer
  133. }, func(v ...interface{}) {
  134. Slowf(fmt.Sprint(v...))
  135. })
  136. }
  137. func TestStructedLogSlowv(t *testing.T) {
  138. doTestStructedLog(t, levelSlow, func(writer io.WriteCloser) {
  139. slowLog = writer
  140. }, func(v ...interface{}) {
  141. Slowv(fmt.Sprint(v...))
  142. })
  143. }
  144. func TestStructedLogStat(t *testing.T) {
  145. doTestStructedLog(t, levelStat, func(writer io.WriteCloser) {
  146. statLog = writer
  147. }, func(v ...interface{}) {
  148. Stat(v...)
  149. })
  150. }
  151. func TestStructedLogStatf(t *testing.T) {
  152. doTestStructedLog(t, levelStat, func(writer io.WriteCloser) {
  153. statLog = writer
  154. }, func(v ...interface{}) {
  155. Statf(fmt.Sprint(v...))
  156. })
  157. }
  158. func TestStructedLogSevere(t *testing.T) {
  159. doTestStructedLog(t, levelSevere, func(writer io.WriteCloser) {
  160. severeLog = writer
  161. }, func(v ...interface{}) {
  162. Severe(v...)
  163. })
  164. }
  165. func TestStructedLogSeveref(t *testing.T) {
  166. doTestStructedLog(t, levelSevere, func(writer io.WriteCloser) {
  167. severeLog = writer
  168. }, func(v ...interface{}) {
  169. Severef(fmt.Sprint(v...))
  170. })
  171. }
  172. func TestStructedLogWithDuration(t *testing.T) {
  173. const message = "hello there"
  174. writer := new(mockWriter)
  175. infoLog = writer
  176. atomic.StoreUint32(&initialized, 1)
  177. WithDuration(time.Second).Info(message)
  178. var entry logEntry
  179. if err := json.Unmarshal([]byte(writer.builder.String()), &entry); err != nil {
  180. t.Error(err)
  181. }
  182. assert.Equal(t, levelInfo, entry.Level)
  183. assert.Equal(t, message, entry.Content)
  184. assert.Equal(t, "1000.0ms", entry.Duration)
  185. }
  186. func TestSetLevel(t *testing.T) {
  187. SetLevel(ErrorLevel)
  188. const message = "hello there"
  189. writer := new(mockWriter)
  190. infoLog = writer
  191. atomic.StoreUint32(&initialized, 1)
  192. Info(message)
  193. assert.Equal(t, 0, writer.builder.Len())
  194. }
  195. func TestSetLevelTwiceWithMode(t *testing.T) {
  196. testModes := []string{
  197. "mode",
  198. "console",
  199. "volumn",
  200. }
  201. for _, mode := range testModes {
  202. testSetLevelTwiceWithMode(t, mode)
  203. }
  204. }
  205. func TestSetLevelWithDuration(t *testing.T) {
  206. SetLevel(ErrorLevel)
  207. const message = "hello there"
  208. writer := new(mockWriter)
  209. infoLog = writer
  210. atomic.StoreUint32(&initialized, 1)
  211. WithDuration(time.Second).Info(message)
  212. assert.Equal(t, 0, writer.builder.Len())
  213. }
  214. func TestErrorfWithWrappedError(t *testing.T) {
  215. SetLevel(ErrorLevel)
  216. const message = "there"
  217. writer := new(mockWriter)
  218. errorLog = writer
  219. atomic.StoreUint32(&initialized, 1)
  220. Errorf("hello %w", errors.New(message))
  221. assert.True(t, strings.Contains(writer.builder.String(), "hello there"))
  222. }
  223. func TestMustNil(t *testing.T) {
  224. Must(nil)
  225. }
  226. func TestSetup(t *testing.T) {
  227. MustSetup(LogConf{
  228. ServiceName: "any",
  229. Mode: "console",
  230. })
  231. MustSetup(LogConf{
  232. ServiceName: "any",
  233. Mode: "file",
  234. Path: os.TempDir(),
  235. })
  236. MustSetup(LogConf{
  237. ServiceName: "any",
  238. Mode: "volume",
  239. Path: os.TempDir(),
  240. })
  241. assert.NotNil(t, setupWithVolume(LogConf{}))
  242. assert.NotNil(t, setupWithFiles(LogConf{}))
  243. assert.Nil(t, setupWithFiles(LogConf{
  244. ServiceName: "any",
  245. Path: os.TempDir(),
  246. Compress: true,
  247. KeepDays: 1,
  248. }))
  249. setupLogLevel(LogConf{
  250. Level: levelInfo,
  251. })
  252. setupLogLevel(LogConf{
  253. Level: levelError,
  254. })
  255. setupLogLevel(LogConf{
  256. Level: levelSevere,
  257. })
  258. _, err := createOutput("")
  259. assert.NotNil(t, err)
  260. Disable()
  261. }
  262. func TestDisable(t *testing.T) {
  263. Disable()
  264. var opt logOptions
  265. WithKeepDays(1)(&opt)
  266. WithGzip()(&opt)
  267. assert.Nil(t, Close())
  268. writeConsole = false
  269. assert.Nil(t, Close())
  270. }
  271. func TestDisableStat(t *testing.T) {
  272. DisableStat()
  273. const message = "hello there"
  274. writer := new(mockWriter)
  275. statLog = writer
  276. atomic.StoreUint32(&initialized, 1)
  277. Stat(message)
  278. assert.Equal(t, 0, writer.builder.Len())
  279. }
  280. func TestWithGzip(t *testing.T) {
  281. fn := WithGzip()
  282. var opt logOptions
  283. fn(&opt)
  284. assert.True(t, opt.gzipEnabled)
  285. }
  286. func TestWithKeepDays(t *testing.T) {
  287. fn := WithKeepDays(1)
  288. var opt logOptions
  289. fn(&opt)
  290. assert.Equal(t, 1, opt.keepDays)
  291. }
  292. func BenchmarkCopyByteSliceAppend(b *testing.B) {
  293. for i := 0; i < b.N; i++ {
  294. var buf []byte
  295. buf = append(buf, getTimestamp()...)
  296. buf = append(buf, ' ')
  297. buf = append(buf, s...)
  298. _ = buf
  299. }
  300. }
  301. func BenchmarkCopyByteSliceAllocExactly(b *testing.B) {
  302. for i := 0; i < b.N; i++ {
  303. now := []byte(getTimestamp())
  304. buf := make([]byte, len(now)+1+len(s))
  305. n := copy(buf, now)
  306. buf[n] = ' '
  307. copy(buf[n+1:], s)
  308. }
  309. }
  310. func BenchmarkCopyByteSlice(b *testing.B) {
  311. var buf []byte
  312. for i := 0; i < b.N; i++ {
  313. buf = make([]byte, len(s))
  314. copy(buf, s)
  315. }
  316. fmt.Fprint(ioutil.Discard, buf)
  317. }
  318. func BenchmarkCopyOnWriteByteSlice(b *testing.B) {
  319. var buf []byte
  320. for i := 0; i < b.N; i++ {
  321. size := len(s)
  322. buf = s[:size:size]
  323. }
  324. fmt.Fprint(ioutil.Discard, buf)
  325. }
  326. func BenchmarkCacheByteSlice(b *testing.B) {
  327. for i := 0; i < b.N; i++ {
  328. dup := fetch()
  329. copy(dup, s)
  330. put(dup)
  331. }
  332. }
  333. func BenchmarkLogs(b *testing.B) {
  334. b.ReportAllocs()
  335. log.SetOutput(ioutil.Discard)
  336. for i := 0; i < b.N; i++ {
  337. Info(i)
  338. }
  339. }
  340. func fetch() []byte {
  341. select {
  342. case b := <-pool:
  343. return b
  344. default:
  345. }
  346. return make([]byte, 4096)
  347. }
  348. func getFileLine() (string, int) {
  349. _, file, line, _ := runtime.Caller(1)
  350. short := file
  351. for i := len(file) - 1; i > 0; i-- {
  352. if file[i] == '/' {
  353. short = file[i+1:]
  354. break
  355. }
  356. }
  357. return short, line
  358. }
  359. func put(b []byte) {
  360. select {
  361. case pool <- b:
  362. default:
  363. }
  364. }
  365. func doTestStructedLog(t *testing.T, level string, setup func(writer io.WriteCloser),
  366. write func(...interface{})) {
  367. const message = "hello there"
  368. writer := new(mockWriter)
  369. setup(writer)
  370. atomic.StoreUint32(&initialized, 1)
  371. write(message)
  372. var entry logEntry
  373. if err := json.Unmarshal([]byte(writer.builder.String()), &entry); err != nil {
  374. t.Error(err)
  375. }
  376. assert.Equal(t, level, entry.Level)
  377. val, ok := entry.Content.(string)
  378. assert.True(t, ok)
  379. assert.True(t, strings.Contains(val, message))
  380. }
  381. func testSetLevelTwiceWithMode(t *testing.T, mode string) {
  382. SetUp(LogConf{
  383. Mode: mode,
  384. Level: "error",
  385. Path: "/dev/null",
  386. })
  387. SetUp(LogConf{
  388. Mode: mode,
  389. Level: "info",
  390. Path: "/dev/null",
  391. })
  392. const message = "hello there"
  393. writer := new(mockWriter)
  394. infoLog = writer
  395. atomic.StoreUint32(&initialized, 1)
  396. Info(message)
  397. assert.Equal(t, 0, writer.builder.Len())
  398. Infof(message)
  399. assert.Equal(t, 0, writer.builder.Len())
  400. ErrorStack(message)
  401. assert.Equal(t, 0, writer.builder.Len())
  402. ErrorStackf(message)
  403. assert.Equal(t, 0, writer.builder.Len())
  404. }