gocql icon indicating copy to clipboard operation
gocql copied to clipboard

Multiple session during go tests, resulting in failed tests

Open alexvnovelo opened this issue 3 years ago • 3 comments

Please answer these questions before submitting your issue. Thanks!

Background: I'm running golang integration tests that connect to one of our staging environments scylladb clusters. When i run go test ./... it actually runs 2 packages in parallel (sub directories from root directory where i called go test ./...). In each of these packages, there is one main _test.go file that runs through a suite of tests, creating their own session but under the same configurations. The close separately once their tests have finished.

When i run each of these packages seperately, the work perfectly. All tests pass, no timeouts, etc. However, when I run them together, I get the failing tests in both (1 failed test for each package), and occasionally the stack trace being printed out with the goroutines as shown in the "### What did you see instead?" section.

So my question is, Is it bad to have multiple session when running go tests? It seems to only have these issues when both of these sessions are open. Any help would be appreciated!

What version of Scylla or Cassandra are you using?

Scylla Enterprise 2021.1.8

What version of Gocql are you using?

github.com/gocql/gocql v0.0.0-20191102131523

What version of Go are you using?

go version go1.17.5 darwin/amd64

What did you do?

Ran integration tests

What did you expect to see?

Passing tests

What did you see instead?

goroutine 85 [select]: github.com/gocql/gocql.(*writeCoalescer).writeFlusher(0xc000382f00, 0x30d40) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:814 +0x139 created by github.com/gocql/gocql.newWriteCoalescer /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:719 +0x125

