From bb8ce48a6bbb38f808bff456df5c35d9488554ed Mon Sep 17 00:00:00 2001
From: Josh Bleecher Snyder <josh@tailscale.com>
Date: Tue, 25 May 2021 15:02:52 -0700
Subject: [PATCH] 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>
---
 logtail/logtail.go | 11 +++++------
 1 file changed, 5 insertions(+), 6 deletions(-)

diff --git a/logtail/logtail.go b/logtail/logtail.go
index d9ed73532..6247573fd 100644
--- a/logtail/logtail.go
+++ b/logtail/logtail.go
@@ -15,6 +15,7 @@ import (
 	"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 {