Investigate the tests race conditions #1369

rach-id · 2023-02-10T15:48:07Z

Description

Currently, when running the race tests, we're also adding the -short flag. This means that multiple tests get skipped and not checked for races:

celestia-app/Makefile

Line 113 in 6163e27

@VERSION=$(VERSION) go test -mod=readonly -race -short ./...

To see the races happening, run the following:

$ go test -mod=readonly -race  ./...

Acceptance Criteria

Investigate the issue

The text was updated successfully, but these errors were encountered:

evan-forbes · 2023-02-10T19:07:09Z

one of the race conditions appears to be caused by the changes introduced in #1300. Now we're reading the header in the CheckTxState in Baseapp during ProcessProposal, which is somehow tripping up the race detector since that same state can be written to by a different routine, although that different routine doesn't appear to doing so until we commit the block.

rach-id · 2023-02-10T19:24:14Z

We could add a mutex to the context to fix this, no?. But another race sometimes happens also, related to IAVL (would need to run the tests multiple times to get it)

evan-forbes · 2023-02-20T13:12:37Z

we should see what the cosmos-sdk does to prevent this in v0.47.0-rc2

Wondertan · 2023-02-20T13:51:49Z

Posting here a recent race we observed in our CI.

WARNING: DATA RACE
Read at 0x00c00a4fbc50 by goroutine 5384:
  github.com/cosmos/cosmos-sdk/store/rootmulti.(*Store).LastCommitID()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/store/rootmulti/store.go:405 +0x3e
  github.com/cosmos/cosmos-sdk/store/rootmulti.(*Store).LatestVersion()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/store/rootmulti/store.go:400 +0x2e
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).createQueryContext()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/abci.go:635 +0x16d
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).RegisterGRPCServer.func1()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/grpcserver.go:50 +0x1c9
  github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1()
      /home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:25 +0x8e
  github.com/grpc-ecosystem/go-grpc-middleware/recovery.UnaryServerInterceptor.func1()
      /home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/recovery/interceptors.go:33 +0x139
  github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1()
      /home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:25 +0x8e
  github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1()
      /home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:34 +0x126
  github.com/cosmos/cosmos-sdk/x/auth/types._Query_Account_Handler()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/x/auth/types/query.pb.go:1178 +0x1dd
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).RegisterGRPCServer.func2()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/grpcserver.go:82 +0x13b
  google.golang.org/grpc.(*Server).processUnaryRPC()
      /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1336 +0x15da
  google.golang.org/grpc.(*Server).handleStream()
      /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1704 +0xff8
  google.golang.org/grpc.(*Server).serveStreams.func1.2()
      /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:965 +0xec

Previous write at 0x00c00a4fbc50 by goroutine 5037:
  github.com/cosmos/cosmos-sdk/store/rootmulti.(*Store).Commit()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/store/rootmulti/store.go:431 +0x1a7
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).Commit()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/abci.go:332 +0x203
  github.com/celestiaorg/celestia-app/app.(*App).Commit()
      <autogenerated>:1 +0x44
  github.com/tendermint/tendermint/abci/client.(*localClient).CommitSync()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/abci/client/local_client.go:290 +0x11a
  github.com/tendermint/tendermint/proxy.(*appConnConsensus).CommitSync()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/proxy/app_conn.go:96 +0x42
  github.com/tendermint/tendermint/state.(*BlockExecutor).Commit()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/state/execution.go:298 +0x366
  github.com/tendermint/tendermint/state.(*BlockExecutor).ApplyBlock()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/state/execution.go:250 +0xa90
  github.com/tendermint/tendermint/consensus.(*State).finalizeCommit()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1668 +0x12cc
  github.com/tendermint/tendermint/consensus.(*State).tryFinalizeCommit()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1576 +0x495
  github.com/tendermint/tendermint/consensus.(*State).enterCommit.func1()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1511 +0x13d
  runtime.deferreturn()
      /opt/hostedtoolcache/go/1.19.5/x64/src/runtime/panic.go:476 +0x32
  github.com/tendermint/tendermint/consensus.(*State).addVote()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:2171 +0x2b64
  github.com/tendermint/tendermint/consensus.(*State).tryAddVote()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1963 +0x77
  github.com/tendermint/tendermint/consensus.(*State).handleMsg()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:853 +0x1bc
  github.com/tendermint/tendermint/consensus.(*State).receiveRoutine()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:780 +0x6f1
  github.com/tendermint/tendermint/consensus.(*State).OnStart.func1()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:379 +0x3b

MSevey · 2023-05-23T21:01:42Z

Capturing recent occurrence

