123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408 |
- // Copyright (C) 2014 Jakob Borg. All rights reserved. Use of this source code
- // is governed by an MIT-style license that can be found in the LICENSE file.
- //go:generate -command counterfeiter go run github.com/maxbrunsfeld/counterfeiter/v6
- //go:generate counterfeiter -o mocks/logger.go --fake-name Recorder . Recorder
- // Package logger implements a standardized logger with callback functionality
- package logger
- import (
- "fmt"
- "io"
- "log"
- "os"
- "slices"
- "strings"
- "sync"
- "time"
- )
- // This package uses stdlib sync as it may be used to debug syncthing/lib/sync
- // and that would cause an implosion of the universe.
- type LogLevel int
- const (
- LevelDebug LogLevel = iota
- LevelVerbose
- LevelInfo
- LevelWarn
- NumLevels
- )
- const (
- DefaultFlags = log.Ltime | log.Ldate
- DebugFlags = log.Ltime | log.Ldate | log.Lmicroseconds | log.Lshortfile
- )
- // A MessageHandler is called with the log level and message text.
- type MessageHandler func(l LogLevel, msg string)
- type Logger interface {
- AddHandler(level LogLevel, h MessageHandler)
- SetFlags(flag int)
- SetPrefix(prefix string)
- Debugln(vals ...interface{})
- Debugf(format string, vals ...interface{})
- Verboseln(vals ...interface{})
- Verbosef(format string, vals ...interface{})
- Infoln(vals ...interface{})
- Infof(format string, vals ...interface{})
- Warnln(vals ...interface{})
- Warnf(format string, vals ...interface{})
- ShouldDebug(facility string) bool
- SetDebug(facility string, enabled bool)
- Facilities() map[string]string
- FacilityDebugging() []string
- NewFacility(facility, description string) Logger
- }
- type logger struct {
- logger *log.Logger
- handlers [NumLevels][]MessageHandler
- facilities map[string]string // facility name => description
- debug map[string]struct{} // only facility names with debugging enabled
- traces []string
- mut sync.Mutex
- }
- // DefaultLogger logs to standard output with a time prefix.
- var DefaultLogger = New()
- func New() Logger {
- if os.Getenv("LOGGER_DISCARD") != "" {
- // Hack to completely disable logging, for example when running
- // benchmarks.
- return newLogger(io.Discard)
- }
- return newLogger(controlStripper{os.Stdout})
- }
- func newLogger(w io.Writer) Logger {
- traces := strings.FieldsFunc(os.Getenv("STTRACE"), func(r rune) bool {
- return strings.ContainsRune(",; ", r)
- })
- if len(traces) > 0 {
- if slices.Contains(traces, "all") {
- traces = []string{"all"}
- } else {
- slices.Sort(traces)
- }
- }
- return &logger{
- logger: log.New(w, "", DefaultFlags),
- traces: traces,
- facilities: make(map[string]string),
- debug: make(map[string]struct{}),
- }
- }
- // AddHandler registers a new MessageHandler to receive messages with the
- // specified log level or above.
- func (l *logger) AddHandler(level LogLevel, h MessageHandler) {
- l.mut.Lock()
- defer l.mut.Unlock()
- l.handlers[level] = append(l.handlers[level], h)
- }
- // See log.SetFlags
- func (l *logger) SetFlags(flag int) {
- l.logger.SetFlags(flag)
- }
- // See log.SetPrefix
- func (l *logger) SetPrefix(prefix string) {
- l.logger.SetPrefix(prefix)
- }
- func (l *logger) callHandlers(level LogLevel, s string) {
- for ll := LevelDebug; ll <= level; ll++ {
- for _, h := range l.handlers[ll] {
- h(level, strings.TrimSpace(s))
- }
- }
- }
- // Debugln logs a line with a DEBUG prefix.
- func (l *logger) Debugln(vals ...interface{}) {
- l.debugln(3, vals...)
- }
- func (l *logger) debugln(level int, vals ...interface{}) {
- s := fmt.Sprintln(vals...)
- l.mut.Lock()
- defer l.mut.Unlock()
- l.logger.Output(level, "DEBUG: "+s)
- l.callHandlers(LevelDebug, s)
- }
- // Debugf logs a formatted line with a DEBUG prefix.
- func (l *logger) Debugf(format string, vals ...interface{}) {
- l.debugf(3, format, vals...)
- }
- func (l *logger) debugf(level int, format string, vals ...interface{}) {
- s := fmt.Sprintf(format, vals...)
- l.mut.Lock()
- defer l.mut.Unlock()
- l.logger.Output(level, "DEBUG: "+s)
- l.callHandlers(LevelDebug, s)
- }
- // Infoln logs a line with a VERBOSE prefix.
- func (l *logger) Verboseln(vals ...interface{}) {
- s := fmt.Sprintln(vals...)
- l.mut.Lock()
- defer l.mut.Unlock()
- l.logger.Output(2, "VERBOSE: "+s)
- l.callHandlers(LevelVerbose, s)
- }
- // Infof logs a formatted line with a VERBOSE prefix.
- func (l *logger) Verbosef(format string, vals ...interface{}) {
- s := fmt.Sprintf(format, vals...)
- l.mut.Lock()
- defer l.mut.Unlock()
- l.logger.Output(2, "VERBOSE: "+s)
- l.callHandlers(LevelVerbose, s)
- }
- // Infoln logs a line with an INFO prefix.
- func (l *logger) Infoln(vals ...interface{}) {
- s := fmt.Sprintln(vals...)
- l.mut.Lock()
- defer l.mut.Unlock()
- l.logger.Output(2, "INFO: "+s)
- l.callHandlers(LevelInfo, s)
- }
- // Infof logs a formatted line with an INFO prefix.
- func (l *logger) Infof(format string, vals ...interface{}) {
- s := fmt.Sprintf(format, vals...)
- l.mut.Lock()
- defer l.mut.Unlock()
- l.logger.Output(2, "INFO: "+s)
- l.callHandlers(LevelInfo, s)
- }
- // Warnln logs a formatted line with a WARNING prefix.
- func (l *logger) Warnln(vals ...interface{}) {
- s := fmt.Sprintln(vals...)
- l.mut.Lock()
- defer l.mut.Unlock()
- l.logger.Output(2, "WARNING: "+s)
- l.callHandlers(LevelWarn, s)
- }
- // Warnf logs a formatted line with a WARNING prefix.
- func (l *logger) Warnf(format string, vals ...interface{}) {
- s := fmt.Sprintf(format, vals...)
- l.mut.Lock()
- defer l.mut.Unlock()
- l.logger.Output(2, "WARNING: "+s)
- l.callHandlers(LevelWarn, s)
- }
- // ShouldDebug returns true if the given facility has debugging enabled.
- func (l *logger) ShouldDebug(facility string) bool {
- l.mut.Lock()
- _, res := l.debug[facility]
- l.mut.Unlock()
- return res
- }
- // SetDebug enabled or disables debugging for the given facility name.
- func (l *logger) SetDebug(facility string, enabled bool) {
- l.mut.Lock()
- defer l.mut.Unlock()
- if _, ok := l.debug[facility]; enabled && !ok {
- l.SetFlags(DebugFlags)
- l.debug[facility] = struct{}{}
- } else if !enabled && ok {
- delete(l.debug, facility)
- if len(l.debug) == 0 {
- l.SetFlags(DefaultFlags)
- }
- }
- }
- // isTraced returns whether the facility name is contained in STTRACE.
- func (l *logger) isTraced(facility string) bool {
- if len(l.traces) > 0 {
- if l.traces[0] == "all" {
- return true
- }
- _, found := slices.BinarySearch(l.traces, facility)
- return found
- }
- return false
- }
- // FacilityDebugging returns the set of facilities that have debugging
- // enabled.
- func (l *logger) FacilityDebugging() []string {
- enabled := make([]string, 0, len(l.debug))
- l.mut.Lock()
- for facility := range l.debug {
- enabled = append(enabled, facility)
- }
- l.mut.Unlock()
- return enabled
- }
- // Facilities returns the currently known set of facilities and their
- // descriptions.
- func (l *logger) Facilities() map[string]string {
- l.mut.Lock()
- res := make(map[string]string, len(l.facilities))
- for facility, descr := range l.facilities {
- res[facility] = descr
- }
- l.mut.Unlock()
- return res
- }
- // NewFacility returns a new logger bound to the named facility.
- func (l *logger) NewFacility(facility, description string) Logger {
- l.SetDebug(facility, l.isTraced(facility))
- l.mut.Lock()
- l.facilities[facility] = description
- l.mut.Unlock()
- return &facilityLogger{
- logger: l,
- facility: facility,
- }
- }
- // A facilityLogger is a regular logger but bound to a facility name. The
- // Debugln and Debugf methods are no-ops unless debugging has been enabled for
- // this facility on the parent logger.
- type facilityLogger struct {
- *logger
- facility string
- }
- // Debugln logs a line with a DEBUG prefix.
- func (l *facilityLogger) Debugln(vals ...interface{}) {
- if !l.ShouldDebug(l.facility) {
- return
- }
- l.logger.debugln(3, vals...)
- }
- // Debugf logs a formatted line with a DEBUG prefix.
- func (l *facilityLogger) Debugf(format string, vals ...interface{}) {
- if !l.ShouldDebug(l.facility) {
- return
- }
- l.logger.debugf(3, format, vals...)
- }
- // A Recorder keeps a size limited record of log events.
- type Recorder interface {
- Since(t time.Time) []Line
- Clear()
- }
- type recorder struct {
- lines []Line
- initial int
- mut sync.Mutex
- }
- // A Line represents a single log entry.
- type Line struct {
- When time.Time `json:"when"`
- Message string `json:"message"`
- Level LogLevel `json:"level"`
- }
- func NewRecorder(l Logger, level LogLevel, size, initial int) Recorder {
- r := &recorder{
- lines: make([]Line, 0, size),
- initial: initial,
- }
- l.AddHandler(level, r.append)
- return r
- }
- func (r *recorder) Since(t time.Time) []Line {
- r.mut.Lock()
- defer r.mut.Unlock()
- res := r.lines
- for i := 0; i < len(res); i++ {
- if res[i].When.After(t) {
- // We must copy the result as r.lines can be mutated as soon as the lock
- // is released.
- res = res[i:]
- cp := make([]Line, len(res))
- copy(cp, res)
- return cp
- }
- }
- return nil
- }
- func (r *recorder) Clear() {
- r.mut.Lock()
- r.lines = r.lines[:0]
- r.mut.Unlock()
- }
- func (r *recorder) append(l LogLevel, msg string) {
- line := Line{
- When: time.Now(), // intentionally high precision
- Message: msg,
- Level: l,
- }
- r.mut.Lock()
- defer r.mut.Unlock()
- if len(r.lines) == cap(r.lines) {
- if r.initial > 0 {
- // Shift all lines one step to the left, keeping the "initial" first intact.
- copy(r.lines[r.initial+1:], r.lines[r.initial+2:])
- } else {
- copy(r.lines, r.lines[1:])
- }
- // Add the new one at the end
- r.lines[len(r.lines)-1] = line
- return
- }
- r.lines = append(r.lines, line)
- if len(r.lines) == r.initial {
- r.lines = append(r.lines, Line{time.Now(), "...", l})
- }
- }
- // controlStripper is a Writer that replaces control characters
- // with spaces.
- type controlStripper struct {
- io.Writer
- }
- func (s controlStripper) Write(data []byte) (int, error) {
- for i, b := range data {
- if b == '\n' || b == '\r' {
- // Newlines are OK
- continue
- }
- if b < 32 {
- // Characters below 32 are control characters
- data[i] = ' '
- }
- }
- return s.Writer.Write(data)
- }
|