You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

231 lines
5.8 KiB

Better logging (#6038) (#6095) * Panic don't fatal on create new logger Fixes #5854 Signed-off-by: Andrew Thornton <art27@cantab.net> * partial broken * Update the logging infrastrcture Signed-off-by: Andrew Thornton <art27@cantab.net> * Reset the skip levels for Fatal and Error Signed-off-by: Andrew Thornton <art27@cantab.net> * broken ncsa * More log.Error fixes Signed-off-by: Andrew Thornton <art27@cantab.net> * Remove nal * set log-levels to lowercase * Make console_test test all levels * switch to lowercased levels * OK now working * Fix vetting issues * Fix lint * Fix tests * change default logging to match current gitea * Improve log testing Signed-off-by: Andrew Thornton <art27@cantab.net> * reset error skip levels to 0 * Update documentation and access logger configuration * Redirect the router log back to gitea if redirect macaron log but also allow setting the log level - i.e. TRACE * Fix broken level caching * Refactor the router log * Add Router logger * Add colorizing options * Adjust router colors * Only create logger if they will be used * update app.ini.sample * rename Attribute ColorAttribute * Change from white to green for function * Set fatal/error levels * Restore initial trace logger * Fix Trace arguments in modules/auth/auth.go * Properly handle XORMLogger * Improve admin/config page * fix fmt * Add auto-compression of old logs * Update error log levels * Remove the unnecessary skip argument from Error, Fatal and Critical * Add stacktrace support * Fix tests * Remove x/sync from vendors? * Add stderr option to console logger * Use filepath.ToSlash to protect against Windows in tests * Remove prefixed underscores from names in colors.go * Remove not implemented database logger This was removed from Gogs on 4 Mar 2016 but left in the configuration since then. * Ensure that log paths are relative to ROOT_PATH * use path.Join * rename jsonConfig to logConfig * Rename "config" to "jsonConfig" to make it clearer * Requested changes * Requested changes: XormLogger * Try to color the windows terminal If successful default to colorizing the console logs * fixup * Colorize initially too * update vendor * Colorize logs on default and remove if this is not a colorizing logger * Fix documentation * fix test * Use go-isatty to detect if on windows we are on msys or cygwin * Fix spelling mistake * Add missing vendors * More changes * Rationalise the ANSI writer protection * Adjust colors on advice from @0x5c * Make Flags a comma separated list * Move to use the windows constant for ENABLE_VIRTUAL_TERMINAL_PROCESSING * Ensure matching is done on the non-colored message - to simpify EXPRESSION
5 years ago
  1. // Copyright 2019 The Gitea Authors. All rights reserved.
  2. // Use of this source code is governed by a MIT-style
  3. // license that can be found in the LICENSE file.
  4. package log
  5. import (
  6. "fmt"
  7. "io/ioutil"
  8. "net"
  9. "strings"
  10. "sync"
  11. "testing"
  12. "time"
  13. "github.com/stretchr/testify/assert"
  14. )
  15. func listenReadAndClose(t *testing.T, l net.Listener, expected string) {
  16. conn, err := l.Accept()
  17. assert.NoError(t, err)
  18. defer conn.Close()
  19. written, err := ioutil.ReadAll(conn)
  20. assert.NoError(t, err)
  21. assert.Equal(t, expected, string(written))
  22. }
  23. func TestConnLogger(t *testing.T) {
  24. protocol := "tcp"
  25. address := ":3099"
  26. l, err := net.Listen(protocol, address)
  27. if err != nil {
  28. t.Fatal(err)
  29. }
  30. defer l.Close()
  31. prefix := "TestPrefix "
  32. level := INFO
  33. flags := LstdFlags | LUTC | Lfuncname
  34. logger := NewConn()
  35. connLogger := logger.(*ConnLogger)
  36. logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, true, true, protocol, address))
  37. assert.Equal(t, flags, connLogger.Flags)
  38. assert.Equal(t, level, connLogger.Level)
  39. assert.Equal(t, level, logger.GetLevel())
  40. location, _ := time.LoadLocation("EST")
  41. date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location)
  42. dateString := date.UTC().Format("2006/01/02 15:04:05")
  43. event := Event{
  44. level: INFO,
  45. msg: "TEST MSG",
  46. caller: "CALLER",
  47. filename: "FULL/FILENAME",
  48. line: 1,
  49. time: date,
  50. }
  51. expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg)
  52. var wg sync.WaitGroup
  53. wg.Add(2)
  54. go func() {
  55. defer wg.Done()
  56. listenReadAndClose(t, l, expected)
  57. }()
  58. go func() {
  59. defer wg.Done()
  60. err := logger.LogEvent(&event)
  61. assert.NoError(t, err)
  62. }()
  63. wg.Wait()
  64. event.level = WARN
  65. expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg)
  66. wg.Add(2)
  67. go func() {
  68. defer wg.Done()
  69. listenReadAndClose(t, l, expected)
  70. }()
  71. go func() {
  72. defer wg.Done()
  73. err := logger.LogEvent(&event)
  74. assert.NoError(t, err)
  75. }()
  76. wg.Wait()
  77. logger.Close()
  78. }
  79. func TestConnLoggerBadConfig(t *testing.T) {
  80. logger := NewConn()
  81. err := logger.Init("{")
  82. assert.Equal(t, "unexpected end of JSON input", err.Error())
  83. logger.Close()
  84. }
  85. func TestConnLoggerCloseBeforeSend(t *testing.T) {
  86. protocol := "tcp"
  87. address := ":3099"
  88. prefix := "TestPrefix "
  89. level := INFO
  90. flags := LstdFlags | LUTC | Lfuncname
  91. logger := NewConn()
  92. logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, false, false, protocol, address))
  93. logger.Close()
  94. }
  95. func TestConnLoggerFailConnect(t *testing.T) {
  96. protocol := "tcp"
  97. address := ":3099"
  98. prefix := "TestPrefix "
  99. level := INFO
  100. flags := LstdFlags | LUTC | Lfuncname
  101. logger := NewConn()
  102. logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, false, false, protocol, address))
  103. assert.Equal(t, level, logger.GetLevel())
  104. location, _ := time.LoadLocation("EST")
  105. date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location)
  106. //dateString := date.UTC().Format("2006/01/02 15:04:05")
  107. event := Event{
  108. level: INFO,
  109. msg: "TEST MSG",
  110. caller: "CALLER",
  111. filename: "FULL/FILENAME",
  112. line: 1,
  113. time: date,
  114. }
  115. err := logger.LogEvent(&event)
  116. assert.Error(t, err)
  117. logger.Close()
  118. }
  119. func TestConnLoggerClose(t *testing.T) {
  120. protocol := "tcp"
  121. address := ":3099"
  122. l, err := net.Listen(protocol, address)
  123. if err != nil {
  124. t.Fatal(err)
  125. }
  126. defer l.Close()
  127. prefix := "TestPrefix "
  128. level := INFO
  129. flags := LstdFlags | LUTC | Lfuncname
  130. logger := NewConn()
  131. connLogger := logger.(*ConnLogger)
  132. logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, false, false, protocol, address))
  133. assert.Equal(t, flags, connLogger.Flags)
  134. assert.Equal(t, level, connLogger.Level)
  135. assert.Equal(t, level, logger.GetLevel())
  136. location, _ := time.LoadLocation("EST")
  137. date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location)
  138. dateString := date.UTC().Format("2006/01/02 15:04:05")
  139. event := Event{
  140. level: INFO,
  141. msg: "TEST MSG",
  142. caller: "CALLER",
  143. filename: "FULL/FILENAME",
  144. line: 1,
  145. time: date,
  146. }
  147. expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg)
  148. var wg sync.WaitGroup
  149. wg.Add(2)
  150. go func() {
  151. defer wg.Done()
  152. err := logger.LogEvent(&event)
  153. assert.NoError(t, err)
  154. logger.Close()
  155. }()
  156. go func() {
  157. defer wg.Done()
  158. listenReadAndClose(t, l, expected)
  159. }()
  160. wg.Wait()
  161. logger = NewConn()
  162. connLogger = logger.(*ConnLogger)
  163. logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, false, true, protocol, address))
  164. assert.Equal(t, flags, connLogger.Flags)
  165. assert.Equal(t, level, connLogger.Level)
  166. assert.Equal(t, level, logger.GetLevel())
  167. event.level = WARN
  168. expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg)
  169. wg.Add(2)
  170. go func() {
  171. defer wg.Done()
  172. listenReadAndClose(t, l, expected)
  173. }()
  174. go func() {
  175. defer wg.Done()
  176. err := logger.LogEvent(&event)
  177. assert.NoError(t, err)
  178. logger.Close()
  179. }()
  180. wg.Wait()
  181. logger.Flush()
  182. logger.Close()
  183. }