Skip to content

database/sql: QueryContext() and Scan() data race #23519

Closed
@felixge

Description

@felixge

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

I reproduced this issue with multiple versions:

go version devel +99e6e482f4 Tue Jan 23 07:52:44 2018 +0000 darwin/amd64
go version go1.9.3 darwin/amd64

Does this issue reproduce with the latest release?

Yes.

What operating system and processor architecture are you using (go env)?

GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/felixge/Library/Caches/go-build"
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/felixge/code/go"
GORACE=""
GOROOT="/Users/felixge/code/golang"
GOTMPDIR=""
GOTOOLDIR="/Users/felixge/code/golang/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/fn/ln1qjq1927q88vpxvm7smkvm0000gn/T/go-build664804739=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

I have a test case involving a QueryContext query that is canceled in the middle of a call to rows.Scan(). The best minimal reproduction I was able to come up with was to apply this test patch to the Go core:

diff --git a/src/database/sql/sql_test.go b/src/database/sql/sql_test.go
index 8137eff82b..fd6ed14086 100644
--- a/src/database/sql/sql_test.go
+++ b/src/database/sql/sql_test.go
@@ -3194,6 +3194,9 @@ func TestIssue18429(t *testing.T) {
 			if rows != nil {
 				// Call Next to test Issue 21117 and check for races.
 				for rows.Next() {
+					// Call Scan() to trigger additional race conditions.
+					var name string
+					_ = rows.Scan(&name)
 				}
 				rows.Close()
 			}

The race detector doesn't always pick it up, so I was testing this in a loop:

cd src/database/sql
while go test -v -race -run 'TestIssue18429'; do :; done

What did you expect to see?

No race condition.

What did you see instead?

=== RUN   TestIssue18429
--- PASS: TestIssue18429 (0.07s)
PASS
ok  	database/sql	1.083s
=== RUN   TestIssue18429
==================
WARNING: DATA RACE
Write at 0x00c420158105 by goroutine 62:
  database/sql.(*rowsCursor).Close()
      /Users/felixge/code/golang/src/database/sql/fakedb_test.go:1025 +0xda
  database/sql.(*Rows).close.func1()
      /Users/felixge/code/golang/src/database/sql/sql.go:2920 +0x6e
  database/sql.withLock()
      /Users/felixge/code/golang/src/database/sql/sql.go:3032 +0x74
  database/sql.(*Rows).close()
      /Users/felixge/code/golang/src/database/sql/sql.go:2919 +0x1af
  database/sql.(*Rows).awaitDone()
      /Users/felixge/code/golang/src/database/sql/sql.go:2588 +0x138

Previous read at 0x00c420158105 by goroutine 23:
  runtime.slicebytetostring()
      /Users/felixge/code/golang/src/runtime/string.go:72 +0x0
  database/sql.convertAssign()
      /Users/felixge/code/golang/src/database/sql/convert.go:239 +0x21f0
  database/sql.(*Rows).Scan()
      /Users/felixge/code/golang/src/database/sql/sql.go:2886 +0x280
  database/sql.TestIssue18429.func1()
      /Users/felixge/code/golang/src/database/sql/sql_test.go:3199 +0x27b

Goroutine 62 (running) created at:
  database/sql.(*Rows).initContextClose()
      /Users/felixge/code/golang/src/database/sql/sql.go:2572 +0xda
  database/sql.(*DB).queryDC()
      /Users/felixge/code/golang/src/database/sql/sql.go:1509 +0x51f
  database/sql.(*Tx).QueryContext()
      /Users/felixge/code/golang/src/database/sql/sql.go:2128 +0x19f
  database/sql.TestIssue18429.func1()
      /Users/felixge/code/golang/src/database/sql/sql_test.go:3193 +0x1fe

Goroutine 23 (running) created at:
  database/sql.TestIssue18429()
      /Users/felixge/code/golang/src/database/sql/sql_test.go:3176 +0x19f
  testing.tRunner()
      /Users/felixge/code/golang/src/testing/testing.go:777 +0x16d
==================
--- FAIL: TestIssue18429 (0.07s)
	testing.go:730: race detected during execution of test
FAIL
exit status 1
FAIL	database/sql	0.084s

I strongly suspect that the work done in 1126d14 / #21117 is still missing some locking.

Metadata

Metadata

Assignees

No one assigned

    Labels

    FrozenDueToAgeNeedsInvestigationSomeone must examine and confirm this is a valid issue and not a duplicate of an existing one.

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions