gorm bug: Create in PostgreSQL sets incorrect primary key (race condition)

main.go

package main

import (
	"log"
	"sync"

	"github.com/jinzhu/gorm"
	_ "github.com/jinzhu/gorm/dialects/postgres"
)

type Test struct {
	ID uint `sql:"AUTO_INCREMENT" gorm:"primary_key"`
	I  int
}

func main() {
	db, err := gorm.Open("postgres", "postgres://test:test@localhost:5432/test")
	if err != nil {
		panic(err)
	}

	db.LogMode(true)
	db.DB().Ping()

	db.Exec("DROP TABLE tests;")
	db.AutoMigrate(&Test{})

	N := 20

	// Wait group to only print results after all creates
	var wg sync.WaitGroup
	// results channel captures iteration i -> entry ID
	type result struct {
		i  int
		ID uint
	}
	results := make(chan result, N)
	for i := 0; i < N; i++ {
		wg.Add(1)
		// Create N separate goroutines that perform INSERTs simultaneously
		go func(i int) {
			defer wg.Done()
			// We create a record without primary key
			test := &Test{I: i}
			// Insert into database. Automatically assigns ID, and then sets
			// test.ID (but sometimes to the wrong ID)
			db.Create(test)
			// Save i -> test.ID
			results <- result{i, test.ID}
		}(i)
	}

	// Wait for all to finish before printing results
	wg.Wait()
	for i := 0; i < N; i++ {
		// Channel contains iteration i, and test.ID at that point. We fetch
		// the record from the database again (using the unique i), and retrieve
		// its actual ID.
		result := <-results
		var actual Test
		db.Where("i = ?", result.i).First(&actual)
		log.Printf("Test %d had test.ID %d after create, actual ID is %d\n",
			result.i, result.ID, actual.ID)
	}
}

output.txt

(/home/jw/tmp/testcase/main.go:25) 
[2016-08-07 00:04:59]  [4.27ms]  DROP TABLE tests;

(/home/jw/tmp/testcase/main.go:26) 
[2016-08-07 00:04:59]  [18.13ms]  CREATE TABLE "tests" ("id" serial,"i" integer , PRIMARY KEY ("id")) 

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [8.25ms]  INSERT INTO "tests" ("i") VALUES ('15') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [25.16ms]  INSERT INTO "tests" ("i") VALUES ('3') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [0.82ms]  INSERT INTO "tests" ("i") VALUES ('7') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [13.77ms]  INSERT INTO "tests" ("i") VALUES ('2') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [0.55ms]  SELECT "id" FROM "tests"  # THIS IS NOT THE QUERY WE EXPECT

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [10.21ms]  INSERT INTO "tests" ("i") VALUES ('11') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [9.19ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [9.94ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [6.67ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [12.33ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [7.00ms]  INSERT INTO "tests" ("i") VALUES ('5') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [1.26ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [4.70ms]  INSERT INTO "tests" ("i") VALUES ('19') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [0.88ms]  INSERT INTO "tests" ("i") VALUES ('8') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [0.75ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [18.28ms]  INSERT INTO "tests" ("i") VALUES ('1') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [0.78ms]  INSERT INTO "tests" ("i") VALUES ('14') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [3.56ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [16.47ms]  INSERT INTO "tests" ("i") VALUES ('13') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [2.10ms]  INSERT INTO "tests" ("i") VALUES ('9') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [4.71ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [12.99ms]  INSERT INTO "tests" ("i") VALUES ('12') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [5.75ms]  INSERT INTO "tests" ("i") VALUES ('4') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [12.52ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [14.90ms]  INSERT INTO "tests" ("i") VALUES ('0') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [8.73ms]  INSERT INTO "tests" ("i") VALUES ('18') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [3.09ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [5.61ms]  INSERT INTO "tests" ("i") VALUES ('6') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [4.36ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [3.01ms]  INSERT INTO "tests" ("i") VALUES ('17') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [8.31ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [7.32ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [4.97ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [10.83ms]  INSERT INTO "tests" ("i") VALUES ('10') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [4.78ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [5.08ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [4.83ms]  INSERT INTO "tests" ("i") VALUES ('16') RETURNING "tests"."id"

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [2.37ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [3.68ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:47) 
[2016-08-07 00:04:59]  [0.74ms]  SELECT "id" FROM "tests"  

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.95ms]  SELECT * FROM "tests"  WHERE (i = '7') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 7 had test.ID 4 after create, actual ID is 4

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.99ms]  SELECT * FROM "tests"  WHERE (i = '3') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 3 had test.ID 1 after create, actual ID is 1

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [1.74ms]  SELECT * FROM "tests"  WHERE (i = '11') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 11 had test.ID 5 after create, actual ID is 5

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.83ms]  SELECT * FROM "tests"  WHERE (i = '2') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 2 had test.ID 4 after create, actual ID is 2    # WRONG!!

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.76ms]  SELECT * FROM "tests"  WHERE (i = '15') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 15 had test.ID 3 after create, actual ID is 3

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.59ms]  SELECT * FROM "tests"  WHERE (i = '5') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 5 had test.ID 7 after create, actual ID is 7

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.39ms]  SELECT * FROM "tests"  WHERE (i = '8') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 8 had test.ID 10 after create, actual ID is 10

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.40ms]  SELECT * FROM "tests"  WHERE (i = '1') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 1 had test.ID 7 after create, actual ID is 6    # WRONG!!

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.37ms]  SELECT * FROM "tests"  WHERE (i = '19') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 19 had test.ID 8 after create, actual ID is 8

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.91ms]  SELECT * FROM "tests"  WHERE (i = '14') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 14 had test.ID 11 after create, actual ID is 11

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.45ms]  SELECT * FROM "tests"  WHERE (i = '4') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 4 had test.ID 12 after create, actual ID is 12

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.36ms]  SELECT * FROM "tests"  WHERE (i = '9') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 9 had test.ID 15 after create, actual ID is 15

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.33ms]  SELECT * FROM "tests"  WHERE (i = '13') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 13 had test.ID 13 after create, actual ID is 13

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.33ms]  SELECT * FROM "tests"  WHERE (i = '0') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 0 had test.ID 14 after create, actual ID is 14

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.32ms]  SELECT * FROM "tests"  WHERE (i = '6') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 6 had test.ID 18 after create, actual ID is 18

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.33ms]  SELECT * FROM "tests"  WHERE (i = '12') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 12 had test.ID 10 after create, actual ID is 9    # WRONG!!

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.31ms]  SELECT * FROM "tests"  WHERE (i = '18') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 18 had test.ID 17 after create, actual ID is 17

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.70ms]  SELECT * FROM "tests"  WHERE (i = '17') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 17 had test.ID 19 after create, actual ID is 19

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.53ms]  SELECT * FROM "tests"  WHERE (i = '10') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 10 had test.ID 16 after create, actual ID is 16

(/home/jw/tmp/testcase/main.go:57) 
[2016-08-07 00:04:59]  [0.35ms]  SELECT * FROM "tests"  WHERE (i = '16') ORDER BY "tests"."id" ASC LIMIT 1
2016/08/07 00:04:59 Test 16 had test.ID 20 after create, actual ID is 20