--> Running tests in race mode
VERSION=0.15.0-rc0-52-g5aba51b go test -mod=readonly -race ./test/util/testnode
==================
WARNING: DATA RACE
Write at 0x00c001424b10 by goroutine 189:
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).BeginBlock()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/abci.go:177 +0xa6b
  github.com/celestiaorg/celestia-app/app.(*App).BeginBlock()
      <autogenerated>:1 +0x97
  github.com/tendermint/tendermint/abci/client.(*localClient).BeginBlockSync()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/abci/client/local_client.go:306 +0x174
  github.com/tendermint/tendermint/proxy.(*appConnConsensus).BeginBlockSync()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/proxy/app_conn.go:84 +0xb7
  github.com/tendermint/tendermint/state.execBlockOnProxyApp()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/state/execution.go:377 +0x59c
  github.com/tendermint/tendermint/state.(*BlockExecutor).ApplyBlock()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/state/execution.go:210 +0x22d
  github.com/tendermint/tendermint/consensus.(*State).finalizeCommit()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1681 +0x12cc
  github.com/tendermint/tendermint/consensus.(*State).tryFinalizeCommit()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1589 +0x495
  github.com/tendermint/tendermint/consensus.(*State).enterCommit.func1()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1524 +0x113
  runtime.deferreturn()
      /usr/local/go/src/runtime/panic.go:476 +0x32
  github.com/tendermint/tendermint/consensus.(*State).addVote()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:2192 +0x2b64
  github.com/tendermint/tendermint/consensus.(*State).tryAddVote()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1984 +0x77
  github.com/tendermint/tendermint/consensus.(*State).handleMsg()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:867 +0x1bc
  github.com/tendermint/tendermint/consensus.(*State).receiveRoutine()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:794 +0x6f1
  github.com/tendermint/tendermint/consensus.(*State).OnStart.func1()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:388 +0x3b

Previous read at 0x00c001424b10 by goroutine 6890:
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).createQueryContext()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/abci.go:672 +0x519
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).RegisterGRPCServer.func1()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/grpcserver.go:50 +0x1c9
  github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1()
      /Users/matt/Code/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:25 +0x8e
  github.com/grpc-ecosystem/go-grpc-middleware/recovery.UnaryServerInterceptor.func1()
      /Users/matt/Code/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/recovery/interceptors.go:33 +0x139
  github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1()
      /Users/matt/Code/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:25 +0x8e
  github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1()
      /Users/matt/Code/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:34 +0x126
  github.com/cosmos/cosmos-sdk/x/auth/types._Query_Account_Handler()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/x/auth/types/query.pb.go:1178 +0x1dd
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).RegisterGRPCServer.func2()
      /Users/matt/Code/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/grpcserver.go:82 +0x13b
  google.golang.org/grpc.(*Server).processUnaryRPC()
      /Users/matt/Code/go/pkg/mod/google.golang.org/[email protected]/server.go:1336 +0x15da
  google.golang.org/grpc.(*Server).handleStream()
      /Users/matt/Code/go/pkg/mod/google.golang.org/[email protected]/server.go:1704 +0xff8
  google.golang.org/grpc.(*Server).serveStreams.func1.2()
      /Users/matt/Code/go/pkg/mod/google.golang.org/[email protected]/server.go:965 +0xec

rach-id · 2023-05-23T22:58:33Z

@MSevey Can you please link where this happened?

MSevey · 2023-05-24T01:11:53Z

@MSevey Can you please link where this happened?

this issue came up when in my 1:1 with Evan. I just rand the test/utils/testnode package with the race detector. I was just interested in learning more about it, but sounds like this has been a persistent issue.

Full stack trace https://gist.github.com/MSevey/e9a5db50e5407ee6c8810471659b0daa

evan-forbes · 2023-06-15T14:16:20Z

we should try again since this should at least help celestiaorg/cosmos-sdk#326 since it eliminates the reading of the header in the checkTx state during prepare and process proposal

Wondertan · 2023-06-23T16:01:11Z

One more. Maybe related to above, maybe not:

==================
WARNING: DATA RACE
Write at 0x00c0081ebf28 by goroutine 2986:
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).setCheckState()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/baseapp.go:437 +0x2af
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).Commit()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/abci.go:353 +0x544
  github.com/celestiaorg/celestia-app/app.(*App).Commit()
      <autogenerated>:1 +0x44
  github.com/tendermint/tendermint/abci/client.(*localClient).CommitSync()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/abci/client/local_client.go:290 +0x11a
  github.com/tendermint/tendermint/proxy.(*appConnConsensus).CommitSync()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/proxy/app_conn.go:96 +0x42
  github.com/tendermint/tendermint/state.(*BlockExecutor).Commit()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/state/execution.go:298 +0x366
  github.com/tendermint/tendermint/state.(*BlockExecutor).ApplyBlock()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/state/execution.go:250 +0xa90
  github.com/tendermint/tendermint/consensus.(*State).finalizeCommit()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1681 +0x12cc
  github.com/tendermint/tendermint/consensus.(*State).tryFinalizeCommit()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1589 +0x495
  github.com/tendermint/tendermint/consensus.(*State).enterCommit.func1()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1524 +0x113
  runtime.deferreturn()
      /opt/hostedtoolcache/go/1.20.5/x64/src/runtime/panic.go:476 +0x32
  github.com/tendermint/tendermint/consensus.(*State).addVote()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:2191 +0x2b64
  github.com/tendermint/tendermint/consensus.(*State).tryAddVote()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:1983 +0x77
  github.com/tendermint/tendermint/consensus.(*State).handleMsg()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:867 +0x65c
  github.com/tendermint/tendermint/consensus.(*State).receiveRoutine()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:794 +0x6cb
  github.com/tendermint/tendermint/consensus.(*State).OnStart.func1()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/consensus/state.go:388 +0x3b

