Gorm: Race condition on ModelStruct.TableName()

Created on 30 Mar 2017  路  14Comments  路  Source: go-gorm/gorm

I'm getting a race condition warning when running a daemon I'm coding. Windows 10, MySQL 5.7.16, Go 1.8, GORM@master:

> go run -race .\worker.go

WARNING: DATA RACE
Read at 0x00c0421f8310 by goroutine 22:
  github.com/jinzhu/gorm.(*ModelStruct).TableName()
      C:/goprojects/src/github.com/jinzhu/gorm/model_struct.go:53 +0x4f
  github.com/jinzhu/gorm.(*Scope).TableName()
      C:/goprojects/src/github.com/jinzhu/gorm/scope.go:315 +0x1b7
  github.com/jinzhu/gorm.(*Scope).QuotedTableName()
      C:/goprojects/src/github.com/jinzhu/gorm/scope.go:327 +0x5c
  github.com/jinzhu/gorm.queryCallback()
      C:/goprojects/src/github.com/jinzhu/gorm/callback_query.go:28 +0xf1c
  github.com/jinzhu/gorm.(*Scope).callCallbacks()
      C:/goprojects/src/github.com/jinzhu/gorm/scope.go:821 +0x8f
  github.com/jinzhu/gorm.(*DB).First()
      C:/goprojects/src/github.com/jinzhu/gorm/main.go:264 +0x2e0
  main.fetchFeeds.func1()
      C:/goprojects/src/brunocassol.visualstudio.com/_git/go/rssreader/worker/worker.go:35 +0x2b1

Previous write at 0x00c0421f8310 by goroutine 20:
  github.com/jinzhu/gorm.(*ModelStruct).TableName()
      C:/goprojects/src/github.com/jinzhu/gorm/model_struct.go:62 +0x2dc
  github.com/jinzhu/gorm.(*Scope).TableName()
      C:/goprojects/src/github.com/jinzhu/gorm/scope.go:315 +0x1b7
  github.com/jinzhu/gorm.(*Scope).QuotedTableName()
      C:/goprojects/src/github.com/jinzhu/gorm/scope.go:327 +0x5c
  github.com/jinzhu/gorm.queryCallback()
      C:/goprojects/src/github.com/jinzhu/gorm/callback_query.go:28 +0xf1c
  github.com/jinzhu/gorm.(*Scope).callCallbacks()
      C:/goprojects/src/github.com/jinzhu/gorm/scope.go:821 +0x8f
  github.com/jinzhu/gorm.(*DB).First()
      C:/goprojects/src/github.com/jinzhu/gorm/main.go:264 +0x2e0
  main.fetchFeeds.func1()
      C:/goprojects/src/brunocassol.visualstudio.com/_git/go/rssreader/worker/worker.go:35 +0x2b1

model_struct.go:62 is s.defaultTableName = tableName in the following func:

// TableName get model's table name
func (s *ModelStruct) TableName(db *DB) string {
    if s.defaultTableName == "" && db != nil && s.ModelType != nil {
        // Set default table name
        if tabler, ok := reflect.New(s.ModelType).Interface().(tabler); ok {
            s.defaultTableName = tabler.TableName()
        } else {
            tableName := ToDBName(s.ModelType.Name())
            if db == nil || !db.parent.singularTable {
                tableName = inflection.Plural(tableName)
            }
            s.defaultTableName = tableName
        }
    }

    return DefaultTableNameHandler(db, s.defaultTableName)
}

It seems this code has to do with table db.SingularTable(true) which I'm using and was introduced about 2 months ago in this commit: https://github.com/jinzhu/gorm/commit/6633f325b8f514c7e2b8ffd989b1918bd82b4d9e.

If it helps this are the only 2 models I have in the code:

type Feed struct {
    ID         int       `json:"id" gorm:"primary_key"`
    Title      string    `json:"title"`
    Link       string    `json:"link"`
    LastResult string    `json:"last_result"`
    CheckCount int64     `json:"check_count"`
    NextCheck  time.Time `json:"next_check"`
    Items      []Item    `json:"items"`

    CreatedAt time.Time  `json:"created_at"`
    UpdatedAt time.Time  `json:"updated_at"`
    DeletedAt *time.Time `json:"deleted_at" sql:"index"`
}

type Item struct {
    ID     int    `gorm:"primary_key"`
    Title  string `json:"title"`
    Link   string `json:"link"`
    FeedID int    `json:"feed_id"`

    CreatedAt time.Time  `json:"created_at"`
    UpdatedAt time.Time  `json:"updated_at"`
    DeletedAt *time.Time `json:"deleted_at" sql:"index"`
}

I tried writing a test but couldn't replicate the issue.

Most helpful comment

