log: race between SetFlag and Output

[dsnet]

CL/38056 introduced a regression where l.flag was accessed outside of the protection of l.mu, which can cause a race with SetFlag:

go/src/log/log.go

Lines 152 to 154 in 4cf19fb

	if l.flag&(Ldate|Ltime|Lmicroseconds) != 0 {
	now = time.Now()
	}

A fix for this has been sent in CL/64710, but I'm opening an issue to consider cherry picking this into go1.9.1.

\cc @BoGeM

[gopherbot]

Change https://golang.org/cl/64710 mentions this issue: log: fix data race on log.Output

[dsnet]

Re-open for possible cherry-pick (for Go1.9 regression)

[n10v]

Sorry for this😰

[dsnet]

Mistakes happen. Most users probably never hit this issue. Hot-swapping the flag value is a rare use-case in my opinion.

[otoolec]

We just hit this. Caused in our case by spawning a goroutine during init which called log.Println while the main goroutine continued running init functions, one of which called log.SetFlag at the same time.

WARNING: DATA RACE
Read at 0x00c42008c1a8 by goroutine 8:
  log.(*Logger).Output()
      /usr/local/go/src/log/log.go:152 +0x77
  log.Println()
      /usr/local/go/src/log/log.go:305 +0xa1

Previous write at 0x00c42008c1a8 by main goroutine:
  log.(*Logger).SetFlags()
      /usr/local/go/src/log/log.go:244 +0x76
  log.SetFlags()
      /usr/local/go/src/log/log.go:275 +0x54

[rsc]

CL 64710 OK for Go 1.9.2.
It just reverts to the old Go 1.8 code.

[gopherbot]

Change https://golang.org/cl/70976 mentions this issue: [release-branch.go1.9] log: fix data race on log.Output

[rsc]

go1.9.2 has been packaged and includes:

• CL 64710

The release is posted at golang.org/dl.

— golang.org/x/build/cmd/releasebot, Oct 26 21:09:15 UTC