Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

Sign up
Appearance settings

driver: bad connection thrown randomly #1629

Unanswered
miparnisari asked this question in Q&A
Discussion options

Issue description

I have a repo with some tests that run against MySQL and Postgres. The tests against Postgres always pass. The tests against MySQL randomly (50% chance i'd say) throw a driver: bad connection error. The error occurs both on one-off queries and transactions.

The interesting thing is that I can only reproduce in GitHub actions, never locally. What this means is that I don't know how to isolate the problem. Is it Github Actions? Docker on Github Actions? MySQL driver? MySQL db? My own code?

Example code

https://github.com/miparnisari/openfga. You can fork it and make commits to main to trigger the tests.

Error log

In a read:

2024年08月29日T17:50:06.3432416Z 2024年08月29日T17:48:47.981Z	�[31mERROR�[0m	sql	{"error": "driver: bad connection", "stack": "goroutine 44134 [running]:\nruntime/debug.Stack()\n\t/opt/hostedtoolcache/go/1.22.6/x64/src/runtime/debug/stack.go:24 +0x67\ngithub.com/openfga/openfga/pkg/storage/sqlcommon.HandleSQLError({0x21e7900, 0x2d9cc10}, {0x220a5d8, 0xc0011e81b8}, {0x0, 0x0, 0x0?})\n\t/home/runner/work/openfga/openfga/pkg/storage/sqlcommon/sqlcommon.go:412 +0x4d8\ngithub.com/openfga/openfga/pkg/storage/mysql.(*MySQL).read(0xc0010a8280, {0x21fc858, 0xc000c93290}, {0xc001992100, 0x1a}, 0xc000aa70e0, 0x0)\n\t/home/runner/work/openfga/openfga/pkg/storage/mysql/mysql.go:197 +0x10e6\ngithub.com/openfga/openfga/pkg/storage/mysql.(*MySQL).Read(0xc0010a8280, {0x21fc858, 0xc000c93260}, {0xc001992100, 0x1a}, 0xc000aa70e0, {{0x1a7bcb3?}})\n\t/home/runner/work/openfga/openfga/pkg/storage/mysql/mysql.go:140 +0x1dd\ngithub.com/openfga/openfga/pkg/storage/storagewrappers.(*ContextTracerWrapper).Read(0xc000de0510, {0x21fc858, 0xc000c93230}, {0xc001992100, 0x1a}, 0xc000aa70e0, {{0x1a7bf00?}})\n\t/home/runner/work/openfga/openfga/pkg/storage/storagewrappers/context.go:44 +0x117\ngithub.com/openfga/openfga/pkg/storage/storagewrappers.(*boundedConcurrencyTupleReader).Read(0xc000a82918, {0x21fc858, 0xc000c93230}, {0xc001992100, 0x1a}, 0xc000aa70e0, {{0x44a9ed?}})\n\t/home/runner/work/openfga/openfga/pkg/storage/storagewrappers/boundedconcurrency.go:79 +0x1c2\ngithub.com/openfga/openfga/pkg/storage/storagewrappers.(*combinedTupleReader).Read(0xc000ff5410, {0x21fc858, 0xc000c93230}, {0xc001992100, 0x1a}, 0xc000aa70e0, {{0x0?}})\n\t/home/runner/work/openfga/openfga/pkg/storage/storagewrappers/combinedtuplereader.go:55 +0x5c2\ngithub.com/openfga/openfga/pkg/server/commands/listusers.(*listUsersQuery).expandTTU(0xc000b823c0, {0x21fc858, 0xc000c93200}, 0xc000c929c0, 0xc000f47680, 0xc000aa7080)\n\t/home/runner/work/openfga/openfga/pkg/server/commands/listusers/list_users_rpc.go:859 +0x64c\ngithub.com/openfga/openfga/pkg/server/commands/listusers.(*listUsersQuery).expandRewrite(0xc000b823c0, {0x21fc890, 0xc000d7b5e0}, 0xc000c929c0, 0xc000af9e40, 0xc000aa7080)\n\t/home/runner/work/openfga/openfga/pkg/server/commands/listusers/list_users_rpc.go:407 +0x25a\ngithub.com/openfga/openfga/pkg/server/commands/listusers.(*listUsersQuery).expandUnion.func1({0x21fc890, 0xc000d7b5e0})\n\t/home/runner/work/openfga/openfga/pkg/server/commands/listusers/list_users_rpc.go:645 +0xc8\ngithub.com/sourcegraph/conc/pool.(*ContextPool).Go.func1()\n\t/home/runner/go/pkg/mod/github.com/sourcegraph/conc@v0.3.0/pool/context_pool.go:38 +0xf3\ngithub.com/sourcegraph/conc/pool.(*ContextPool).Go.(*ErrorPool).Go.func2()\n\t/home/runner/go/pkg/mod/github.com/sourcegraph/conc@v0.3.0/pool/error_pool.go:30 +0x34\ngithub.com/sourcegraph/conc/pool.(*Pool).worker(0xc000af6000)\n\t/home/runner/go/pkg/mod/github.com/sourcegraph/conc@v0.3.0/pool/pool.go:154 +0xde\ngithub.com/sourcegraph/conc/panics.(*Catcher).Try(0xc000af6010, 0xc0019ede20)\n\t/home/runner/go/pkg/mod/github.com/sourcegraph/conc@v0.3.0/panics/panics.go:23 +0x78\ngithub.com/sourcegraph/conc.(*WaitGroup).Go.func1()\n\t/home/runner/go/pkg/mod/github.com/sourcegraph/conc@v0.3.0/waitgroup.go:32 +0x90\ncreated by github.com/sourcegraph/conc.(*WaitGroup).Go in goroutine 44132\n\t/home/runner/go/pkg/mod/github.com/sourcegraph/conc@v0.3.0/waitgroup.go:30 +0xe5\n"}

In a transaction:

2024年08月29日T18:10:13.1788685Z 2024年08月29日T18:08:54.771Z	�[31mERROR�[0m	sql	{"error": "driver: bad connection", "stack": "goroutine 29937 [running]:\nruntime/debug.Stack()\n\t/opt/hostedtoolcache/go/1.22.6/x64/src/runtime/debug/stack.go:24 +0x67\ngithub.com/openfga/openfga/pkg/storage/sqlcommon.HandleSQLError({0x21e7920, 0x2d9cc10}, {0x220a5f8, 0xc002742dd8}, {0x0, 0x0, 0x0?})\n\t/home/runner/work/openfga/openfga/pkg/storage/sqlcommon/sqlcommon.go:412 +0x4d8\ngithub.com/openfga/openfga/pkg/storage/mysql.(*MySQL).CreateStore(0xc000210320, {0x21fc878, 0xc000e7c270}, 0xc0017505a0)\n\t/home/runner/work/openfga/openfga/pkg/storage/mysql/mysql.go:479 +0x1a06\ngithub.com/openfga/openfga/pkg/server/commands.(*CreateStoreCommand).Execute(0xc0028f58e0, {0x21fc878, 0xc000e7c270}, 0xc001447200)\n\t/home/runner/work/openfga/openfga/pkg/server/commands/create_store.go:43 +0x275\ngithub.com/openfga/openfga/pkg/server.(*Server).CreateStore(0xc00062e340, {0x21fc878, 0xc000e7c210}, 0xc001447200)\n\t/home/runner/work/openfga/openfga/pkg/server/server.go:1279 +0x856\ngithub.com/openfga/api/proto/openfga/v1._OpenFGAService_CreateStore_Handler.func1({0x21fc878, 0xc000e7c210}, {0x1dac540, 0xc001447200})\n\t/home/runner/go/pkg/mod/github.com/openfga/api/proto@v0.0.0-20240807201305-c96ec773cae9/openfga/v1/openfga_service_grpc.pb.go:548 +0xbf\ngithub.com/openfga/openfga/cmd/run.(*ServerContext).Run.UnaryServerInterceptor.func27({0x21fc878, 0xc000e7c1e0}, {0x1dac540, 0xc001447200}, 0xc0028f5860, 0xc000d78a80)\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware/v2@v2.1.0/interceptors/auth/auth.go:48 +0x136\ngoogle.golang.org/grpc.getChainUnaryHandler.func1({0x21fc878, 0xc000e7c1e0}, {0x1dac540, 0xc001447200})\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1196 +0x12d\ngithub.com/openfga/openfga/pkg/middleware/validator.UnaryServerInterceptor.func1.1({0x21fc878, 0xc000e7c150}, {0x1dac540, 0xc001447200})\n\t/home/runner/work/openfga/openfga/pkg/middleware/validator/validator.go:34 +0xff\ngithub.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/validator.UnaryServerInterceptor.func1({0x21fc878, 0xc000e7c150}, {0x1dac540, 0xc001447200}, 0x38?, 0xc000e72280)\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware/v2@v2.1.0/interceptors/validator/interceptors.go:23 +0xfa\ngithub.com/openfga/openfga/pkg/middleware/validator.UnaryServerInterceptor.func1({0x21fc878, 0xc000e7c150}, {0x1dac540, 0xc001447200}, 0xc0028f5860, 0xc001447400)\n\t/home/runner/work/openfga/openfga/pkg/middleware/validator/validator.go:33 +0xfc\ngoogle.golang.org/grpc.getChainUnaryHandler.func1({0x21fc878, 0xc000e7c150}, {0x1dac540, 0xc001447200})\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1196 +0x12d\ngithub.com/openfga/openfga/cmd/run.(*ServerContext).Run.NewLoggingInterceptor.UnaryServerInterceptor.func85({0x21fc878, 0xc000e7c150}, {0x1dac540, 0xc001447200}, 0xc0028f5860, 0xc0014473c0)\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware/v2@v2.1.0/interceptors/server.go:22 +0x2e2\ngoogle.golang.org/grpc.getChainUnaryHandler.func1({0x21fc878, 0xc000e7c150}, {0x1dac540, 0xc001447200})\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1196 +0x12d\ngithub.com/openfga/openfga/cmd/run.(*ServerContext).Run.NewUnaryInterceptor.UnaryServerInterceptor.func83({0x21fc920, 0xc0003b8310}, {0x1dac540, 0xc001447200}, 0xc0028f5860, 0xc001447380)\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware/v2@v2.1.0/interceptors/server.go:22 +0x2e2\ngoogle.golang.org/grpc.getChainUnaryHandler.func1({0x21fc920, 0xc0003b8310}, {0x1dac540, 0xc001447200})\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1196 +0x12d\ngithub.com/openfga/openfga/cmd/run.(*ServerContext).Run.(*TimeoutInterceptor).NewUnaryTimeoutInterceptor.func18({0x21fc878, 0xc000e7c090}, {0x1dac540, 0xc001447200}, 0xc0028f5860?, 0xc001447340)\n\t/home/runner/work/openfga/openfga/pkg/middleware/timeout.go:35 +0xf7\ngoogle.golang.org/grpc.getChainUnaryHandler.func1({0x21fc878, 0xc000e7c090}, {0x1dac540, 0xc001447200})\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1196 +0x12d\ngithub.com/openfga/openfga/cmd/run.(*ServerContext).Run.NewUnaryInterceptor.UnaryServerInterceptor.func79({0x21fc878, 0xc000e7c090}, {0x1dac540, 0xc001447200}, 0xc0028f5860, 0xc0014472c0)\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware/v2@v2.1.0/interceptors/server.go:22 +0x2e2\ngoogle.golang.org/grpc.getChainUnaryHandler.func1({0x21fc878, 0xc000e7c090}, {0x1dac540, 0xc001447200})\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1196 +0x12d\ngithub.com/grpc-ecosystem/go-grpc-middleware/tags.UnaryServerInterceptor.func1({0x21fc878, 0xc000e7c030}, {0x1dac540, 0xc001447200}, 0xc0028f5860, 0xc001447280)\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.4.0/tags/interceptors.go:23 +0x114\ngoogle.golang.org/grpc.getChainUnaryHandler.func1({0x21fc878, 0xc000e7c030}, {0x1dac540, 0xc001447200})\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1196 +0x12d\ngithub.com/grpc-ecosystem/go-grpc-middleware/v2/interceptors/recovery.UnaryServerInterceptor.func1({0x21fc878, 0xc000e7c030}, {0x1dac540, 0xc001447200}, 0xc0028f5860?, 0xc001447240)\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware/v2@v2.1.0/interceptors/recovery/interceptors.go:34 +0x14b\ngoogle.golang.org/grpc.NewServer.chainUnaryServerInterceptors.chainUnaryInterceptors.func1({0x21fc878, 0xc000e7c030}, {0x1dac540, 0xc001447200}, 0xc0028f5860, 0xc000d78a80)\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1187 +0xe8\ngithub.com/openfga/api/proto/openfga/v1._OpenFGAService_CreateStore_Handler({0x1e39cc0, 0xc00062e340}, {0x21fc878, 0xc000e7c030}, 0xc000e38f80, 0xc0010ae880)\n\t/home/runner/go/pkg/mod/github.com/openfga/api/proto@v0.0.0-20240807201305-c96ec773cae9/openfga/v1/openfga_service_grpc.pb.go:550 +0x1f4\ngoogle.golang.org/grpc.(*Server).processUnaryRPC(0xc00026a400, {0x21fc878, 0xc000837f20}, {0x2207260, 0xc002804300}, 0xc002b23200, 0xc000ed6b70, 0x2dcc310, 0x0)\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1379 +0x1a2d\ngoogle.golang.org/grpc.(*Server).handleStream(0xc00026a400, {0x2207260, 0xc002804300}, 0xc002b23200)\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1790 +0x1825\ngoogle.golang.org/grpc.(*Server).serveStreams.func2.1()\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1029 +0x159\ncreated by google.golang.org/grpc.(*Server).serveStreams.func2 in goroutine 29990\n\t/home/runner/go/pkg/mod/google.golang.org/grpc@v1.65.0/server.go:1040 +0x225\n"}

Configuration

Driver version (or git SHA): v1.8.1

Go version: 1.22.6

Server version: MySQL 8

Server OS: The issue happens on Ubuntu 22.04.4 (Github Actions).

You must be logged in to vote

Replies: 2 comments 5 replies

Comment options

It is too complex to investigate. Please minimize the reproducer.

Im most cases, "bad connection" errors happens after other error logged (not returned). Long living connection may cause it too.

  • Do you use max connection lifetime?
  • Any log on stderr?
You must be logged in to vote
5 replies
Comment options

@methane thanks for your reply. I agree, my repo is too complex to investigate, I need to spend some time trimming it. 😢

Do you use max connection lifetime?

My settings for these tests that fail:

  • MaxOpenConns: 30
  • MaxIdleConns: 10
  • ConnMaxIdleLifetime = 0
  • ConMaxxLifetime = 0

Any log on stderr?

I have all the logs for a failed test run here: logs_27770610005.zip I don't see any errors there.

Comment options

Are you sure about your test runner doesn't capture and hide logs from the driver?

Comment options

ConMaxLifetime = 0

Use 3 min.

Comment options

@methane is there a way to turn on logs from the driver?

Use 3 min.

Why do you suggest this? Doesn't ConMaxLifetime = 0 mean infinite lifetime? Why would I want to cap it, that would cause connection churn, no?

Comment options

@methane is there a way to turn on logs from the driver?

It is on by default. Unless your test runner capture the log.

Why do you suggest this? Doesn't ConMaxLifetime = 0 mean infinite lifetime? Why would I want to cap it, that would cause connection churn, no?

Because someone close connections and it cause error. Driver should close connection before it is closed by others.

Read https://github.com/go-sql-driver/mysql#important-settings

Comment options

You must be logged in to vote
0 replies
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Category
Q&A
Labels
None yet
Converted from issue

This discussion was converted from issue #1628 on August 30, 2024 05:32.

AltStyle によって変換されたページ (->オリジナル) /