Skip to content

Instantly share code, notes, and snippets.

@jw-00000

jw-00000/main.go

Last active August 6, 2016 22:07
Show Gist options
  • Save jw-00000/5396cae6ebf838d04639e6f95ebac91b to your computer and use it in GitHub Desktop.
Save jw-00000/5396cae6ebf838d04639e6f95ebac91b to your computer and use it in GitHub Desktop.
Download ZIP
gorm bug: Create in PostgreSQL sets incorrect primary key (race condition)
Raw
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)
}
}
Raw
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
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment