Data race for socket

[kirik]

Hello! I got race condition randomly. Here is stack:

WARNING: DATA RACE
Read at 0x00c4201381b8 by goroutine 94:
  github.com/globalsign/mgo.(*Session).acquireSocket()
      /.../github.com/globalsign/mgo/session.go:4822 +0x768
  github.com/globalsign/mgo.(*Database).Run()
      /.../github.com/globalsign/mgo/session.go:799 +0x6d
  github.com/globalsign/mgo.(*Session).Run()
      /.../github.com/globalsign/mgo/session.go:2270 +0xc3
  github.com/globalsign/mgo.(*mongoCluster).isMaster()
      /.../github.com/globalsign/mgo/cluster.go:182 +0x27c
  github.com/globalsign/mgo.(*mongoCluster).syncServer()
      /.../github.com/globalsign/mgo/cluster.go:231 +0x457
  github.com/globalsign/mgo.(*mongoCluster).syncServersIteration.func1.1()
      /.../github.com/globalsign/mgo/cluster.go:553 +0x200

Previous write at 0x00c4201381b8 by goroutine 33:
  github.com/globalsign/mgo.(*mongoSocket).kill()
      /.../github.com/globalsign/mgo/socket.go:351 +0x251
  github.com/globalsign/mgo.(*mongoSocket).resetNonce.func1()
      /.../github.com/globalsign/mgo/auth.go:123 +0x135
  github.com/globalsign/mgo.(*mongoSocket).readLoop()
      /.../github.com/globalsign/mgo/socket.go:628 +0x1101

Goroutine 94 (running) created at:
  github.com/globalsign/mgo.(*mongoCluster).syncServersIteration.func1()
      /.../github.com/globalsign/mgo/cluster.go:525 +0x174
  github.com/globalsign/mgo.(*mongoCluster).syncServersIteration()
      /.../github.com/globalsign/mgo/cluster.go:580 +0x54b
  github.com/globalsign/mgo.(*mongoCluster).syncServersLoop()
      /.../github.com/globalsign/mgo/cluster.go:390 +0x18e

Goroutine 33 (running) created at:
  github.com/globalsign/mgo.newSocket()
      /.../github.com/globalsign/mgo/socket.go:197 +0x392
  github.com/globalsign/mgo.(*mongoServer).Connect()
      /.../github.com/globalsign/mgo/server.go:183 +0x60c
  github.com/globalsign/mgo.(*mongoServer).AcquireSocket()
      /.../github.com/globalsign/mgo/server.go:129 +0x349
  github.com/globalsign/mgo.(*mongoCluster).syncServer()
      /.../github.com/globalsign/mgo/cluster.go:225 +0x2a5
  github.com/globalsign/mgo.(*mongoCluster).syncServersIteration.func1.1()
      /.../github.com/globalsign/mgo/cluster.go:553 +0x200
==================

I can't reproduce it. But I believe, that we need to Lock mutex for s.masterSocket on /.../globalsign/mgo/session.go:4822 before read dead property. Am I right?

Му OS is Ubuntu 16.04 and GO version is 1.9.2 linux/amd64.

Thank you in advance!

[domodwyer]

Hi @kirik

This is a bit weird - what commit are you using?

On the latest release (master / baa28fc / r2018.02.20) I see a read lock being taken on session.go:4813 (a few lines above the reported read) and an exclusive lock being taken on the write too (socket.go:344).

Dom

[kirik]

Hi @domodwyer
I'm using the latest release. Yes, there is exclusive lock on mongoSocket on socket.go:344, but on session.go:4813 read lock takes on the Session, not on masterSocket which it should be (I believe).
I'm Golang-newbie, don't blame me please if I wrong :)

[domodwyer]

Ah you're totally right. It's probably the case for the s.slaveSocket read too in the if above.

It should be possible to take read locks without causing a deadlock, but the locking is really, really tricky to follow so I can't say for sure without a test/proper review. I'm not entirely sure if it's a major problem either - the caller would get an error when trying to use the returned socket - it would be worth fixing and then profiling.

Thanks for the report!

Dom

[KJTsanaktsidis]

I might be able to have a look at this on Friday if nobody grabs it before then, since my brain has recently been in that code.

[tadukurow]

Seems like this issue is gaining some traction.
The fix could be as easy as ensuring locks are taken on slaveSocket and masterSocket (adding func(s *socket) Dead() error perhaps) whilst checking if they are dead in session.acquireSocket().

But as said above the locking is tricky and needs some careful investigation.
@KJTsanaktsidis you're still welcome to have a stab at this, if not maybe @eminano can help?

[KJTsanaktsidis]

I'll try and find some time for this over the weekend, but I don't want to stop someone else from taking a look at this too. Sorry, this kind of slipped off my radar :/