vocdoni-node
vocdoni-node copied to clipboard
Published
20 hours ago •
vocdoni
vocdoni
Data race in api/census_test
This happens in bizono-0.1 branch (in sync currently with dev).
2022-10-25T21:12:36Z DEBUG bearerstdapi/bearerstdapi.go:117 request: null
2022-10-25T21:12:36Z DEBUG httprouter/message.go:56 response: {"error":"census id not found in local storage"}
2022-10-25T21:12:36Z DEBUG middleware/logger.go:150 "GET http://127.0.0.1:41437/census/55977632d187d38433ffae3e271c6f518b3a5fcf0af4c6697b9ee8ab2b594dc7/proof/3bea6f5b3af6de0374366c4719e43a1b067d89bc7f01f1f573981659a44ff17a HTTP/1.1" from 127.0.0.1:33008 - 400 49B in 630.35µs
2022-10-25T21:12:36Z INFO api/census_test.go:141 logger construction succeeded at level debug with output stdout
==================
WARNING: DATA RACE
Write at 0x00000722a744 by goroutine 31:
go.vocdoni.io/dvote/log.Init()
/__w/vocdoni-node/vocdoni-node/log/log.go:53 +0x5a4
go.vocdoni.io/dvote/api.TestCensusProof()
/__w/vocdoni-node/vocdoni-node/api/census_test.go:141 +0x5a
testing.tRunner()
/usr/local/go/src/testing/testing.go:1439 +0x213
testing.(*T).Run.func1()
/usr/local/go/src/testing/testing.go:1486 +0x47
Previous read at 0x00000722a744 by goroutine 23:
go.vocdoni.io/dvote/log.checkInvalidChars()
/__w/vocdoni-node/vocdoni-node/log/log.go:132 +0x3c
go.vocdoni.io/dvote/log.Warn()
/__w/vocdoni-node/vocdoni-node/log/log.go:156 +0x9d
go.vocdoni.io/dvote/httprouter/bearerstdapi.(*BearerStandardAPI).RegisterMethod.func1()
/__w/vocdoni-node/vocdoni-node/httprouter/bearerstdapi/bearerstdapi.go:147 +0x20a
go.vocdoni.io/dvote/httprouter/bearerstdapi.(*BearerStandardAPI).RegisterMethod.func1()
/__w/vocdoni-node/vocdoni-node/httprouter/bearerstdapi/bearerstdapi.go:146 +0x1a4
go.vocdoni.io/dvote/httprouter/bearerstdapi.(*BearerStandardAPI).RegisterMethod.func1()
/__w/vocdoni-node/vocdoni-node/httprouter/bearerstdapi/bearerstdapi.go:140 +0xaa
go.vocdoni.io/dvote/httprouter.(*HTTProuter).routerHandler.func1.2()
/__w/vocdoni-node/vocdoni-node/httprouter/httprouter.go:261 +0xde
Goroutine 31 (running) created at:
testing.(*T).Run()
/usr/local/go/src/testing/testing.go:1486 +0x724
testing.runTests.func1()
/usr/local/go/src/testing/testing.go:1839 +0x99
testing.tRunner()
/usr/local/go/src/testing/testing.go:1439 +0x213
testing.runTests()
/usr/local/go/src/testing/testing.go:1837 +0x7e4
testing.(*M).Run()
/usr/local/go/src/testing/testing.go:1719 +0xa71
main.main()
_testmain.go:49 +0x2e4
Goroutine 23 (finished) created at:
go.vocdoni.io/dvote/httprouter.(*HTTProuter).routerHandler.func1()
/__w/vocdoni-node/vocdoni-node/httprouter/httprouter.go:261 +0x51e
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2084 +0x4d
github.com/go-chi/chi.(*Mux).routeHTTP()
/go/pkg/mod/github.com/go-chi/[email protected]+incompatible/mux.go:431 +0x475
github.com/go-chi/chi.(*Mux).routeHTTP-fm()
<autogenerated>:1 +0x57
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2084 +0x4d
github.com/go-chi/cors.(*Cors).Handler.func1()
/go/pkg/mod/github.com/go-chi/[email protected]/cors.go:228 +0x323
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2084 +0x4d
github.com/go-chi/chi/middleware.Timeout.func1.1()
/go/pkg/mod/github.com/go-chi/[email protected]+incompatible/middleware/timeout.go:45 +0x4ef
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2084 +0x4d
github.com/go-chi/chi/middleware.ThrottleWithOpts.func1.1()
/go/pkg/mod/github.com/go-chi/[email protected]+incompatible/middleware/throttle.go:100 +0x[596](https://github.com/vocdoni/vocdoni-node/actions/runs/3324309634/jobs/5495717261#step:5:597)
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2084 +0x4d
github.com/go-chi/chi/middleware.Heartbeat.func1.1()
/go/pkg/mod/github.com/go-chi/[email protected]+incompatible/middleware/heartbeat.go:21 +0x190
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2084 +0x4d
github.com/go-chi/chi/middleware.Recoverer.func1()
/go/pkg/mod/github.com/go-chi/[email protected]+incompatible/middleware/recoverer.go:37 +0xeb
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2084 +0x4d
github.com/go-chi/chi/middleware.RequestLogger.func1.1()
/go/pkg/mod/github.com/go-chi/[email protected]+incompatible/middleware/logger.go:46 +0x58d
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2084 +0x4d
github.com/go-chi/chi/middleware.RealIP.func1()
/go/pkg/mod/github.com/go-chi/[email protected]+incompatible/middleware/realip.go:34 +0xd3
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2084 +0x4d
github.com/go-chi/chi.(*Mux).ServeHTTP()
/go/pkg/mod/github.com/go-chi/[email protected]+incompatible/mux.go:86 +0x7bc
net/http.serverHandler.ServeHTTP()
/usr/local/go/src/net/http/server.go:2916 +0x896
net/http.(*conn).serve()
/usr/local/go/src/net/http/server.go:1966 +0xbaa
net/http.(*Server).Serve.func3()
/usr/local/go/src/net/http/server.go:3071 +0x58
==================
@mvdan do you understand the race? It seems to be caused by the log package (I'm I wrong?). How's that possible?
This is the same as https://github.com/vocdoni/vocdoni-node/pull/153. The tests shouldn't be calling the global log.Init: tests can run in parallel, so they race with each other when modifying the global logger.
We should remove these log.Init calls inside tests. I can also send a PR to make log.Init panic if called twice, which should help us spot these regressions much faster. log.Init should only be called once, from func main.
We should remove these log.Init calls inside tests. I can also send a PR to make log.Init panic if called twice, which should help us spot these regressions much faster. log.Init should only be called once, from func main.
Sounds good to me.
Closing this issue.