database/sql: concurrent (*Tx).Stmt calls may crash when Tx is canceled

[cespare]

This is with go1.10beta1 / linux / amd64.

Repro code is at the bottom of the post.

You'll need to provide it with a postgres DB. I haven't had a chance to try with other drivers, but I'm 95% sure this is not driver-related.

I reliably get a crash after a few seconds:

$ go build && ./min txrace                                                                 !
378 (378 errors)
794 (732 errors)
1203 (1107 errors)
1645 (1484 errors)
2084 (1858 errors)
2528 (2219 errors)
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x4bef1b]

goroutine 8 [running]:
database/sql.(*Tx).StmtContext.func2()
        /home/caleb/apps/go/src/database/sql/sql.go:2061 +0x7b
database/sql.withLock(0x650680, 0xc4200c0000, 0xc4200dbe60)
        /home/caleb/apps/go/src/database/sql/sql.go:3032 +0x63
database/sql.(*Tx).StmtContext(0xc4200c0500, 0x651560, 0xc4200181b8, 0xc420144000, 0x0)
        /home/caleb/apps/go/src/database/sql/sql.go:2058 +0x5f7
database/sql.(*Tx).Stmt(0xc4200c0500, 0xc420144000, 0xc420161c80)
        /home/caleb/apps/go/src/database/sql/sql.go:2102 +0x4d
main.runTx(0xc420088140, 0xc420144000, 0x0, 0x0)
        /home/caleb/p/go/src/github.com/cespare/misc/txrace/min/txrace.go:70 +0x18b
main.main.func1(0xc420088140, 0xc420144000, 0xc420018cd8, 0xc420018cd0)
        /home/caleb/p/go/src/github.com/cespare/misc/txrace/min/txrace.go:36 +0x46
created by main.main
        /home/caleb/p/go/src/github.com/cespare/misc/txrace/min/txrace.go:34 +0x2a6

If I run this with 1.9.2 I don't see a crash but it OOMs after a bit due to some leak (likely #22976). (The original code that my repro was reduced from sees other, different crashes on 1.9.2 which look like #21117.)

Tentatively marking as Go 1.10 since it seems to be a regression.

/cc @kardianos

---

package main

import (
	"context"
	"database/sql"
	"fmt"
	"log"
	"os"
	"sync/atomic"
	"time"

	_ "github.com/lib/pq"
)

func main() {
	if len(os.Args) != 2 {
		log.Fatalf("usage: %s <dbname>", os.Args[0])
	}
	dbName := os.Args[1]
	db, err := sql.Open("postgres", "postgres://localhost/"+dbName)
	if err != nil {
		log.Fatal(err)
	}
	defer db.Close()

	stmt, err := db.Prepare("SELECT 1")
	if err != nil {
		log.Fatal(err)
	}

	var n int64
	var errs int64
	for i := 0; i < 10; i++ {
		go func() {
			for i := 0; ; i++ {
				if err := runTx(db, stmt); err != nil {
					atomic.AddInt64(&errs, 1)
				}
				atomic.AddInt64(&n, 1)
			}
		}()
	}
	for range time.Tick(time.Second) {
		fmt.Printf("%d (%d errors)\n", atomic.LoadInt64(&n), atomic.LoadInt64(&errs))
	}
}

func runTx(db *sql.DB, stmt *sql.Stmt) error {
	ctx, cancel := context.WithCancel(context.Background())
	quit := make(chan struct{})
	done := make(chan struct{})
	go func() {
		timer := time.NewTimer(time.Microsecond)
		defer timer.Stop()
		select {
		case <-quit:
		case <-timer.C:
		}
		cancel()
		close(done)
	}()
	defer func() {
		close(quit)
		<-done
	}()
	tx, err := db.BeginTx(ctx, nil)
	if err != nil {
		return err
	}
	_ = tx.Stmt(stmt)
	return tx.Commit()
}

[kardianos]

It is a regression. I introduced this in 1126d14 . I went through the other instances of withLock and don't see other similar mistakes.

[gopherbot]

Change https://golang.org/cl/85175 mentions this issue: database/sql: fix nil pointer use within withLock

[cespare]

Thanks @kardianos. This fixes the issue for me.