Data race while shutting down the database

[egonelbre]

I currently haven't yet diagnosed the underlying issue, but there's a possible to get a data race while the database is shutting down.

Based on the stack traces I would guess it has to do with having ongoing operations while calling *sql.DB.Close. https://pkg.go.dev/database/sql#Conn.Close can be called concurrently with any other pending operations.

I'll try to create a reproducer next week.

Race 1:

WARNING: DATA RACE
Write at 0x00c0021aabb0 by goroutine 1628:
  github.com/googleapis/go-sql-spanner.(*connector).closeClients()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:383 +0x78
  github.com/googleapis/go-sql-spanner.(*connector).Close()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:376 +0x108
  database/sql.(*DB).Close()
      /usr/local/go/src/database/sql/sql.go:937 +0x4b6

Previous write at 0x00c0021aabb0 by goroutine 2271:
  github.com/googleapis/go-sql-spanner.(*connector).closeClients()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:383 +0x78
  github.com/googleapis/go-sql-spanner.(*connector).decreaseConnCount()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:360 +0x152
  github.com/googleapis/go-sql-spanner.(*conn).Close()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:1031 +0x35
  database/sql.(*driverConn).finalClose.func2()
      /usr/local/go/src/database/sql/sql.go:677 +0x71
  database/sql.withLock()
      /usr/local/go/src/database/sql/sql.go:3530 +0xa6
  database/sql.(*driverConn).finalClose()
      /usr/local/go/src/database/sql/sql.go:675 +0x18d
  database/sql.finalCloser.finalClose-fm()
      <autogenerated>:1 +0x42
  database/sql.(*driverConn).Close()
      /usr/local/go/src/database/sql/sql.go:656 +0x170
  database/sql.(*DB).putConn()
      /usr/local/go/src/database/sql/sql.go:1512 +0x528
  database/sql.(*driverConn).releaseConn()
      /usr/local/go/src/database/sql/sql.go:560 +0x64
  database/sql.(*driverConn).releaseConn-fm()
      <autogenerated>:1 +0x17
  database/sql.(*Rows).close()
      /usr/local/go/src/database/sql/sql.go:3424 +0x3b5
  database/sql.(*Rows).Close()
      /usr/local/go/src/database/sql/sql.go:3395 +0x84
  database/sql.(*Rows).Next()
      /usr/local/go/src/database/sql/sql.go:3025 +0x13d
  database/sql.(*Row).Scan()
      /usr/local/go/src/database/sql/sql.go:3467 +0x2a4

Race 2:

WARNING: DATA RACE
Read at 0x00c0021aabc8 by goroutine 1628:
  github.com/googleapis/go-sql-spanner.(*connector).closeClients()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:385 +0xbb
  github.com/googleapis/go-sql-spanner.(*connector).Close()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:376 +0x108
  database/sql.(*DB).Close()
      /usr/local/go/src/database/sql/sql.go:937 +0x4b6

Previous write at 0x00c0021aabc8 by goroutine 2271:
  github.com/googleapis/go-sql-spanner.(*connector).closeClients()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:387 +0x11b
  github.com/googleapis/go-sql-spanner.(*connector).decreaseConnCount()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:360 +0x152
  github.com/googleapis/go-sql-spanner.(*conn).Close()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.7.2/driver.go:1031 +0x35
  database/sql.(*driverConn).finalClose.func2()
      /usr/local/go/src/database/sql/sql.go:677 +0x71
  database/sql.withLock()
      /usr/local/go/src/database/sql/sql.go:3530 +0xa6
  database/sql.(*driverConn).finalClose()
      /usr/local/go/src/database/sql/sql.go:675 +0x18d
  database/sql.finalCloser.finalClose-fm()
      <autogenerated>:1 +0x42
  database/sql.(*driverConn).Close()
      /usr/local/go/src/database/sql/sql.go:656 +0x170
  database/sql.(*DB).putConn()
      /usr/local/go/src/database/sql/sql.go:1512 +0x528
  database/sql.(*driverConn).releaseConn()
      /usr/local/go/src/database/sql/sql.go:560 +0x64
  database/sql.(*driverConn).releaseConn-fm()
      <autogenerated>:1 +0x17
  database/sql.(*Rows).close()
      /usr/local/go/src/database/sql/sql.go:3424 +0x3b5
  database/sql.(*Rows).Close()
      /usr/local/go/src/database/sql/sql.go:3395 +0x84
  database/sql.(*Rows).Next()
      /usr/local/go/src/database/sql/sql.go:3025 +0x13d
  database/sql.(*Row).Scan()
      /usr/local/go/src/database/sql/sql.go:3467 +0x2a4

[egonelbre]

Here's a reproducer:

package main

import (
	"context"
	"database/sql"
	"fmt"
	"time"

	_ "github.com/googleapis/go-sql-spanner"
	"github.com/googleapis/go-sql-spanner/examples"
)

// Simple sample application that shows how to use the Spanner Go sql driver.
//
// Execute the sample with the command `go run main.go` from this directory.
func helloWorld(projectId, instanceId, databaseId string) error {
	ctx := context.Background()
	db, err := sql.Open("spanner", fmt.Sprintf("projects/%s/instances/%s/databases/%s", projectId, instanceId, databaseId))
	if err != nil {
		return fmt.Errorf("failed to open database connection: %v\n", err)
	}
	defer db.Close()

	go func() {
		time.Sleep(time.Second)
		db.Close()
	}()

	for {
		rows, err := db.QueryContext(ctx, "SELECT 'Hello World!'")
		if err != nil {
			return fmt.Errorf("failed to execute query: %v", err)
		}
		var msg string
		for rows.Next() {
			if err := rows.Scan(&msg); err != nil {
				return fmt.Errorf("failed to scan row values: %v", err)
			}
			fmt.Printf("%s\n", msg)
		}
		if err := rows.Err(); err != nil {
			return fmt.Errorf("failed to execute query: %v", err)
		}
		if err := rows.Close(); err != nil {
			fmt.Printf("failed to close rows: %v", err)
			return nil
		}
	}
}

func main() {
	examples.RunSampleOnEmulator(helloWorld)
}