Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

log: race between SetFlag and Output #21935

Closed
dsnet opened this issue Sep 19, 2017 · 8 comments
Closed

log: race between SetFlag and Output #21935

dsnet opened this issue Sep 19, 2017 · 8 comments
Labels
CherryPickApproved Used during the release process for point releases FrozenDueToAge release-blocker
Milestone

Comments

@dsnet
Copy link
Member

dsnet commented Sep 19, 2017

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

@dsnet dsnet added this to the Go1.9.1 milestone Sep 19, 2017
@gopherbot
Copy link

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

@dsnet
Copy link
Member Author

dsnet commented Sep 19, 2017

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

@dsnet dsnet reopened this Sep 19, 2017
@n10v
Copy link
Contributor

n10v commented Sep 20, 2017

Sorry for this😰

@dsnet
Copy link
Member Author

dsnet commented Sep 20, 2017

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

@otoolec
Copy link

otoolec commented Sep 27, 2017

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 rsc modified the milestones: Go1.9.1, Go1.9.2 Oct 4, 2017
@rsc
Copy link
Contributor

rsc commented Oct 13, 2017

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

@rsc rsc added the CherryPickApproved Used during the release process for point releases label Oct 14, 2017
@gopherbot
Copy link

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

gopherbot pushed a commit that referenced this issue Oct 25, 2017
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>
Reviewed-on: https://go-review.googlesource.com/70976
Run-TryBot: Russ Cox <rsc@golang.org>
@rsc
Copy link
Contributor

rsc commented Oct 26, 2017

go1.9.2 has been packaged and includes:

The release is posted at golang.org/dl.

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

@rsc rsc closed this as completed Oct 26, 2017
@golang golang locked and limited conversation to collaborators Oct 26, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
CherryPickApproved Used during the release process for point releases FrozenDueToAge release-blocker
Projects
None yet
Development

No branches or pull requests

6 participants