goroutine 83 [IO wait]: internal/poll.runtime_pollWait(0x7f96effc9310, 0x72, 0xffffffffffffffff) /opt/go/src/runtime/netpoll.go:222 +0x55 internal/poll.(*pollDesc).wait(0xc0003a0398, 0x72, 0x1000, 0x1000, 0xffffffffffffffff) /opt/go/src/internal/poll/fd_poll_runtime.go:87 +0x45 internal/poll.(*pollDesc).waitRead(...) /opt/go/src/internal/poll/fd_poll_runtime.go:92 internal/poll.(*FD).Read(0xc0003a0380, 0xc000346000, 0x1000, 0x1000, 0x0, 0x0, 0x0) /opt/go/src/internal/poll/fd_unix.go:166 +0x1d5 net.(*netFD).Read(0xc0003a0380, 0xc000346000, 0x1000, 0x1000, 0xc0003a7080, 0x3, 0xc0003ade88) /opt/go/src/net/fd_posix.go:55 +0x4f net.(*conn).Read(0xc0002c8300, 0xc000346000, 0x1000, 0x1000, 0x0, 0x0, 0x0) /opt/go/src/net/net.go:183 +0x91 bufio.(*Reader).Read(0xc0002819e0, 0xc00033e228, 0x1, 0x9, 0x40, 0x38, 0xce7ea0) /opt/go/src/bufio/bufio.go:227 +0x222 io.ReadAtLeast(0xe23ec0, 0xc0002819e0, 0xc00033e228, 0x1, 0x9, 0x1, 0xc0003add70, 0x410058, 0x38) /opt/go/src/io/io.go:328 +0x87 io.ReadFull(...) /opt/go/src/io/io.go:347 github.com/gocql/gocql.readHeader(0xe23ec0, 0xc0002819e0, 0xc00033e228, 0x9, 0x9, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/frame.go:449 +0x96 github.com/gocql/gocql.(*Conn).recv(0xc00033e1e0, 0x0, 0x0) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:593 +0xfd github.com/gocql/gocql.(*Conn).serve(0xc00033e1e0) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:510 +0x31 created by github.com/gocql/gocql.(*Session).dialWithoutObserver /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:283 +0x6ca

goroutine 86 [IO wait]: internal/poll.runtime_pollWait(0x7f96effc93f8, 0x72, 0xffffffffffffffff) /opt/go/src/runtime/netpoll.go:222 +0x55 internal/poll.(*pollDesc).wait(0xc00012a818, 0x72, 0x1000, 0x1000, 0xffffffffffffffff) /opt/go/src/internal/poll/fd_poll_runtime.go:87 +0x45 internal/poll.(*pollDesc).waitRead(...) /opt/go/src/internal/poll/fd_poll_runtime.go:92 internal/poll.(*FD).Read(0xc00012a800, 0xc000348000, 0x1000, 0x1000, 0x0, 0x0, 0x0) /opt/go/src/internal/poll/fd_unix.go:166 +0x1d5 net.(*netFD).Read(0xc00012a800, 0xc000348000, 0x1000, 0x1000, 0xc0003a7200, 0x3, 0xc000082e88) /opt/go/src/net/fd_posix.go:55 +0x4f net.(*conn).Read(0xc0002c8310, 0xc000348000, 0x1000, 0x1000, 0x0, 0x0, 0x0) /opt/go/src/net/net.go:183 +0x91 bufio.(*Reader).Read(0xc000281c20, 0xc00033e318, 0x1, 0x9, 0x40, 0x38, 0xce7ea0) /opt/go/src/bufio/bufio.go:227 +0x222 io.ReadAtLeast(0xe23ec0, 0xc000281c20, 0xc00033e318, 0x1, 0x9, 0x1, 0xc000082d70, 0x410058, 0x38) /opt/go/src/io/io.go:328 +0x87 io.ReadFull(...) /opt/go/src/io/io.go:347 github.com/gocql/gocql.readHeader(0xe23ec0, 0xc000281c20, 0xc00033e318, 0x9, 0x9, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/frame.go:449 +0x96 github.com/gocql/gocql.(*Conn).recv(0xc00033e2d0, 0x0, 0x0) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:593 +0xfd github.com/gocql/gocql.(*Conn).serve(0xc00033e2d0) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:510 +0x31 created by github.com/gocql/gocql.(*Session).dialWithoutObserver /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:283 +0x6ca

goroutine 84 [select]: github.com/gocql/gocql.(*Conn).heartBeat(0xc00033e1e0) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:550 +0x110 created by github.com/gocql/gocql.(*Session).dialWithoutObserver /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:284 +0x6ef

goroutine 87 [select]: github.com/gocql/gocql.(*Conn).heartBeat(0xc00033e2d0) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:550 +0x110 created by github.com/gocql/gocql.(*Session).dialWithoutObserver /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:284 +0x6ef

goroutine 99 [select]: github.com/gocql/gocql.(*Conn).exec(0xc0004280f0, 0xe35860, 0xc000125140, 0xe24700, 0xc0002ca300, 0x0, 0x0, 0x0, 0x0, 0x0) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:902 +0x3d3 github.com/gocql/gocql.(*Conn).executeQuery(0xc0004280f0, 0xe35860, 0xc000125140, 0xc0001f6240, 0x2a89755125acdb) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:1121 +0x569 github.com/gocql/gocql.(*Query).execute(0xc0001f6240, 0xe35860, 0xc000125140, 0xc0004280f0, 0x6be717) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/session.go:949 +0x49 github.com/gocql/gocql.(*queryExecutor).attemptQuery(0xc0003802a0, 0xe35860, 0xc000125140, 0xe3e5d0, 0xc0001f6240, 0xc0004280f0, 0xc0003ca000) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/query_executor.go:29 +0x84 github.com/gocql/gocql.(*queryExecutor).do(0xc0003802a0, 0xe35860, 0xc000125140, 0xe3e5d0, 0xc0001f6240, 0x40f8fb) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/query_executor.go:112 +0x1c7 github.com/gocql/gocql.(*queryExecutor).executeQuery(0xc0003802a0, 0xe3e5d0, 0xc0001f6240, 0x0, 0x0, 0x0) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/query_executor.go:60 +0xfb github.com/gocql/gocql.(*Session).executeQuery(0xc00039ea80, 0xc0001f6240, 0xd36216) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/session.go:426 +0xb2 github.com/gocql/gocql.(*Query).Iter(0xc0001f6240, 0xc0001f6240) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/session.go:1130 +0x45 github.com/gocql/gocql.(*Query).Exec(0xc0001f6240, 0xc0001f6240, 0x1e) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/session.go:1113 +0x2b medium.com/pkg/cql.(*Client).Exec(0xc000010308, 0xe35860, 0xc000125110, 0xe25820, 0xc00000e978, 0x0, 0x0) /workspace/go/pkg/cql/client.go:84 +0x1e5 medium.com/cmd/store/scylla.(*Store).DropTables(0xc00022c0e0, 0xe357f0, 0xc00003c0a8, 0xc0002cd790, 0x9, 0x0, 0x0) /workspace/go/cmd/store/scylla/tables.go:324 +0x17e medium.com/cmd/store/scylla.testFeatures(0xc000103c80, 0xe357f0, 0xc00003c0a8, 0xc00022c0e0) /workspace/go/cmd/store/scylla/entity_test.go:118 +0x1665 medium.com/cmd/store/scylla.TestStore.func1.1(0xc000103c80) /workspace/go/cmd/store/scylla/store_test.go:18 +0x4a testing.tRunner(0xc000103c80, 0xc000325920) /opt/go/src/testing/testing.go:1194 +0xef created by testing.(*T).Run /opt/go/src/testing/testing.go:1239 +0x2b3

goroutine 11 [select, 2 minutes]: github.com/gocql/gocql.(*Session).reconnectDownedHosts(0xc00039ea80, 0xdf8475800) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/session.go:286 +0x1b1 created by github.com/gocql/gocql.(*Session).init /builder/home/go/pkg/mod/github.com/gocql/[email protected]/session.go:252 +0x6df

goroutine 47 [select]: github.com/gocql/gocql.(*writeCoalescer).writeFlusher(0xc00034a2a0, 0x30d40) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:814 +0x139 created by github.com/gocql/gocql.newWriteCoalescer /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:719 +0x125

goroutine 49 [select]: github.com/gocql/gocql.(*Conn).heartBeat(0xc0004280f0) /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:550 +0x110 created by github.com/gocql/gocql.(*Session).dialWithoutObserver /builder/home/go/pkg/mod/github.com/gocql/[email protected]/conn.go:284 +0x6ef

If you are having connectivity related issues please share the following additional information

Describe your Cassandra cluster

please provide the following information

  • output of nodetool status
  • output of SELECT peer, rpc_address FROM system.peers
  • rebuild your application with the gocql_debug tag and post the output

alexvnovelo avatar Feb 09 '22 23:02 alexvnovelo

Do you see a panic or is there something else that causes the stack trace to be printed?

github.com/gocql/gocql v0.0.0-20191102131523

This version seems to be old and seems to be the upstream gocql/gocql, not scylladb/gocql. Please try using the latest version of scylladb/gocql, see https://github.com/scylladb/gocql#installation

martin-sucha avatar Feb 10 '22 08:02 martin-sucha

Do you see a panic or is there something else that causes the stack trace to be printed?

github.com/gocql/gocql v0.0.0-20191102131523

This version seems to be old and seems to be the upstream gocql/gocql, not scylladb/gocql. Please try using the latest version of scylladb/gocql, see https://github.com/scylladb/gocql#installation

It ends up panicking due to a timeout error with the tests exceeding 10 minutes. The 2 packages, when tested separately, take around 3 minutes. This leads me to believe there is some some sort of resource competition/data race going on .

Is is bad that we're using the upstream gocql/gocql instead of scylladb/gocql? Have their been issues reported when using gocql/gocql and Scylla databases? Thanks!

alexvnovelo avatar Feb 10 '22 17:02 alexvnovelo

See my reply at https://github.com/gocql/gocql/issues/1596#issuecomment-1037015708

martin-sucha avatar Feb 12 '22 06:02 martin-sucha