logtail: allow changing log level concurrently

When tailscaled starts up, these lines run:

func run() error {
	// ...
	pol := logpolicy.New("tailnode.log.tailscale.io")
	pol.SetVerbosityLevel(args.verbose)
	// ...
}

If there are old log entries present, they immediate start getting uploaded. This races with the call to pol.SetVerbosityLevel.

This manifested itself as a test failure in tailscale.com/tstest/integration
when run with -race:

WARNING: DATA RACE
Read at 0x00c0001bc970 by goroutine 24:
  tailscale.com/logtail.(*Logger).Write()
      /Users/josh/t/corp/oss/logtail/logtail.go:517 +0x27c
  log.(*Logger).Output()
      /Users/josh/go/ts/src/log/log.go:184 +0x2b8
  log.Printf()
      /Users/josh/go/ts/src/log/log.go:323 +0x94
  tailscale.com/logpolicy.newLogtailTransport.func1()
      /Users/josh/t/corp/oss/logpolicy/logpolicy.go:509 +0x36c
  net/http.(*Transport).dial()
      /Users/josh/go/ts/src/net/http/transport.go:1168 +0x238
  net/http.(*Transport).dialConn()
      /Users/josh/go/ts/src/net/http/transport.go:1606 +0x21d0
  net/http.(*Transport).dialConnFor()
      /Users/josh/go/ts/src/net/http/transport.go:1448 +0xe4

Previous write at 0x00c0001bc970 by main goroutine:
  tailscale.com/logtail.(*Logger).SetVerbosityLevel()
      /Users/josh/t/corp/oss/logtail/logtail.go:131 +0x98
  tailscale.com/logpolicy.(*Policy).SetVerbosityLevel()
      /Users/josh/t/corp/oss/logpolicy/logpolicy.go:463 +0x60
  main.run()
      /Users/josh/t/corp/oss/cmd/tailscaled/tailscaled.go:178 +0x50
  main.main()
      /Users/josh/t/corp/oss/cmd/tailscaled/tailscaled.go:163 +0x71c

Goroutine 24 (running) created at:
  net/http.(*Transport).queueForDial()
      /Users/josh/go/ts/src/net/http/transport.go:1417 +0x4d8
  net/http.(*Transport).getConn()
      /Users/josh/go/ts/src/net/http/transport.go:1371 +0x5b8
  net/http.(*Transport).roundTrip()
      /Users/josh/go/ts/src/net/http/transport.go:585 +0x7f4
  net/http.(*Transport).RoundTrip()
      /Users/josh/go/ts/src/net/http/roundtrip.go:17 +0x30
  net/http.send()
      /Users/josh/go/ts/src/net/http/client.go:251 +0x4f0
  net/http.(*Client).send()
      /Users/josh/go/ts/src/net/http/client.go:175 +0x148
  net/http.(*Client).do()
      /Users/josh/go/ts/src/net/http/client.go:717 +0x1d0
  net/http.(*Client).Do()
      /Users/josh/go/ts/src/net/http/client.go:585 +0x358
  tailscale.com/logtail.(*Logger).upload()
      /Users/josh/t/corp/oss/logtail/logtail.go:367 +0x334
  tailscale.com/logtail.(*Logger).uploading()
      /Users/josh/t/corp/oss/logtail/logtail.go:289 +0xec


Rather than complicate the logpolicy API,
allow the verbosity to be adjusted concurrently.

Signed-off-by: Josh Bleecher Snyder <josh@tailscale.com>
This commit is contained in:
Josh Bleecher Snyder 2021-05-25 15:02:52 -07:00 committed by Brad Fitzpatrick
parent 1ece91cede
commit bb8ce48a6b

View File

@ -15,6 +15,7 @@
"net/http"
"os"
"strconv"
"sync/atomic"
"time"
"tailscale.com/logtail/backoff"
@ -72,7 +73,7 @@ func NewLogger(cfg Config, logf tslogger.Logf) *Logger {
}
l := &Logger{
stderr: cfg.Stderr,
stderrLevel: cfg.StderrLevel,
stderrLevel: int64(cfg.StderrLevel),
httpc: cfg.HTTPC,
url: cfg.BaseURL + "/c/" + cfg.Collection + "/" + cfg.PrivateID.String(),
lowMem: cfg.LowMemory,
@ -103,7 +104,7 @@ func NewLogger(cfg Config, logf tslogger.Logf) *Logger {
// logging facilities and uploading to a log server.
type Logger struct {
stderr io.Writer
stderrLevel int
stderrLevel int64 // accessed atomically
httpc *http.Client
url string
lowMem bool
@ -125,10 +126,8 @@ type Logger struct {
// SetVerbosityLevel controls the verbosity level that should be
// written to stderr. 0 is the default (not verbose). Levels 1 or higher
// are increasingly verbose.
//
// It should not be changed concurrently with log writes.
func (l *Logger) SetVerbosityLevel(level int) {
l.stderrLevel = level
atomic.StoreInt64(&l.stderrLevel, int64(level))
}
// SetLinkMonitor sets the optional the link monitor.
@ -514,7 +513,7 @@ func (l *Logger) Write(buf []byte) (int, error) {
return 0, nil
}
level, buf := parseAndRemoveLogLevel(buf)
if l.stderr != nil && l.stderr != ioutil.Discard && level <= l.stderrLevel {
if l.stderr != nil && l.stderr != ioutil.Discard && int64(level) <= atomic.LoadInt64(&l.stderrLevel) {
if buf[len(buf)-1] == '\n' {
l.stderr.Write(buf)
} else {