bun icon indicating copy to clipboard operation
bun copied to clipboard

Race in (*DB).Table

Open mattpgray opened this issue 2 years ago • 1 comments

Hi, I am calling (*DB).Table in my code from multiple goroutines and the race detector has detected a race.

I am using go 1.20.2 and bun 1.1.2

While investigating the cause of this error, I have created this test case that shows the error:

package race

import (
	"database/sql"
	"reflect"
	"sync"
	"testing"

	"github.com/uptrace/bun"
	"github.com/uptrace/bun/dialect/pgdialect"
	"github.com/uptrace/bun/driver/pgdriver"
)

type ExampleModel struct {
	Column string
}

func TestRace(t *testing.T) {
	url := "postgres://postgres:[email protected]:5432/postgres?sslmode=disable"
	sqldb := sql.OpenDB(pgdriver.NewConnector(pgdriver.WithDSN(url)))
	db := bun.NewDB(sqldb, pgdialect.New())

	const nRunners = 50
	res := make(chan string, nRunners)
	var wg sync.WaitGroup
	for i := 0; i < nRunners; i++ {
		wg.Add(1)
		go func() {
			defer wg.Done()
			table := db.Table(reflect.TypeOf((*ExampleModel)(nil)))
			res <- table.Fields[0].CreateTableSQLType
		}()
	}

	wg.Wait()
	close(res)

	uniqueResults := map[string]struct{}{}
	for typ := range res {
		uniqueResults[typ] = struct{}{}
	}

	if len(uniqueResults) != 1 {
		t.Fatalf("incorrect number of unique results %+v", uniqueResults)
	}
}

Where there is a required postgres container that I created using docker run --rm --name postgres -p 5432:5432 -e POSTGRES_PASSWORD=postgres -e POSTGRES_USER=postgres -e POSTGRES_DB=postgres postgres:10.15 postgres -c log_statement=all.

When I run the above test with go test -race ., I get the following output:

$ go test -race .
==================
WARNING: DATA RACE
Write at 0x00c00008a260 by goroutine 11:
  github.com/uptrace/bun/schema.(*Tables).table()
      /home/mgray/go/pkg/mod/github.com/uptrace/[email protected]/schema/tables.go:120 +0x684
  github.com/uptrace/bun/schema.(*Tables).Get()
      /home/mgray/go/pkg/mod/github.com/uptrace/[email protected]/schema/tables.go:62 +0x6b
  github.com/uptrace/bun.(*DB).Table()
      /home/mgray/go/pkg/mod/github.com/uptrace/[email protected]/db.go:195 +0x2d
  race.TestRace.func1()
      /home/mgray/sandbox/bun-race/race_test.go:32 +0xf5

Previous read at 0x00c00008a260 by goroutine 46:
  race.TestRace.func1()
      /home/mgray/sandbox/bun-race/race_test.go:33 +0x153

Goroutine 11 (running) created at:
  race.TestRace()
      /home/mgray/sandbox/bun-race/race_test.go:30 +0x246
  testing.tRunner()
      /home/mgray/sdk/go1.20.2/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /home/mgray/sdk/go1.20.2/src/testing/testing.go:1629 +0x47

Goroutine 46 (finished) created at:
  race.TestRace()
      /home/mgray/sandbox/bun-race/race_test.go:30 +0x246
  testing.tRunner()
      /home/mgray/sdk/go1.20.2/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /home/mgray/sdk/go1.20.2/src/testing/testing.go:1629 +0x47
==================
--- FAIL: TestRace (0.00s)
    race_test.go:46: incorrect number of unique results map[:{} VARCHAR:{}]
    testing.go:1446: race detected during execution of test
FAIL
FAIL	race	0.014s
FAIL

After investigating the files in the race log, it seems that the fields in table are mutated outside of the sync once function, causing a race when multiple goroutines try to create the table entry for the first time.

In schema/tables.go:

	if !inProgress.init2() {
		return table
	}

	t.mu.Lock()
	delete(t.inProgress, typ)
	t.tables.Store(typ, table)
	t.mu.Unlock()

	t.dialect.OnTable(table)

	for _, field := range table.FieldMap {
		if field.UserSQLType == "" {
			field.UserSQLType = field.DiscoveredSQLType
		}
		if field.CreateTableSQLType == "" {
			field.CreateTableSQLType = field.UserSQLType
		}
	}

Moving the table mutation into init2 seems to fix the issue for me. I am happy to submit a PR if this seems okay.

mattpgray avatar Mar 31 '23 10:03 mattpgray

For anyone else having this issue registering the models before usage using db.RegisterModel also seems to work.

ghost avatar Aug 02 '24 13:08 ghost

This issue has been automatically marked as stale because it has not had activity in the last 30 days. If there is no update within the next 7 days, this issue will be closed.

github-actions[bot] avatar Nov 08 '24 03:11 github-actions[bot]