search

eug48 / fhir

FHIR Server using MongoDB and Go - now with proper transactions support! Aims to start quickly, have modest resource requirements and good performance.
Apache License 2.0
69 stars 16 forks source link

Parallel writes end up in write conflicts #6

Open 0xmichalis opened 5 years ago

0xmichalis commented 5 years ago

When multiple processes try to write to the fhir server, the requests fail with write conflicts. I am able to work around this issue by using the X-Mutex-Name header documented here but I was wondering whether this issue is meant to be fixed appropriately by having some sort of deterministic concurrency control baked into the server.

ps.1 The writes in the server are independent resources in my case (they are all resource creations).

ps.2 I am using the all-in-one image that bakes Mongo in it.

``` handlePanics: recovered: (WriteConflict) WriteConflict MongoDB operation error (/go/src/github.com/eug48/fhir/server/mongo_data_access.go:434) github.com/eug48/fhir/server.convertMongoErr /go/src/github.com/eug48/fhir/server/mongo_data_access.go:1148 github.com/eug48/fhir/server.(*mongoSession).PostWithID /go/src/github.com/eug48/fhir/server/mongo_data_access.go:434 github.com/eug48/fhir/server.(*BatchController).doRequest /go/src/github.com/eug48/fhir/server/batch_controller.go:417 github.com/eug48/fhir/server.(*BatchController).Post /go/src/github.com/eug48/fhir/server/batch_controller.go:303 github.com/eug48/fhir/server.(*BatchController).Post-fm /go/src/github.com/eug48/fhir/server/routing.go:128 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/fhir-server/middleware.ClientSpecifiedMutexesMiddleware.func2 /go/src/github.com/eug48/fhir/fhir-server/middleware/client_specified_mutexes.go:95 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/server.AbortNonFhirXMLorJSONRequestsMiddleware /go/src/github.com/eug48/fhir/server/middleware.go:43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/server.EnableXmlToJsonConversionMiddleware.func1 /go/src/github.com/eug48/fhir/server/middleware.go:14 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.RecoveryWithWriter.func1 /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/recovery.go:76 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.LoggerWithWriter.func1 /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/logger.go:84 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).handleHTTPRequest /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:383 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).ServeHTTP /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:349 net/http.serverHandler.ServeHTTP /usr/local/go/src/net/http/server.go:2697 net/http.(*conn).serve /usr/local/go/src/net/http/server.go:1830 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:2361 failed to create Encounter github.com/eug48/fhir/server.(*BatchController).doRequest /go/src/github.com/eug48/fhir/server/batch_controller.go:419 github.com/eug48/fhir/server.(*BatchController).Post /go/src/github.com/eug48/fhir/server/batch_controller.go:303 github.com/eug48/fhir/server.(*BatchController).Post-fm /go/src/github.com/eug48/fhir/server/routing.go:128 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/fhir-server/middleware.ClientSpecifiedMutexesMiddleware.func2 /go/src/github.com/eug48/fhir/fhir-server/middleware/client_specified_mutexes.go:95 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/server.AbortNonFhirXMLorJSONRequestsMiddleware /go/src/github.com/eug48/fhir/server/middleware.go:43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/server.EnableXmlToJsonConversionMiddleware.func1 /go/src/github.com/eug48/fhir/server/middleware.go:14 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.RecoveryWithWriter.func1 /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/recovery.go:76 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.LoggerWithWriter.func1 /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/logger.go:84 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).handleHTTPRequest /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:383 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).ServeHTTP /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:349 net/http.serverHandler.ServeHTTP /usr/local/go/src/net/http/server.go:2697 net/http.(*conn).serve /usr/local/go/src/net/http/server.go:1830 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:2361 goroutine 15 [running]: runtime/debug.Stack(0x149e000, 0xc42066da00, 0x149e000) /usr/local/go/src/runtime/debug/stack.go:24 +0xa7 github.com/eug48/fhir/server.ErrorToOpOutcome(0xf54200, 0xc421e3ac80, 0xc4214e1580, 0x1) /go/src/github.com/eug48/fhir/server/errors.go:29 +0x474 github.com/eug48/fhir/server.(*BatchController).Post(0xc4200f9b80, 0xc4217ac370) /go/src/github.com/eug48/fhir/server/batch_controller.go:318 +0x25f4 github.com/eug48/fhir/server.(*BatchController).Post-fm(0xc4217ac370) /go/src/github.com/eug48/fhir/server/routing.go:128 +0x34 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac370) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/fhir-server/middleware.ClientSpecifiedMutexesMiddleware.func2(0xc4217ac370) /go/src/github.com/eug48/fhir/fhir-server/middleware/client_specified_mutexes.go:95 +0xbc github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac370) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/server.AbortNonFhirXMLorJSONRequestsMiddleware(0xc4217ac370) /go/src/github.com/eug48/fhir/server/middleware.go:43 +0x1c7 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac370) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/server.EnableXmlToJsonConversionMiddleware.func1(0xc4217ac370) /go/src/github.com/eug48/fhir/server/middleware.go:14 +0x9e github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac370) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.RecoveryWithWriter.func1(0xc4217ac370) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/recovery.go:76 +0x5a github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac370) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.LoggerWithWriter.func1(0xc4217ac370) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/logger.go:84 +0xcc github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac370) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).handleHTTPRequest(0xc420386000, 0xc4217ac370) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:383 +0x586 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).ServeHTTP(0xc420386000, 0x14a4f60, 0xc420384fc0, 0xc4210a2800) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:349 +0x153 net/http.serverHandler.ServeHTTP(0xc4200a9a00, 0x14a4f60, 0xc420384fc0, 0xc4210a2800) /usr/local/go/src/net/http/server.go:2697 +0xbc net/http.(*conn).serve(0xc4214fd680, 0x14a71a0, 0xc42270f640) /usr/local/go/src/net/http/server.go:1830 +0x651 created by net/http.(*Server).Serve /usr/local/go/src/net/http/server.go:2798 +0x27b [GIN] 2019/05/22 - 11:08:34 | 500 | 322.9276ms | 10.1.11.3 | POST / 2019/05/22 11:08:34 [Recovery] 2019/05/22 - 11:08:34 panic recovered: POST / HTTP/1.1 Host: fhirserver:3001 Accept-Encoding: gzip Content-Length: 1117334 Content-Type: application/json User-Agent: Go-http-client/1.1 session.Finish error: (NoSuchTransaction) Transaction 1 has been aborted. /usr/local/go/src/runtime/panic.go:502 (0x4344b8) /go/src/github.com/eug48/fhir/server/mongo_data_access.go:115 (0xd7df3f) /go/src/github.com/eug48/fhir/server/batch_controller.go:321 (0xd76e85) /go/src/github.com/eug48/fhir/server/routing.go:128 (0xd99813) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/fhir-server/middleware/client_specified_mutexes.go:95 (0x9a37eb) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/server/middleware.go:43 (0xd7d0b6) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/server/middleware.go:14 (0xd98dbd) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/recovery.go:76 (0x959d69) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/logger.go:84 (0x958bbb) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:383 (0x950a25) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:349 (0x9502b2) /usr/local/go/src/net/http/server.go:2697 (0x68bc0b) /usr/local/go/src/net/http/server.go:1830 (0x687d40) /usr/local/go/src/runtime/asm_amd64.s:2361 (0x460df0) handlePanics: recovered: (WriteConflict) WriteConflict MongoDB operation error (/go/src/github.com/eug48/fhir/server/mongo_data_access.go:434) github.com/eug48/fhir/server.convertMongoErr /go/src/github.com/eug48/fhir/server/mongo_data_access.go:1148 github.com/eug48/fhir/server.(*mongoSession).PostWithID /go/src/github.com/eug48/fhir/server/mongo_data_access.go:434 github.com/eug48/fhir/server.(*BatchController).doRequest /go/src/github.com/eug48/fhir/server/batch_controller.go:417 github.com/eug48/fhir/server.(*BatchController).Post /go/src/github.com/eug48/fhir/server/batch_controller.go:303 github.com/eug48/fhir/server.(*BatchController).Post-fm /go/src/github.com/eug48/fhir/server/routing.go:128 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/fhir-server/middleware.ClientSpecifiedMutexesMiddleware.func2 /go/src/github.com/eug48/fhir/fhir-server/middleware/client_specified_mutexes.go:95 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/server.AbortNonFhirXMLorJSONRequestsMiddleware /go/src/github.com/eug48/fhir/server/middleware.go:43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/server.EnableXmlToJsonConversionMiddleware.func1 /go/src/github.com/eug48/fhir/server/middleware.go:14 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.RecoveryWithWriter.func1 /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/recovery.go:76 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.LoggerWithWriter.func1 /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/logger.go:84 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).handleHTTPRequest /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:383 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).ServeHTTP /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:349 net/http.serverHandler.ServeHTTP /usr/local/go/src/net/http/server.go:2697 net/http.(*conn).serve /usr/local/go/src/net/http/server.go:1830 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:2361 failed to create Encounter github.com/eug48/fhir/server.(*BatchController).doRequest /go/src/github.com/eug48/fhir/server/batch_controller.go:419 github.com/eug48/fhir/server.(*BatchController).Post /go/src/github.com/eug48/fhir/server/batch_controller.go:303 github.com/eug48/fhir/server.(*BatchController).Post-fm /go/src/github.com/eug48/fhir/server/routing.go:128 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/fhir-server/middleware.ClientSpecifiedMutexesMiddleware.func2 /go/src/github.com/eug48/fhir/fhir-server/middleware/client_specified_mutexes.go:95 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/server.AbortNonFhirXMLorJSONRequestsMiddleware /go/src/github.com/eug48/fhir/server/middleware.go:43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/server.EnableXmlToJsonConversionMiddleware.func1 /go/src/github.com/eug48/fhir/server/middleware.go:14 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.RecoveryWithWriter.func1 /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/recovery.go:76 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.LoggerWithWriter.func1 /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/logger.go:84 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).handleHTTPRequest /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:383 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).ServeHTTP /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:349 net/http.serverHandler.ServeHTTP /usr/local/go/src/net/http/server.go:2697 net/http.(*conn).serve /usr/local/go/src/net/http/server.go:1830 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:2361 goroutine 52 [running]: runtime/debug.Stack(0x149e000, 0xc420365600, 0x149e000) /usr/local/go/src/runtime/debug/stack.go:24 +0xa7 github.com/eug48/fhir/server.ErrorToOpOutcome(0xf54200, 0xc4203fba00, 0xc421e27580, 0x1) /go/src/github.com/eug48/fhir/server/errors.go:29 +0x474 github.com/eug48/fhir/server.(*BatchController).Post(0xc4200f9b80, 0xc4217ac420) /go/src/github.com/eug48/fhir/server/batch_controller.go:318 +0x25f4 github.com/eug48/fhir/server.(*BatchController).Post-fm(0xc4217ac420) /go/src/github.com/eug48/fhir/server/routing.go:128 +0x34 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac420) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/fhir-server/middleware.ClientSpecifiedMutexesMiddleware.func2(0xc4217ac420) /go/src/github.com/eug48/fhir/fhir-server/middleware/client_specified_mutexes.go:95 +0xbc github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac420) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/server.AbortNonFhirXMLorJSONRequestsMiddleware(0xc4217ac420) /go/src/github.com/eug48/fhir/server/middleware.go:43 +0x1c7 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac420) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/server.EnableXmlToJsonConversionMiddleware.func1(0xc4217ac420) /go/src/github.com/eug48/fhir/server/middleware.go:14 +0x9e github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac420) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.RecoveryWithWriter.func1(0xc4217ac420) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/recovery.go:76 +0x5a github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac420) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.LoggerWithWriter.func1(0xc4217ac420) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/logger.go:84 +0xcc github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Context).Next(0xc4217ac420) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 +0x43 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).handleHTTPRequest(0xc420386000, 0xc4217ac420) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:383 +0x586 github.com/eug48/fhir/vendor/github.com/gin-gonic/gin.(*Engine).ServeHTTP(0xc420386000, 0x14a4f60, 0xc420385180, 0xc4210a2a00) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:349 +0x153 net/http.serverHandler.ServeHTTP(0xc4200a9a00, 0x14a4f60, 0xc420385180, 0xc4210a2a00) /usr/local/go/src/net/http/server.go:2697 +0xbc net/http.(*conn).serve(0xc422cde460, 0x14a71a0, 0xc42270f8c0) /usr/local/go/src/net/http/server.go:1830 +0x651 created by net/http.(*Server).Serve /usr/local/go/src/net/http/server.go:2798 +0x27b [GIN] 2019/05/22 - 11:08:34 | 500 | 249.0425ms | 10.1.11.6 | POST / 2019/05/22 11:08:34 [Recovery] 2019/05/22 - 11:08:34 panic recovered: POST / HTTP/1.1 Host: fhirserver:3001 Accept-Encoding: gzip Content-Length: 1117334 Content-Type: application/json User-Agent: Go-http-client/1.1 session.Finish error: (NoSuchTransaction) Transaction 1 has been aborted. /usr/local/go/src/runtime/panic.go:502 (0x4344b8) /go/src/github.com/eug48/fhir/server/mongo_data_access.go:115 (0xd7df3f) /go/src/github.com/eug48/fhir/server/batch_controller.go:321 (0xd76e85) /go/src/github.com/eug48/fhir/server/routing.go:128 (0xd99813) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/fhir-server/middleware/client_specified_mutexes.go:95 (0x9a37eb) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/server/middleware.go:43 (0xd7d0b6) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/server/middleware.go:14 (0xd98dbd) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/recovery.go:76 (0x959d69) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/logger.go:84 (0x958bbb) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/context.go:109 (0x947e52) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:383 (0x950a25) /go/src/github.com/eug48/fhir/vendor/github.com/gin-gonic/gin/gin.go:349 (0x9502b2) /usr/local/go/src/net/http/server.go:2697 (0x68bc0b) /usr/local/go/src/net/http/server.go:1830 (0x687d40) /usr/local/go/src/runtime/asm_amd64.s:2361 (0x460df0) ```
eug48 commented 5 years ago

That's interesting - are you able to share what the requests look like? There's actually a new command-line switch requestsDumpDir that logs everything to a directory.

These transaction write conflicts are coming from MongoDB and the server is probably supposed to automatically retry the transaction. However I don't understand how resource creations can cause such conflicts..

0xmichalis commented 5 years ago

Sure, it's a record generated by synthea (record.tar.gz). Note that I am using the same record in all of those parallel requests and rely on the fact that every time a new resource is PUT, the server will return the created resource with its new ID.

eug48 commented 5 years ago

I have reproduced write conflict errors when processing that bundle but only during the first transactions.. Running it again with lots of concurrency then works fine. I don't quite understand why it happens but perhaps something to do with some one-off index work that takes a database-wide lock. Do you also see the first transaction(s) failing or intermittent failures?

0xmichalis commented 5 years ago

My context is tests running in parallel - when run serially (or with the same X-Mutex-Name set on every request), I don't see this issue.

eug48 commented 5 years ago

But when you run them in parallel how often do transactions fail? Can you attach log output? Thanks.