Intermittent data race in CombinedOutput?

[carolynvs]

I am seeing the Travis 1.8 builds occasionally fail with a data race warning.

Example:
https://travis-ci.org/golang/dep/jobs/277758891

WARNING: DATA RACE
Read at 0x00c4203745c8 by goroutine 43:
  github.com/golang/dep/internal/gps.cmd.CombinedOutput.func1()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/cmd_unix.go:56 +0x3b
  github.com/golang/dep/internal/gps.cmd.CombinedOutput()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/cmd_unix.go:78 +0x3b5
  github.com/golang/dep/internal/gps.(*gitRepo).fetch()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/vcs_repo.go:119 +0x235
  github.com/golang/dep/internal/gps.(*baseVCSSource).updateLocal()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/vcs_source.go:86 +0x6c
  github.com/golang/dep/internal/gps.(*gitSource).updateLocal()
      <autogenerated>:291 +0x68
  github.com/golang/dep/internal/gps.(*sourceGateway).require.func4()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source.go:601 +0x79
  github.com/golang/dep/internal/gps.(*supervisor).do()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source_manager.go:615 +0xfb
  github.com/golang/dep/internal/gps.(*sourceGateway).require()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source.go:602 +0x5ad
  github.com/golang/dep/internal/gps.(*sourceGateway).syncLocal()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source.go:275 +0xb0
  github.com/golang/dep/internal/gps.(*SourceMgr).SyncSourceFor()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source_manager.go:464 +0x17e
  github.com/golang/dep/internal/gps.(*bridge).breakLock.func1()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/bridge.go:204 +0x86

Previous write at 0x00c4203745c8 by goroutine 116:
  github.com/golang/dep/internal/gps.cmd.CombinedOutput.func2()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/cmd_unix.go:71 +0x18d

Goroutine 43 (running) created at:
  github.com/golang/dep/internal/gps.(*bridge).breakLock()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/bridge.go:208 +0x308
  github.com/golang/dep/internal/gps.(*solver).getLockVersionIfValid()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/solver.go:944 +0x78d
  github.com/golang/dep/internal/gps.(*solver).createVersionQueue()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/solver.go:787 +0xff1
  github.com/golang/dep/internal/gps.(*solver).solve()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/solver.go:493 +0x58a
  github.com/golang/dep/internal/gps.(*solver).Solve()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/solver.go:443 +0x13f
  github.com/golang/dep/cmd/dep.(*ensureCommand).runUpdate()
      /home/travis/gopath/src/github.com/golang/dep/cmd/dep/ensure.go:386 +0x5b3
  github.com/golang/dep/cmd/dep.(*ensureCommand).Run()
      /home/travis/gopath/src/github.com/golang/dep/cmd/dep/ensure.go:191 +0x5c1
  github.com/golang/dep/cmd/dep.(*Config).Run()
      /home/travis/gopath/src/github.com/golang/dep/cmd/dep/main.go:159 +0xd34
  github.com/golang/dep/cmd/dep.runMain()
      /home/travis/gopath/src/github.com/golang/dep/cmd/dep/integration_test.go:84 +0x2d4
  github.com/golang/dep/internal/test/integration.(*TestProject).DoRun()
      /home/travis/gopath/src/github.com/golang/dep/internal/test/integration/testproj.go:176 +0x50d
  github.com/golang/dep/cmd/dep.testIntegration.func1()
      /home/travis/gopath/src/github.com/golang/dep/cmd/dep/integration_test.go:117 +0x90b
  testing.tRunner()
      /home/travis/.gimme/versions/go1.8.3.linux.amd64/src/testing/testing.go:657 +0x107

Goroutine 116 (finished) created at:
  github.com/golang/dep/internal/gps.cmd.CombinedOutput()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/cmd_unix.go:75 +0x2b2
  github.com/golang/dep/internal/gps.(*gitRepo).fetch()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/vcs_repo.go:119 +0x235
  github.com/golang/dep/internal/gps.(*baseVCSSource).updateLocal()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/vcs_source.go:86 +0x6c
  github.com/golang/dep/internal/gps.(*gitSource).updateLocal()
      <autogenerated>:291 +0x68
  github.com/golang/dep/internal/gps.(*sourceGateway).require.func4()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source.go:601 +0x79
  github.com/golang/dep/internal/gps.(*supervisor).do()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source_manager.go:615 +0xfb
  github.com/golang/dep/internal/gps.(*sourceGateway).require()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source.go:602 +0x5ad
  github.com/golang/dep/internal/gps.(*sourceGateway).syncLocal()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source.go:275 +0xb0
  github.com/golang/dep/internal/gps.(*SourceMgr).SyncSourceFor()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/source_manager.go:464 +0x17e
  github.com/golang/dep/internal/gps.(*bridge).breakLock.func1()
      /home/travis/gopath/src/github.com/golang/dep/internal/gps/bridge.go:204 +0x86

[jmank88]

@tamird and I were looking at this, but I lost the stack trace by restarting the job: #1194

[carolynvs]

I've captured the full output from the race in a safe place:

https://gist.github.com/carolynvs/d3cecfc7e23567ad7a16ee750fa7987c

[tamird]

Yup, this is our smoking gun - notice that the read is on line 56: https://github.com/golang/dep/pull/1200/files#diff-88f7792af129ab5cf21a1cdb14828b1aL56

This was fixed in #1200.

[jmank88]

It looks like this stack trace aligns with the fix from #1200

[carolynvs]

Thanks, sorry I didn't notice that the PR was just needing another rebase!