Repository navigation
Referential Integrity errors log goroutines dying #60
Description
Whenever I get a referential integrity error in dat (a FK violated) I get the following log:
SSSSSS19:57:49.958360 ERR dat:sqlx queryStruct.3
err: pq: insert or update on table "offers" violates foreign key constraint "offers_game_id_fkey"
sql: WITH upd AS ( UPDATE "offers" SET "game_id" = $1, "offer_template_id" = $2, "player_id" = $3 WHERE (id=$4) RETURNING "id","created_at","updated_at","claimed_at"), ins AS ( INSERT INTO "offers"("game_id","offer_template_id","player_id") SELECT $1,$2,$3 WHERE NOT EXISTS (SELECT 1 FROM upd) RETURNING "id","created_at","updated_at","claimed_at") SELECT * FROM ins UNION ALL SELECT * FROM upd
args: $1=invalid-game $2=e6683585-2fb6-4dd9-8069-f4014a16638e $3=player-3 $4=00000000-0000-0000-0000-000000000000
goroutine 22 [running]:
runtime/debug.Stack(0x10, 0xc42018cc20, 0xc0180)
/usr/local/Cellar/go/1.7.4_2/libexec/src/runtime/debug/stack.go:24 +0x79
github.com/topfreegames/offers/vendor/github.com/mgutz/logxi/v1.(*HappyDevFormatter).getLevelContext(0xc42008fc60, 0x3, 0xc420329a40, 0x0, 0x0, 0x0, 0x0, 0xc420078c78, 0x5)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/mgutz/dat/sqlx-runner/exec.go:77 +0x33c
github.com/topfreegames/offers/vendor/github.com/mgutz/dat/sqlx-runner.(*Execer).queryStructFn(0xc420366000, 0x489060, 0xc42033ad20, 0x0, 0x0)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/mgutz/dat/sqlx-runner/exec.go:395 +0x235
github.com/topfreegames/offers/vendor/github.com/mgutz/dat/sqlx-runner.(*Execer).queryStruct(0xc420366000, 0x489060, 0xc42033ad20, 0xc42033ae01, 0xc4203270c0)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/mgutz/dat/sqlx-runner/exec.go:355 +0x63
github.com/topfreegames/offers/vendor/github.com/mgutz/dat/sqlx-runner.(*Execer).QueryStruct(0xc420366000, 0x489060, 0xc42033ad20, 0x4, 0xc42033adc0)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/mgutz/dat/sqlx-runner/execer.go:133 +0x97
github.com/topfreegames/offers/models.UpsertOffer.func1(0x594979, 0x594978)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/models/offer.go:62 +0x267
github.com/topfreegames/offers/models.(*MixedMetricsReporter).WithDatastoreSegment(0x0, 0x54e514, 0x6, 0x54e8e6, 0x6, 0xc42018d4c8, 0x0, 0x0)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/models/mixed_metrics_reporter.go:40 +0x183
github.com/topfreegames/offers/models.UpsertOffer(0x7b3900, 0xc420332240, 0xc42033ad20, 0x0, 0xc42004f588, 0x2afe3)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/models/offer.go:63 +0xbc
github.com/topfreegames/offers/models_test.glob..func4.3.3()
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/models/offer_test.go:135 +0xd1
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync(0xc420258b40, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/leafnodes/runner.go:104 +0x8d
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).run(0xc420258b40, 0xc42004f7b0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/leafnodes/runner.go:63 +0xe1
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*ItNode).Run(0xc420290720, 0x7aa5c0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/leafnodes/it_node.go:25 +0x64
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/spec.(*Spec).runSample(0xc42009cfc0, 0x0, 0x7aa5c0, 0xc420142c90)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/spec/spec.go:167 +0x4fd
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/spec.(*Spec).Run(0xc42009cfc0, 0x7aa5c0, 0xc420142c90)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/spec/spec.go:118 +0xbe
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpecs(0xc42025b0e0, 0x597001)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/specrunner/spec_runner.go:144 +0x262
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).Run(0xc42025b0e0, 0x19)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/specrunner/spec_runner.go:61 +0xf0
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/suite.(*Suite).Run(0xc420073090, 0x96f828, 0xc42009ca80, 0x55aaf9, 0x19, 0xc4202f6040, 0x1, 0x1, 0x7b0980, 0xc420142c90, ...)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/internal/suite/suite.go:59 +0x23b
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo.RunSpecsWithCustomReporters(0x7ab300, 0xc42009ca80, 0x55aaf9, 0x19, 0xc42018df00, 0x1, 0x1, 0x0)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/ginkgo_dsl.go:207 +0x27b
github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo.RunSpecs(0x7ab300, 0xc42009ca80, 0x55aaf9, 0x19, 0xc43476ccb6)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/vendor/github.com/onsi/ginkgo/ginkgo_dsl.go:188 +0x195
github.com/topfreegames/offers/models_test.TestApi(0xc42009ca80)
/Users/heynemann/Dropbox/dev/go/src/github.com/topfreegames/offers/models/models_suite_test.go:24 +0x64
testing.tRunner(0xc42009ca80, 0x596db8)
/usr/local/Cellar/go/1.7.4_2/libexec/src/testing/testing.go:610 +0x81
created by testing.(*T).Run
/usr/local/Cellar/go/1.7.4_2/libexec/src/testing/testing.go:646 +0x2ec
Any ideas on what's going on? It makes me uneasy to see that whenever a referential integrity error happens.
Activity
heynemann commentedon Feb 17, 2017
Another weird behavior I`m seeing is that if I silence logging (LOGXI="*=ERR,dat:sqlx=OFF") then the above does not happen, but I also stop receiving error messages from the Database.
My tests that verify that a model was not found fail if I run then without logging and pass otherwise.
mgutz commentedon Feb 17, 2017
The logging error is fixed in the next minor release of v2. The logxi logger had a logical error which I've since fixed. I'm concentrating on a release for our product so I probably won't get this for a couple of weeks. Keep the logger on for now or some errors might silently get swallowed.
heynemann commentedon Feb 21, 2017
Should we be using v2?
mgutz commentedon Feb 22, 2017
Yes v2 is the version that removes most of the panics, fixes logging and some JSON marshalling issues. Actually the next update in a couple of weeks will fix logging callstack, swallowing of errors when dat logging is disabled and marhsalling issues. I advise moving to v2 if you can. It gets most of my attention