I'm getting a similar issue but with FirstOrCreate

WARNING: DATA RACE
Read at 0x00c420242130 by goroutine 143:
  github.com/jinzhu/gorm.(*ModelStruct).TableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/model_struct.go:53 +0x45
  github.com/jinzhu/gorm.(*Scope).TableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:327 +0x1b5
  github.com/jinzhu/gorm.(*Scope).QuotedTableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:339 +0x52
  github.com/jinzhu/gorm.queryCallback()
      /home/travis/gopath/src/github.com/jinzhu/gorm/callback_query.go:32 +0xe85
  github.com/jinzhu/gorm.(*Scope).callCallbacks()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:857 +0x90
  github.com/jinzhu/gorm.(*DB).First()
      /home/travis/gopath/src/github.com/jinzhu/gorm/main.go:291 +0x20c
  github.com/jinzhu/gorm.(*DB).FirstOrCreate()
      /home/travis/gopath/src/github.com/jinzhu/gorm/main.go:380 +0x92
  github.com/d4l3k/pok-server/stats.(*Monitor).Log()
      /home/travis/gopath/src/github.com/d4l3k/pok-server/stats/stats.go:50 +0x218
  github.com/d4l3k/pok-server/stats.(*Monitor).monitor()
      /home/travis/gopath/src/github.com/d4l3k/pok-server/stats/stats.go:35 +0x70
Previous write at 0x00c420242130 by goroutine 140:
  github.com/jinzhu/gorm.(*ModelStruct).TableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/model_struct.go:62 +0x2ad
  github.com/jinzhu/gorm.(*Scope).TableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:327 +0x1b5
  github.com/jinzhu/gorm.(*Scope).QuotedTableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:339 +0x52
  github.com/jinzhu/gorm.queryCallback()
      /home/travis/gopath/src/github.com/jinzhu/gorm/callback_query.go:32 +0xe85
  github.com/jinzhu/gorm.(*Scope).callCallbacks()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:857 +0x90
  github.com/jinzhu/gorm.(*DB).First()
      /home/travis/gopath/src/github.com/jinzhu/gorm/main.go:291 +0x20c
  github.com/jinzhu/gorm.(*DB).FirstOrCreate()
      /home/travis/gopath/src/github.com/jinzhu/gorm/main.go:380 +0x92
  github.com/d4l3k/pok-server/stats.(*Monitor).Log()
      /home/travis/gopath/src/github.com/d4l3k/pok-server/stats/stats.go:50 +0x218
  github.com/d4l3k/pok-server/stats.(*Monitor).monitor()
      /home/travis/gopath/src/github.com/d4l3k/pok-server/stats/stats.go:35 +0x70

All 14 comments

I have the same issue (on Ubuntu and Go 1.8) when I recently upgrade to version 2. Checking out gorm to the commit before https://github.com/jinzhu/gorm/commit/6633f325b8f514c7e2b8ffd989b1918bd82b4d9e fixed the race condition.

Same problem when running tests with -race flag, how to fix it @jinzhu?
Check also this comment, orm not works:
https://github.com/jinzhu/gorm/issues/1488#issuecomment-318345956

maybe this will also help:

Previous write at 0x00c4201c0360 by goroutine 10:
  gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm.(*ModelStruct).TableName()
      /Users/apple/Developer/goproject/src/gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm/model_struct.go:62 +0x2d5
  gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm.(*Scope).TableName()
      /Users/apple/Developer/goproject/src/gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm/scope.go:325 +0x1b0
  gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm.(*Scope).QuotedTableName()
      /Users/apple/Developer/goproject/src/gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm/scope.go:337 +0x55
  gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm.createCallback()
      /Users/apple/Developer/goproject/src/gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm/callback_create.go:83 +0x10ac
  gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm.(*Scope).callCallbacks()
      /Users/apple/Developer/goproject/src/gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm/scope.go:831 +0x88
  gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm.(*DB).Create()
      /Users/apple/Developer/goproject/src/gitea.io/atlantide/curiosity/vendor/github.com/jinzhu/gorm/main.go:416 +0xdb
  gitea.io/atlantide/curiosity/test/helpers.(*UsersHelper).MakeUserWithDependencies()
      /Users/apple/Developer/goproject/src/gitea.io/atlantide/curiosity/test/helpers/users_helper.go:40 +0x1a3
  gitea.io/atlantide/curiosity/test/controllers.(*PasswordsResetsControllerSuite).TestUpdate()
      /Users/apple/Developer/goproject/src/gitea.io/atlantide/curiosity/test/controllers/password_resets_controller_test.go:43 +0x72a
  gitea.io/atlantide/curiosity/test/controllers.TestPasswordsResetsControllerSuite()
      /Users/apple/Developer/goproject/src/gitea.io/atlantide/curiosity/test/controllers/password_resets_controller_test.go:176 +0x46
  testing.tRunner()
      /Users/apple/.gimme/versions/go1.8.1.darwin.amd64/src/testing/testing.go:657 +0x107

