log: fix data race on log.Output

There was unprotected access to Logger.flag in log.Output which
could lead to data race in cases when log.SetFlags called simultaneously.
For example, "hot" switching on/off debug-mode for Logger by log.SetFlags
while application still writing logs.

Fixes #21935

Change-Id: I36be25f23cad44cde62ed1af28a30d276400e1b8
Reviewed-on: https://go-review.googlesource.com/64710
Reviewed-by: Joe Tsai <thebrokentoaster@gmail.com>
Run-TryBot: Joe Tsai <thebrokentoaster@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>

diff --git a/src/log/log.go b/src/log/log.go
index a6add87ca44d6df1ae0146a10e88e5fc62558ddb..2b7c57fdfe5ffff9904d9dec12958674d34b1a3a 100644 (file)
--- a/src/log/log.go
+++ b/src/log/log.go
@@ -147,11 +147,7 @@ func (l *Logger) formatHeader(buf *[]byte, t time.Time, file string, line int) {
 // provided for generality, although at the moment on all pre-defined
 // paths it will be 2.
 func (l *Logger) Output(calldepth int, s string) error {
-       // Get time early if we need it.
-       var now time.Time
-       if l.flag&(Ldate|Ltime|Lmicroseconds) != 0 {
-               now = time.Now()
-       }
+       now := time.Now() // get this early.
        var file string
        var line int
        l.mu.Lock()

diff --git a/src/log/log_test.go b/src/log/log_test.go
index 966fdf306bc1c9a2ca368ffc8de0c697e691044d..adc15e7e8ed7240b58a67847c0c010626e8beb89 100644 (file)
--- a/src/log/log_test.go
+++ b/src/log/log_test.go
@@ -88,6 +88,17 @@ func TestOutput(t *testing.T) {
        }
 }
 
+func TestOutputRace(t *testing.T) {
+       var b bytes.Buffer
+       l := New(&b, "", 0)
+       for i := 0; i < 100; i++ {
+               go func() {
+                       l.SetFlags(0)
+               }()
+               l.Output(0, "")
+       }
+}
+
 func TestFlagAndPrefixSetting(t *testing.T) {
        var b bytes.Buffer
        l := New(&b, "Test:", LstdFlags)