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

219 lines
5.7 KiB
Go

// Copyright (c) 2020 Tailscale Inc & AUTHORS All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
// Package logger defines a type for writing to logs. It's just a
// convenience type so that we don't have to pass verbose func(...)
// types around.
package logger
import (
"bufio"
"container/list"
"fmt"
"io"
"io/ioutil"
"log"
"os"
"strings"
"sync"
"time"
"golang.org/x/time/rate"
)
// Logf is the basic Tailscale logger type: a printf-like func.
// Like log.Printf, the format need not end in a newline.
// Logf functions must be safe for concurrent use.
type Logf func(format string, args ...interface{})
// WithPrefix wraps f, prefixing each format with the provided prefix.
func WithPrefix(f Logf, prefix string) Logf {
return func(format string, args ...interface{}) {
f(prefix+format, args...)
}
}
// FuncWriter returns an io.Writer that writes to f.
func FuncWriter(f Logf) io.Writer {
return funcWriter{f}
}
// StdLogger returns a standard library logger from a Logf.
func StdLogger(f Logf) *log.Logger {
return log.New(FuncWriter(f), "", 0)
}
type funcWriter struct{ f Logf }
func (w funcWriter) Write(p []byte) (int, error) {
w.f("%s", p)
return len(p), nil
}
// Discard is a Logf that throws away the logs given to it.
func Discard(string, ...interface{}) {}
// limitData is used to keep track of each format string's associated
// rate-limiting data.
type limitData struct {
lim *rate.Limiter // the token bucket associated with this string
msgBlocked bool // whether a "duplicate error" message has already been logged
ele *list.Element // list element used to access this string in the cache
}
var disableRateLimit = os.Getenv("TS_DEBUG_LOG_RATE") == "all"
// rateFreePrefix are format string prefixes that are exempt from rate limiting.
// Things should not be added to this unless they're already limited otherwise.
var rateFreePrefix = []string{
"magicsock: disco: ",
"magicsock: CreateEndpoint:",
}
// RateLimitedFn returns a rate-limiting Logf wrapping the given logf.
// Messages are allowed through at a maximum of one message every f (where f is a time.Duration), in
// bursts of up to burst messages at a time. Up to maxCache strings will be held at a time.
func RateLimitedFn(logf Logf, f time.Duration, burst int, maxCache int) Logf {
if disableRateLimit {
return logf
}
r := rate.Every(f)
var (
mu sync.Mutex
msgLim = make(map[string]*limitData) // keyed by logf format
msgCache = list.New() // a rudimentary LRU that limits the size of the map
)
type verdict int
const (
allow verdict = iota
warn
block
)
judge := func(format string) verdict {
for _, pfx := range rateFreePrefix {
if strings.HasPrefix(format, pfx) {
return allow
}
}
mu.Lock()
defer mu.Unlock()
rl, ok := msgLim[format]
if ok {
msgCache.MoveToFront(rl.ele)
} else {
rl = &limitData{
lim: rate.NewLimiter(r, burst),
ele: msgCache.PushFront(format),
}
msgLim[format] = rl
if msgCache.Len() > maxCache {
delete(msgLim, msgCache.Back().Value.(string))
msgCache.Remove(msgCache.Back())
}
}
if rl.lim.Allow() {
rl.msgBlocked = false
return allow
}
if !rl.msgBlocked {
rl.msgBlocked = true
return warn
}
return block
}
return func(format string, args ...interface{}) {
switch judge(format) {
case allow:
logf(format, args...)
case warn:
// For the warning, log the specific format string
logf("[RATE LIMITED] format string \"%s\" (example: \"%s\")", format, fmt.Sprintf(format, args...))
}
}
}
// LogOnChange logs a given line only if line != lastLine, or if maxInterval has passed
// since the last time this identical line was logged.
func LogOnChange(logf Logf, maxInterval time.Duration, timeNow func() time.Time) Logf {
var (
mu sync.Mutex
sLastLogged string
tLastLogged = timeNow()
)
return func(format string, args ...interface{}) {
s := fmt.Sprintf(format, args...)
mu.Lock()
if s == sLastLogged && timeNow().Sub(tLastLogged) < maxInterval {
mu.Unlock()
return
}
sLastLogged = s
tLastLogged = timeNow()
mu.Unlock()
// Re-stringify it (instead of using "%s", s) so something like "%s"
// doesn't end up getting rate-limited. (And can't use 's' as the pattern,
// as it might contain formatting directives.)
logf(format, args...)
}
}
// ArgWriter is a fmt.Formatter that can be passed to any Logf func to
// efficiently write to a %v argument without allocations.
type ArgWriter func(*bufio.Writer)
func (fn ArgWriter) Format(f fmt.State, _ rune) {
bw := argBufioPool.Get().(*bufio.Writer)
bw.Reset(f)
fn(bw)
bw.Flush()
argBufioPool.Put(bw)
}
var argBufioPool = &sync.Pool{New: func() interface{} { return bufio.NewWriterSize(ioutil.Discard, 1024) }}
// Filtered returns a Logf that silently swallows some log lines.
// Each inbound format and args is evaluated and printed to a string s.
// The original format and args are passed to logf if and only if allow(s) returns true.
func Filtered(logf Logf, allow func(s string) bool) Logf {
return func(format string, args ...interface{}) {
msg := fmt.Sprintf(format, args...)
if !allow(msg) {
return
}
logf(format, args...)
}
}
// LogfCloser wraps logf to create a logger that can be closed.
// Calling close makes all future calls to newLogf into no-ops.
func LogfCloser(logf Logf) (newLogf Logf, close func()) {
var (
mu sync.Mutex
closed bool
)
close = func() {
mu.Lock()
defer mu.Unlock()
closed = true
}
newLogf = func(msg string, args ...interface{}) {
mu.Lock()
if closed {
mu.Unlock()
return
}
mu.Unlock()
logf(msg, args...)
}
return newLogf, close
}