Hi @mymtw

I am testing with -race flag, seems no error happen? are you using latest master?

Hi @jinzhu, you should run your tests in parallel.
e.g:

func TestSmthSuite(t *testing.T) {
    t.Parallel()
        ....
}

Then you will see

As a temporary workaround, until the bug is fixed, you can put a mutex around db.AutoMigrate() in order to prevent the error.

l.Lock()
db.AutoMigrate(...)
l.Unlock()

bug opened more than 1 year, you can simply use xorm instead

I'm getting a similar issue but with FirstOrCreate

WARNING: DATA RACE
Read at 0x00c420242130 by goroutine 143:
  github.com/jinzhu/gorm.(*ModelStruct).TableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/model_struct.go:53 +0x45
  github.com/jinzhu/gorm.(*Scope).TableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:327 +0x1b5
  github.com/jinzhu/gorm.(*Scope).QuotedTableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:339 +0x52
  github.com/jinzhu/gorm.queryCallback()
      /home/travis/gopath/src/github.com/jinzhu/gorm/callback_query.go:32 +0xe85
  github.com/jinzhu/gorm.(*Scope).callCallbacks()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:857 +0x90
  github.com/jinzhu/gorm.(*DB).First()
      /home/travis/gopath/src/github.com/jinzhu/gorm/main.go:291 +0x20c
  github.com/jinzhu/gorm.(*DB).FirstOrCreate()
      /home/travis/gopath/src/github.com/jinzhu/gorm/main.go:380 +0x92
  github.com/d4l3k/pok-server/stats.(*Monitor).Log()
      /home/travis/gopath/src/github.com/d4l3k/pok-server/stats/stats.go:50 +0x218
  github.com/d4l3k/pok-server/stats.(*Monitor).monitor()
      /home/travis/gopath/src/github.com/d4l3k/pok-server/stats/stats.go:35 +0x70
Previous write at 0x00c420242130 by goroutine 140:
  github.com/jinzhu/gorm.(*ModelStruct).TableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/model_struct.go:62 +0x2ad
  github.com/jinzhu/gorm.(*Scope).TableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:327 +0x1b5
  github.com/jinzhu/gorm.(*Scope).QuotedTableName()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:339 +0x52
  github.com/jinzhu/gorm.queryCallback()
      /home/travis/gopath/src/github.com/jinzhu/gorm/callback_query.go:32 +0xe85
  github.com/jinzhu/gorm.(*Scope).callCallbacks()
      /home/travis/gopath/src/github.com/jinzhu/gorm/scope.go:857 +0x90
  github.com/jinzhu/gorm.(*DB).First()
      /home/travis/gopath/src/github.com/jinzhu/gorm/main.go:291 +0x20c
  github.com/jinzhu/gorm.(*DB).FirstOrCreate()
      /home/travis/gopath/src/github.com/jinzhu/gorm/main.go:380 +0x92
  github.com/d4l3k/pok-server/stats.(*Monitor).Log()
      /home/travis/gopath/src/github.com/d4l3k/pok-server/stats/stats.go:50 +0x218
  github.com/d4l3k/pok-server/stats.(*Monitor).monitor()
      /home/travis/gopath/src/github.com/d4l3k/pok-server/stats/stats.go:35 +0x70

Also have this bug in our production code. Waiting for the PR merge.

This may or may not be the same issue as https://github.com/jinzhu/gorm/issues/1916 but I think I have a workaround. Basically the first time you use a model in gorm, it tries to cache some global state. That's where the race happens. To avoid the race, lock the first use of all gorm models. I did it the following way:

var gormSeedingLock sync.Mutex

func openGormDB() {
    ...
    gormSeedingLock.Lock()
    defer gormSeedingLock.Unlock()
    for _, table := range append([]interface{}{}, append(dbschema.All...)...) {
        (&gorm.Scope{Value: table}).HasColumn("whatever")
    }
}

where dbschema.All is the list of all models.

Edit: sorry, looks like this workaround fixes only the other race. #1958 does fix this race for me though.

Using mutex in orm for resolving this issue... Am I got it correctly that while one user(goroutine) will lock some map, other users(goroutines) will wait while some map will be unlocked?
if yes, this is not problem solving, this is - :wheelchair:

Update: sorry, looks like this workaround fixes only the other race. #1958 does fix this race for me though.

@dnathe4th reported that #2022 doesn't completely fix an issue with defaultTableName field. So posting it again as #2060.

Was this page helpful?
0 / 5 - 0 ratings