globalsign / mgo

The MongoDB driver for Go
Other
1.97k stars 230 forks source link

Lazy initialization of coarse time goroutine #278

Closed cezarsa closed 6 years ago

cezarsa commented 6 years ago

Initializing the coarseTime goroutine in the init() call had a pretty serious side effect. It was impossible to override the value of time.Local without causing a race condition, because its value is used on NewTicker calls.

This PR changes the previous behavior by only initializing the coarseTime goroutine when the first server is created. Allowing programs to possibly override time.Local before mgo is initialized.

domodwyer commented 6 years ago

Hi @cezarsa

I'm interested how this causes an issue - the time read by the ticker uses the monotonic clock to trigger the tick / calculate timeouts. Is it just a race warning when testing with code that also sets the local time var?

Either way, looks good!

Dom

eminano commented 6 years ago

Hi @cezarsa,

Could you please open a new PR targeting development branch instead of master as per contributing guidelines?

Looks good otherwise,

Thanks! Esther

domodwyer commented 6 years ago

It's worth noting that now Go has support for using the vDSO to get the time on FreeBSD (as of Go 1.11 I think, Linux has had it a while), courseTime can probably be deprecated once support for older Go versions is dropped in mgo.

cezarsa commented 6 years ago

@eminano I've switched the base to target the development branch, could you please reopen?

@domodwyer I'm sorry I should have included some details about how to reproduce the race condition an what it looks like, here it is:

With the following code:

package main

import (
    "time"

    _ "github.com/globalsign/mgo"
)

func main() {
    time.Local = time.UTC
}

Running go run -race main.go causes the following output:

$ go run -race main.go
==================
WARNING: DATA RACE
Read at 0x000001310d98 by goroutine 7:
  time.Now()
      /usr/local/Cellar/go/1.11/libexec/src/time/time.go:1060 +0xcf
  time.sendTime()
      /usr/local/Cellar/go/1.11/libexec/src/time/sleep.go:141 +0x44

Previous write at 0x000001310d98 by main goroutine:
  main.main()
      /Users/cezarsa/go/src/github.com/tsuru/tsuru-client/main.go:10 +0x56

Goroutine 7 (running) created at:
  runtime.(*timersBucket).addtimerLocked()
      /usr/local/Cellar/go/1.11/libexec/src/runtime/time.go:170 +0x113
  github.com/tsuru/tsuru-client/vendor/github.com/globalsign/mgo.newcoarseTimeProvider.func1()
      /Users/cezarsa/go/src/github.com/tsuru/tsuru-client/vendor/github.com/globalsign/mgo/coarse_time.go:49 +0x50
==================
Found 1 data race(s)
exit status 66
eminano commented 6 years ago

Hi @cezarsa, I can't reopen the PR because the branch was "force-pushed or recreated". I think I can reopen it only if there are no changes, so I'm afraid it might need to be done in a separate PR.

Sorry about that! :/