logs_test.go 9.2 KB

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