database/sql: add extra locking when calling driver

[blinsay]

What version of Go are you using (go version)?

go version go1.8.3 darwin/amd64

What did you do?

Unlike Conn or Stmt there's no guidance on Tx indicating how the stdlib uses implementations. This seems to cause bugs in driver implementations, as a Tx is expected to handle concurrent calls from multiple goroutines unlike most of the other interfaces in the package.

This came up as I was debugging a panic inside of lib/pq and discovered it was a data race due to the authors not assuming that their Tx would have to deal with calls from multiple goroutines (the repro is here. It slowly adjusts timeouts to try and make the Context time out as results are coming back). Out of curiosity, I looked at go-sql-driver/mysql and the lack of a race there seems like a happy accident - the Context expiring occasionally causes an internal error to bubble up, since the authors appear to aggressively check their invariants.

I'm not sure whether this is a documentation problem or if there's something database/sql could do to make life easier for driver implementors.

[odeke-em]

/cc @kardianos @bradfitz

[chrispassas]

In my case I have a pool of database connections. I open a transaction and run queries. If I use BeginTx() I get an crash panic overtime.

Part of why I need a transaction is so I can use postgresql statement_timeout. The only way to use it with a connection pool is to use a transaction.

If I just use Begin() without context it never crashes. In my case though I need to be able to cancel the transaction if conditions are met in another goroutine.

[blinsay]

Hey y'all,

It looks like driver libs are still tossing out panics in Go 1.9. The underlying problem with the way the stdlib and the drivers are misunderstanding each other seems like it's still there. This comment has some more info (race detector output, panic traces, and a reliable repro) on how lib/pq and database/sql interact to panic.

[kardianos]

This might not be a documentation issue but a driver issue.
row.Next locks on closemu, but doesn't lock on the driver connection lock. If DB.Next operations also locked on the dc, then we would probably correct this issue. Could someone apply the following diff locally and see if it fixes it? I need to do a fuller evaluation of what is going on as well.

In database/sql/sql.go

diff --git a/src/database/sql/sql.go b/src/database/sql/sql.go
index c609fe4..4f2c9f9 100644
--- a/src/database/sql/sql.go
+++ b/src/database/sql/sql.go
@@ -2454,6 +2454,9 @@ func (rs *Rows) nextLocked() (doClose, ok bool) {
        if rs.lastcols == nil {
                rs.lastcols = make([]driver.Value, len(rs.rowsi.Columns()))
        }
+       rs.dc.Lock()
+       defer rs.dc.Unlock()
+
        rs.lasterr = rs.rowsi.Next(rs.lastcols)
        if rs.lasterr != nil {
                // Close the connection if there is a driver error.
@@ -2503,6 +2506,8 @@ func (rs *Rows) NextResultSet() bool {
                doClose = true
                return false
        }
+       rs.dc.Lock()
+       defer rs.dc.Unlock()
        rs.lasterr = nextResultSet.NextResultSet()
        if rs.lasterr != nil {
                doClose = true

I need to do a full evaluation of this solution. But you could try it out and see if the issue goes away.

[blinsay]

I applied the patch and that seems to fix the panic and satisfy the race detector!

Now that the log lines aren't mostly race detector output/panic stacktrace I've started noticing that quite a lot of the errors that come back are sql.ErrNoRows. That seems surprising to me.

Here's some sample data after running the repro for a few minutes:

$ ~/oss/go/bin/go run -race repro.go &> repro.log

# wait a while, grab some coffee

$ grep -E -o "error=.*" < repro.log | sort | uniq -c
  46 error="context deadline exceeded"
   1 error="driver: bad connection"
3017 error="pq: canceling statement due to user request"
  42 error="sql: Rows are closed"
1369 error="sql: no rows in result set"

[kardianos]

@blinsay Good catch. Next step will be to determine why it is reporting no rows sometimes. I suspect it may be driver issue of returning the wrong error (NoRows rather then ctx.Error), but I haven't looked.

[gopherbot]

Change https://golang.org/cl/65731 mentions this issue: database/sql: prevent race in driver by locking dc in Next

[chrispassas]

Once fixed can this be released in go 1.9.1 or 1.9.2? This is causing me problems in my application and waiting for 1.10 would be hard.

Thank you

[chrispassas]

I'm not that familiar with the Go release process. This issue appears to be fixed but sitting in Code Review. What comes next? Is there any hope of getting this in a 1.9.x release?

https://go-review.googlesource.com/c/go/+/65731