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.

240 lines
5.9 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. return
  23. }
  24. func TestConnLogger(t *testing.T) {
  25. var written []byte
  26. protocol := "tcp"
  27. address := ":3099"
  28. l, err := net.Listen(protocol, address)
  29. if err != nil {
  30. t.Fatal(err)
  31. }
  32. defer l.Close()
  33. prefix := "TestPrefix "
  34. level := INFO
  35. flags := LstdFlags | LUTC | Lfuncname
  36. logger := NewConn()
  37. connLogger := logger.(*ConnLogger)
  38. 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))
  39. assert.Equal(t, flags, connLogger.Flags)
  40. assert.Equal(t, level, connLogger.Level)
  41. assert.Equal(t, level, logger.GetLevel())
  42. location, _ := time.LoadLocation("EST")
  43. date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location)
  44. dateString := date.UTC().Format("2006/01/02 15:04:05")
  45. event := Event{
  46. level: INFO,
  47. msg: "TEST MSG",
  48. caller: "CALLER",
  49. filename: "FULL/FILENAME",
  50. line: 1,
  51. time: date,
  52. }
  53. 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)
  54. var wg sync.WaitGroup
  55. wg.Add(2)
  56. go func() {
  57. defer wg.Done()
  58. listenReadAndClose(t, l, expected)
  59. }()
  60. go func() {
  61. defer wg.Done()
  62. err := logger.LogEvent(&event)
  63. assert.NoError(t, err)
  64. }()
  65. wg.Wait()
  66. written = written[:0]
  67. event.level = WARN
  68. 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)
  69. wg.Add(2)
  70. go func() {
  71. defer wg.Done()
  72. listenReadAndClose(t, l, expected)
  73. }()
  74. go func() {
  75. defer wg.Done()
  76. err := logger.LogEvent(&event)
  77. assert.NoError(t, err)
  78. }()
  79. wg.Wait()
  80. logger.Close()
  81. }
  82. func TestConnLoggerBadConfig(t *testing.T) {
  83. logger := NewConn()
  84. err := logger.Init("{")
  85. assert.Equal(t, "unexpected end of JSON input", err.Error())
  86. logger.Close()
  87. }
  88. func TestConnLoggerCloseBeforeSend(t *testing.T) {
  89. protocol := "tcp"
  90. address := ":3099"
  91. prefix := "TestPrefix "
  92. level := INFO
  93. flags := LstdFlags | LUTC | Lfuncname
  94. logger := NewConn()
  95. 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))
  96. logger.Close()
  97. }
  98. func TestConnLoggerFailConnect(t *testing.T) {
  99. protocol := "tcp"
  100. address := ":3099"
  101. prefix := "TestPrefix "
  102. level := INFO
  103. flags := LstdFlags | LUTC | Lfuncname
  104. logger := NewConn()
  105. 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))
  106. assert.Equal(t, level, logger.GetLevel())
  107. location, _ := time.LoadLocation("EST")
  108. date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location)
  109. //dateString := date.UTC().Format("2006/01/02 15:04:05")
  110. event := Event{
  111. level: INFO,
  112. msg: "TEST MSG",
  113. caller: "CALLER",
  114. filename: "FULL/FILENAME",
  115. line: 1,
  116. time: date,
  117. }
  118. err := logger.LogEvent(&event)
  119. assert.Error(t, err)
  120. logger.Close()
  121. }
  122. func TestConnLoggerClose(t *testing.T) {
  123. var written []byte
  124. protocol := "tcp"
  125. address := ":3099"
  126. l, err := net.Listen(protocol, address)
  127. if err != nil {
  128. t.Fatal(err)
  129. }
  130. defer l.Close()
  131. prefix := "TestPrefix "
  132. level := INFO
  133. flags := LstdFlags | LUTC | Lfuncname
  134. logger := NewConn()
  135. connLogger := logger.(*ConnLogger)
  136. 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))
  137. assert.Equal(t, flags, connLogger.Flags)
  138. assert.Equal(t, level, connLogger.Level)
  139. assert.Equal(t, level, logger.GetLevel())
  140. location, _ := time.LoadLocation("EST")
  141. date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location)
  142. dateString := date.UTC().Format("2006/01/02 15:04:05")
  143. event := Event{
  144. level: INFO,
  145. msg: "TEST MSG",
  146. caller: "CALLER",
  147. filename: "FULL/FILENAME",
  148. line: 1,
  149. time: date,
  150. }
  151. 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)
  152. var wg sync.WaitGroup
  153. wg.Add(2)
  154. go func() {
  155. defer wg.Done()
  156. err := logger.LogEvent(&event)
  157. assert.NoError(t, err)
  158. logger.Close()
  159. }()
  160. go func() {
  161. defer wg.Done()
  162. listenReadAndClose(t, l, expected)
  163. }()
  164. wg.Wait()
  165. logger = NewConn()
  166. connLogger = logger.(*ConnLogger)
  167. 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))
  168. assert.Equal(t, flags, connLogger.Flags)
  169. assert.Equal(t, level, connLogger.Level)
  170. assert.Equal(t, level, logger.GetLevel())
  171. written = written[:0]
  172. event.level = WARN
  173. 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)
  174. wg.Add(2)
  175. go func() {
  176. defer wg.Done()
  177. listenReadAndClose(t, l, expected)
  178. }()
  179. go func() {
  180. defer wg.Done()
  181. err := logger.LogEvent(&event)
  182. assert.NoError(t, err)
  183. logger.Close()
  184. }()
  185. wg.Wait()
  186. logger.Flush()
  187. logger.Close()
  188. }