1
0

logger.go 8.8 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369
  1. // Copyright (C) 2014 Jakob Borg. All rights reserved. Use of this source code
  2. // is governed by an MIT-style license that can be found in the LICENSE file.
  3. // Package logger implements a standardized logger with callback functionality
  4. package logger
  5. import (
  6. "fmt"
  7. "io/ioutil"
  8. "log"
  9. "os"
  10. "strings"
  11. "sync"
  12. "time"
  13. )
  14. // This package uses stdlib sync as it may be used to debug syncthing/lib/sync
  15. // and that would cause an implosion of the universe.
  16. type LogLevel int
  17. const (
  18. LevelDebug LogLevel = iota
  19. LevelVerbose
  20. LevelInfo
  21. LevelWarn
  22. LevelFatal
  23. NumLevels
  24. )
  25. // A MessageHandler is called with the log level and message text.
  26. type MessageHandler func(l LogLevel, msg string)
  27. type Logger interface {
  28. AddHandler(level LogLevel, h MessageHandler)
  29. SetFlags(flag int)
  30. SetPrefix(prefix string)
  31. Debugln(vals ...interface{})
  32. Debugf(format string, vals ...interface{})
  33. Verboseln(vals ...interface{})
  34. Verbosef(format string, vals ...interface{})
  35. Infoln(vals ...interface{})
  36. Infof(format string, vals ...interface{})
  37. Warnln(vals ...interface{})
  38. Warnf(format string, vals ...interface{})
  39. Fatalln(vals ...interface{})
  40. Fatalf(format string, vals ...interface{})
  41. ShouldDebug(facility string) bool
  42. SetDebug(facility string, enabled bool)
  43. Facilities() map[string]string
  44. FacilityDebugging() []string
  45. NewFacility(facility, description string) Logger
  46. }
  47. type logger struct {
  48. logger *log.Logger
  49. handlers [NumLevels][]MessageHandler
  50. facilities map[string]string // facility name => description
  51. debug map[string]bool // facility name => debugging enabled
  52. mut sync.Mutex
  53. }
  54. // DefaultLogger logs to standard output with a time prefix.
  55. var DefaultLogger = New()
  56. func New() Logger {
  57. if os.Getenv("LOGGER_DISCARD") != "" {
  58. // Hack to completely disable logging, for example when running benchmarks.
  59. return &logger{
  60. logger: log.New(ioutil.Discard, "", 0),
  61. }
  62. }
  63. return &logger{
  64. logger: log.New(os.Stdout, "", log.Ltime),
  65. }
  66. }
  67. // AddHandler registers a new MessageHandler to receive messages with the
  68. // specified log level or above.
  69. func (l *logger) AddHandler(level LogLevel, h MessageHandler) {
  70. l.mut.Lock()
  71. defer l.mut.Unlock()
  72. l.handlers[level] = append(l.handlers[level], h)
  73. }
  74. // See log.SetFlags
  75. func (l *logger) SetFlags(flag int) {
  76. l.logger.SetFlags(flag)
  77. }
  78. // See log.SetPrefix
  79. func (l *logger) SetPrefix(prefix string) {
  80. l.logger.SetPrefix(prefix)
  81. }
  82. func (l *logger) callHandlers(level LogLevel, s string) {
  83. for ll := LevelDebug; ll <= level; ll++ {
  84. for _, h := range l.handlers[ll] {
  85. h(level, strings.TrimSpace(s))
  86. }
  87. }
  88. }
  89. // Debugln logs a line with a DEBUG prefix.
  90. func (l *logger) Debugln(vals ...interface{}) {
  91. l.debugln(3, vals)
  92. }
  93. func (l *logger) debugln(level int, vals ...interface{}) {
  94. l.mut.Lock()
  95. defer l.mut.Unlock()
  96. s := fmt.Sprintln(vals...)
  97. l.logger.Output(level, "DEBUG: "+s)
  98. l.callHandlers(LevelDebug, s)
  99. }
  100. // Debugf logs a formatted line with a DEBUG prefix.
  101. func (l *logger) Debugf(format string, vals ...interface{}) {
  102. l.debugf(3, format, vals...)
  103. }
  104. func (l *logger) debugf(level int, format string, vals ...interface{}) {
  105. l.mut.Lock()
  106. defer l.mut.Unlock()
  107. s := fmt.Sprintf(format, vals...)
  108. l.logger.Output(level, "DEBUG: "+s)
  109. l.callHandlers(LevelDebug, s)
  110. }
  111. // Infoln logs a line with a VERBOSE prefix.
  112. func (l *logger) Verboseln(vals ...interface{}) {
  113. l.mut.Lock()
  114. defer l.mut.Unlock()
  115. s := fmt.Sprintln(vals...)
  116. l.logger.Output(2, "VERBOSE: "+s)
  117. l.callHandlers(LevelVerbose, s)
  118. }
  119. // Infof logs a formatted line with a VERBOSE prefix.
  120. func (l *logger) Verbosef(format string, vals ...interface{}) {
  121. l.mut.Lock()
  122. defer l.mut.Unlock()
  123. s := fmt.Sprintf(format, vals...)
  124. l.logger.Output(2, "VERBOSE: "+s)
  125. l.callHandlers(LevelVerbose, s)
  126. }
  127. // Infoln logs a line with an INFO prefix.
  128. func (l *logger) Infoln(vals ...interface{}) {
  129. l.mut.Lock()
  130. defer l.mut.Unlock()
  131. s := fmt.Sprintln(vals...)
  132. l.logger.Output(2, "INFO: "+s)
  133. l.callHandlers(LevelInfo, s)
  134. }
  135. // Infof logs a formatted line with an INFO prefix.
  136. func (l *logger) Infof(format string, vals ...interface{}) {
  137. l.mut.Lock()
  138. defer l.mut.Unlock()
  139. s := fmt.Sprintf(format, vals...)
  140. l.logger.Output(2, "INFO: "+s)
  141. l.callHandlers(LevelInfo, s)
  142. }
  143. // Warnln logs a formatted line with a WARNING prefix.
  144. func (l *logger) Warnln(vals ...interface{}) {
  145. l.mut.Lock()
  146. defer l.mut.Unlock()
  147. s := fmt.Sprintln(vals...)
  148. l.logger.Output(2, "WARNING: "+s)
  149. l.callHandlers(LevelWarn, s)
  150. }
  151. // Warnf logs a formatted line with a WARNING prefix.
  152. func (l *logger) Warnf(format string, vals ...interface{}) {
  153. l.mut.Lock()
  154. defer l.mut.Unlock()
  155. s := fmt.Sprintf(format, vals...)
  156. l.logger.Output(2, "WARNING: "+s)
  157. l.callHandlers(LevelWarn, s)
  158. }
  159. // Fatalln logs a line with a FATAL prefix and exits the process with exit
  160. // code 1.
  161. func (l *logger) Fatalln(vals ...interface{}) {
  162. l.mut.Lock()
  163. defer l.mut.Unlock()
  164. s := fmt.Sprintln(vals...)
  165. l.logger.Output(2, "FATAL: "+s)
  166. l.callHandlers(LevelFatal, s)
  167. os.Exit(1)
  168. }
  169. // Fatalf logs a formatted line with a FATAL prefix and exits the process with
  170. // exit code 1.
  171. func (l *logger) Fatalf(format string, vals ...interface{}) {
  172. l.mut.Lock()
  173. defer l.mut.Unlock()
  174. s := fmt.Sprintf(format, vals...)
  175. l.logger.Output(2, "FATAL: "+s)
  176. l.callHandlers(LevelFatal, s)
  177. os.Exit(1)
  178. }
  179. // ShouldDebug returns true if the given facility has debugging enabled.
  180. func (l *logger) ShouldDebug(facility string) bool {
  181. l.mut.Lock()
  182. res := l.debug[facility]
  183. l.mut.Unlock()
  184. return res
  185. }
  186. // SetDebug enabled or disables debugging for the given facility name.
  187. func (l *logger) SetDebug(facility string, enabled bool) {
  188. l.mut.Lock()
  189. l.debug[facility] = enabled
  190. l.mut.Unlock()
  191. }
  192. // FacilityDebugging returns the set of facilities that have debugging
  193. // enabled.
  194. func (l *logger) FacilityDebugging() []string {
  195. var enabled []string
  196. l.mut.Lock()
  197. for facility, isEnabled := range l.debug {
  198. if isEnabled {
  199. enabled = append(enabled, facility)
  200. }
  201. }
  202. l.mut.Unlock()
  203. return enabled
  204. }
  205. // Facilities returns the currently known set of facilities and their
  206. // descriptions.
  207. func (l *logger) Facilities() map[string]string {
  208. l.mut.Lock()
  209. res := make(map[string]string, len(l.facilities))
  210. for facility, descr := range l.facilities {
  211. res[facility] = descr
  212. }
  213. l.mut.Unlock()
  214. return res
  215. }
  216. // NewFacility returns a new logger bound to the named facility.
  217. func (l *logger) NewFacility(facility, description string) Logger {
  218. l.mut.Lock()
  219. if l.facilities == nil {
  220. l.facilities = make(map[string]string)
  221. }
  222. if description != "" {
  223. l.facilities[facility] = description
  224. }
  225. if l.debug == nil {
  226. l.debug = make(map[string]bool)
  227. }
  228. l.debug[facility] = false
  229. l.mut.Unlock()
  230. return &facilityLogger{
  231. logger: l,
  232. facility: facility,
  233. }
  234. }
  235. // A facilityLogger is a regular logger but bound to a facility name. The
  236. // Debugln and Debugf methods are no-ops unless debugging has been enabled for
  237. // this facility on the parent logger.
  238. type facilityLogger struct {
  239. *logger
  240. facility string
  241. }
  242. // Debugln logs a line with a DEBUG prefix.
  243. func (l *facilityLogger) Debugln(vals ...interface{}) {
  244. if !l.ShouldDebug(l.facility) {
  245. return
  246. }
  247. l.logger.debugln(3, vals...)
  248. }
  249. // Debugf logs a formatted line with a DEBUG prefix.
  250. func (l *facilityLogger) Debugf(format string, vals ...interface{}) {
  251. if !l.ShouldDebug(l.facility) {
  252. return
  253. }
  254. l.logger.debugf(3, format, vals...)
  255. }
  256. // A Recorder keeps a size limited record of log events.
  257. type Recorder interface {
  258. Since(t time.Time) []Line
  259. Clear()
  260. }
  261. type recorder struct {
  262. lines []Line
  263. initial int
  264. mut sync.Mutex
  265. }
  266. // A Line represents a single log entry.
  267. type Line struct {
  268. When time.Time `json:"when"`
  269. Message string `json:"message"`
  270. }
  271. func NewRecorder(l Logger, level LogLevel, size, initial int) Recorder {
  272. r := &recorder{
  273. lines: make([]Line, 0, size),
  274. initial: initial,
  275. }
  276. l.AddHandler(level, r.append)
  277. return r
  278. }
  279. func (r *recorder) Since(t time.Time) []Line {
  280. r.mut.Lock()
  281. defer r.mut.Unlock()
  282. res := r.lines
  283. for i := 0; i < len(res) && res[i].When.Before(t); i++ {
  284. // nothing, just incrementing i
  285. }
  286. if len(res) == 0 {
  287. return nil
  288. }
  289. // We must copy the result as r.lines can be mutated as soon as the lock
  290. // is released.
  291. cp := make([]Line, len(res))
  292. copy(cp, res)
  293. return cp
  294. }
  295. func (r *recorder) Clear() {
  296. r.mut.Lock()
  297. r.lines = r.lines[:0]
  298. r.mut.Unlock()
  299. }
  300. func (r *recorder) append(l LogLevel, msg string) {
  301. line := Line{
  302. When: time.Now(),
  303. Message: msg,
  304. }
  305. r.mut.Lock()
  306. defer r.mut.Unlock()
  307. if len(r.lines) == cap(r.lines) {
  308. if r.initial > 0 {
  309. // Shift all lines one step to the left, keeping the "initial" first intact.
  310. copy(r.lines[r.initial+1:], r.lines[r.initial+2:])
  311. } else {
  312. copy(r.lines, r.lines[1:])
  313. }
  314. // Add the new one at the end
  315. r.lines[len(r.lines)-1] = line
  316. return
  317. }
  318. r.lines = append(r.lines, line)
  319. if len(r.lines) == r.initial {
  320. r.lines = append(r.lines, Line{time.Now(), "..."})
  321. }
  322. }