Previous read at 0x00c0081ebf28 by goroutine 5232:
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).createQueryContext()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/abci.go:673 +0x4f2
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).RegisterGRPCServer.func1()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/grpcserver.go:50 +0x1c9
  github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1()
      /home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:25 +0x8e
  github.com/grpc-ecosystem/go-grpc-middleware/recovery.UnaryServerInterceptor.func1()
      /home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/recovery/interceptors.go:33 +0x139
  github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1.1()
      /home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:25 +0x8e
  github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1()
      /home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:34 +0x126
  github.com/cosmos/cosmos-sdk/x/auth/types._Query_Account_Handler()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/x/auth/types/query.pb.go:1178 +0x1dd
  github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).RegisterGRPCServer.func2()
      /home/runner/go/pkg/mod/github.com/celestiaorg/[email protected]/baseapp/grpcserver.go:82 +0x13b
  google.golang.org/grpc.(*Server).processUnaryRPC()
      /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1337 +0x17be
  google.golang.org/grpc.(*Server).handleStream()
      /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1714 +0xff8
  google.golang.org/grpc.(*Server).serveStreams.func1.1()
      /home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:959 +0xec

…2163) ## Overview the testnode is still hitting the race detector #1369, so we aren't running those integration tests with the race detector ## Checklist - [x] New and updated code has appropriate documentation - [x] New and updated code has new and/or updated testing - [x] Required CI checks are passing - [x] Visual proof for any user facing features like CLI or documentation updates - [ ] Linked issues closed with keywords

evan-forbes · 2024-06-10T16:13:57Z

blocked by first switching to v0.50.0 of the sdk since that would likely fix this issue #3535

rach-id added the testing items that are strictly related to adding or extending test coverage label Feb 10, 2023

This was referenced Feb 10, 2023

feat: implement app querier celestiaorg/orchestrator-relayer#112

Merged

feat: add mutex to testnode not to run multiple nodes #1342

Closed

evan-forbes added this to the Mainnet milestone Apr 12, 2023

evan-forbes added the bug Something isn't working label Apr 12, 2023

rootulp mentioned this issue Jun 19, 2023

test: skip data race tests without using -short flag #1964

Closed

evan-forbes mentioned this issue Jul 25, 2023

fix: stop running the malicious integration test during short mode #2163

Merged

5 tasks

evan-forbes removed this from the Mainnet milestone Aug 7, 2023

rootulp mentioned this issue Aug 15, 2023

TestMaxTotalBlobSizeSuite fails test-race #2276

Closed

evan-forbes mentioned this issue Aug 17, 2023

Consider using a different way to exclude test from the race detector #2303

Open

rootulp mentioned this issue Dec 15, 2023

TestCLITestSuite/TestCmdQueryTally: race detected during execution of test #2938

Closed

rootulp mentioned this issue Feb 8, 2024

TestLegacyUpgrade race detected #3095

Closed

coderabbitai bot mentioned this issue Feb 14, 2024

test: skip TestLegacyUpgrade in race mode #3111

Merged

evan-forbes added WS: Maintenance 🔧 includes bugs, refactors, flakes, and tech debt etc needs:triage labels May 17, 2024

evan-forbes removed the needs:triage label May 27, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Investigate the tests race conditions #1369

Investigate the tests race conditions #1369

rach-id commented Feb 10, 2023 •

edited by ninabarbakadze

Loading

evan-forbes commented Feb 10, 2023

rach-id commented Feb 10, 2023

evan-forbes commented Feb 20, 2023

Wondertan commented Feb 20, 2023

MSevey commented May 23, 2023

rach-id commented May 23, 2023

MSevey commented May 24, 2023

evan-forbes commented Jun 15, 2023 •

edited

Loading

Wondertan commented Jun 23, 2023

evan-forbes commented Jun 10, 2024 •

edited

Loading

Investigate the tests race conditions #1369

Investigate the tests race conditions #1369

Comments

rach-id commented Feb 10, 2023 • edited by ninabarbakadze Loading

Description

Acceptance Criteria

evan-forbes commented Feb 10, 2023

rach-id commented Feb 10, 2023

evan-forbes commented Feb 20, 2023

Wondertan commented Feb 20, 2023

MSevey commented May 23, 2023

rach-id commented May 23, 2023

MSevey commented May 24, 2023

evan-forbes commented Jun 15, 2023 • edited Loading

Wondertan commented Jun 23, 2023

evan-forbes commented Jun 10, 2024 • edited Loading

rach-id commented Feb 10, 2023 •

edited by ninabarbakadze

Loading

evan-forbes commented Jun 15, 2023 •

edited

Loading

evan-forbes commented Jun 10, 2024 •

edited

Loading