You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

1885 lines
62 KiB

10 years ago
10 years ago
9 years ago
9 years ago
9 years ago
9 years ago
9 years ago
10 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
8 years ago
8 years ago
10 years ago
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
10 years ago
9 years ago
10 years ago
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
abci: localClient improvements & bugfixes & pubsub Unsubscribe issues (#2748) * use READ lock/unlock in ConsensusState#GetLastHeight Refs #2721 * do not use defers when there's no need * fix peer formatting (output its address instead of the pointer) ``` [54310]: E[11-02|11:59:39.851] Connection failed @ sendRoutine module=p2p peer=0xb78f00 conn=MConn{74.207.236.148:26656} err="pong timeout" ``` https://github.com/tendermint/tendermint/issues/2721#issuecomment-435326581 * panic if peer has no state https://github.com/tendermint/tendermint/issues/2721#issuecomment-435347165 It's confusing that sometimes we check if peer has a state, but most of the times we expect it to be there 1. https://github.com/tendermint/tendermint/blob/add79700b5fe84417538202b6c927c8cc5383672/mempool/reactor.go#L138 2. https://github.com/tendermint/tendermint/blob/add79700b5fe84417538202b6c927c8cc5383672/rpc/core/consensus.go#L196 (edited) I will change everything to always assume peer has a state and panic otherwise that should help identify issues earlier * abci/localclient: extend lock on app callback App callback should be protected by lock as well (note this was already done for InitChainAsync, why not for others???). Otherwise, when we execute the block, tx might come in and call the callback in the same time we're updating it in execBlockOnProxyApp => DATA RACE Fixes #2721 Consensus state is locked ``` goroutine 113333 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00180009c, 0xc0000c7e00) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*RWMutex).RLock(0xc001800090) /usr/local/go/src/sync/rwmutex.go:50 +0x4e github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).GetRoundState(0xc001800000, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:218 +0x46 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusReactor).queryMaj23Routine(0xc0017def80, 0x11104a0, 0xc0072488f0, 0xc007248 9c0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/reactor.go:735 +0x16d created by github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusReactor).AddPeer /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/reactor.go:172 +0x236 ``` because localClient is locked ``` goroutine 1899 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00003363c, 0xc0000cb500) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*Mutex).Lock(0xc000033638) /usr/local/go/src/sync/mutex.go:134 +0xff github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client.(*localClient).SetResponseCallback(0xc0001fb560, 0xc007868540) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client/local_client.go:32 +0x33 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy.(*appConnConsensus).SetResponseCallback(0xc00002f750, 0xc007868540) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy/app_conn.go:57 +0x40 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state.execBlockOnProxyApp(0x1104e20, 0xc002ca0ba0, 0x11092a0, 0xc00002f750, 0xc0001fe960, 0xc000bfc660, 0x110cfe0, 0xc000090330, 0xc9d12, 0xc000d9d5a0, ...) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state/execution.go:230 +0x1fd github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state.(*BlockExecutor).ApplyBlock(0xc002c2a230, 0x7, 0x0, 0xc000eae880, 0x6, 0xc002e52c60, 0x16, 0x1f927, 0xc9d12, 0xc000d9d5a0, ...) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state/execution.go:96 +0x142 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).finalizeCommit(0xc001800000, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1339 +0xa3e github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).tryFinalizeCommit(0xc001800000, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1270 +0x451 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit.func1(0xc001800000, 0x0, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1218 +0x90 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit(0xc001800000, 0x1f928, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1247 +0x6b8 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).addVote(0xc001800000, 0xc003d8dea0, 0xc000cf4cc0, 0x28, 0xf1, 0xc003bc7ad0, 0xc003bc7b10) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1659 +0xbad github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).tryAddVote(0xc001800000, 0xc003d8dea0, 0xc000cf4cc0, 0x28, 0xf1, 0xf1, 0xf1) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1517 +0x59 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).handleMsg(0xc001800000, 0xd98200, 0xc0070dbed0, 0xc000cf4cc0, 0x28) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:660 +0x64b github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine(0xc001800000, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:617 +0x670 created by github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).OnStart /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:311 +0x132 ``` tx comes in and CheckTx is executed right when we execute the block ``` goroutine 111044 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00003363c, 0x0) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*Mutex).Lock(0xc000033638) /usr/local/go/src/sync/mutex.go:134 +0xff github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client.(*localClient).CheckTxAsync(0xc0001fb0e0, 0xc002d94500, 0x13f, 0x280, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client/local_client.go:85 +0x47 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy.(*appConnMempool).CheckTxAsync(0xc00002f720, 0xc002d94500, 0x13f, 0x280, 0x1) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy/app_conn.go:114 +0x51 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/mempool.(*Mempool).CheckTx(0xc002d3a320, 0xc002d94500, 0x13f, 0x280, 0xc0072355f0, 0x0, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/mempool/mempool.go:316 +0x17b github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/core.BroadcastTxSync(0xc002d94500, 0x13f, 0x280, 0x0, 0x0, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/core/mempool.go:93 +0xb8 reflect.Value.call(0xd85560, 0x10326c0, 0x13, 0xec7b8b, 0x4, 0xc00663f180, 0x1, 0x1, 0xc00663f180, 0xc00663f188, ...) /usr/local/go/src/reflect/value.go:447 +0x449 reflect.Value.Call(0xd85560, 0x10326c0, 0x13, 0xc00663f180, 0x1, 0x1, 0x0, 0x0, 0xc005cc9344) /usr/local/go/src/reflect/value.go:308 +0xa4 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.makeHTTPHandler.func2(0x1102060, 0xc00663f100, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/handlers.go:269 +0x188 net/http.HandlerFunc.ServeHTTP(0xc002c81f20, 0x1102060, 0xc00663f100, 0xc0082d7900) /usr/local/go/src/net/http/server.go:1964 +0x44 net/http.(*ServeMux).ServeHTTP(0xc002c81b60, 0x1102060, 0xc00663f100, 0xc0082d7900) /usr/local/go/src/net/http/server.go:2361 +0x127 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.maxBytesHandler.ServeHTTP(0x10f8a40, 0xc002c81b60, 0xf4240, 0x1102060, 0xc00663f100, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:219 +0xcf github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.RecoverAndLogHandler.func1(0x1103220, 0xc00121e620, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:192 +0x394 net/http.HandlerFunc.ServeHTTP(0xc002c06ea0, 0x1103220, 0xc00121e620, 0xc0082d7900) /usr/local/go/src/net/http/server.go:1964 +0x44 net/http.serverHandler.ServeHTTP(0xc001a1aa90, 0x1103220, 0xc00121e620, 0xc0082d7900) /usr/local/go/src/net/http/server.go:2741 +0xab net/http.(*conn).serve(0xc00785a3c0, 0x11041a0, 0xc000f844c0) /usr/local/go/src/net/http/server.go:1847 +0x646 created by net/http.(*Server).Serve /usr/local/go/src/net/http/server.go:2851 +0x2f5 ``` * consensus: use read lock in Receive#VoteMessage * use defer to unlock mutex because application might panic * use defer in every method of the localClient * add a changelog entry * drain channels before Unsubscribe(All) Read https://github.com/tendermint/tendermint/blob/55362ed76630f3e1ebec159a598f6a9fb5892cb1/libs/pubsub/pubsub.go#L13 for the detailed explanation of the issue. We'll need to fix it someday. Make sure to keep an eye on https://github.com/tendermint/tendermint/blob/master/docs/architecture/adr-033-pubsub.md * retry instead of panic when peer has no state in reactors other than consensus in /dump_consensus_state RPC endpoint, skip a peer with no state * rpc/core/mempool: simplify error messages * rpc/core/mempool: use time.After instead of timer also, do not log DeliverTx result (to be consistent with other memthods) * unlock before calling the callback in reqRes#SetCallback
6 years ago
fix data race Closes #1442 ``` WARNING: DATA RACE Write at 0x00c4209de7c8 by goroutine 23: github.com/tendermint/tendermint/types.(*Block).fillHeader() /home/vagrant/go/src/github.com/tendermint/tendermint/types/block.go:88 +0x157 github.com/tendermint/tendermint/types.(*Block).Hash() /home/vagrant/go/src/github.com/tendermint/tendermint/types/block.go:104 +0x121 github.com/tendermint/tendermint/types.(*Block).HashesTo() /home/vagrant/go/src/github.com/tendermint/tendermint/types/block.go:135 +0x4f github.com/tendermint/tendermint/consensus.(*ConsensusState).enterPrecommit() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:1037 +0x182d github.com/tendermint/tendermint/consensus.(*ConsensusState).addVote() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:1425 +0x1a6c github.com/tendermint/tendermint/consensus.(*ConsensusState).tryAddVote() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:1318 +0x77 github.com/tendermint/tendermint/consensus.(*ConsensusState).handleMsg() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:581 +0x7a9 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:539 +0x6c3 Previous read at 0x00c4209de7c8 by goroutine 47: github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*HexBytes).MarshalJSON() <autogenerated>:1 +0x52 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.invokeMarshalJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:433 +0x88 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:82 +0x8d2 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).MarshalJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/amino.go:296 +0x182 github.com/tendermint/tendermint/rpc/lib/types.NewRPCSuccessResponse() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/types/types.go:100 +0x12c github.com/tendermint/tendermint/rpc/lib/server.makeJSONRPCHandler.func1() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/server/handlers.go:152 +0xab7 net/http.HandlerFunc.ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:1918 +0x51 net/http.(*ServeMux).ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:2254 +0xa2 github.com/tendermint/tendermint/rpc/lib/server.RecoverAndLogHandler.func1() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:138 +0x4fa net/http.HandlerFunc.ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:1918 +0x51 net/http.serverHandler.ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:2619 +0xbc net/http.(*conn).serve() /usr/lib/go-1.9/src/net/http/server.go:1801 +0x83b Goroutine 23 (running) created at: github.com/tendermint/tendermint/consensus.(*ConsensusState).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:250 +0x35b github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/consensus.(*ConsensusReactor).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/reactor.go:69 +0x1b4 github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/consensus.(*ConsensusReactor).Start() <autogenerated>:1 +0x43 github.com/tendermint/tendermint/p2p.(*Switch).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/p2p/switch.go:177 +0x124 github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/node.(*Node).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/node/node.go:416 +0xa1b github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/rpc/test.StartTendermint() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/test/helpers.go:100 +0x5b github.com/tendermint/tendermint/rpc/client_test.TestMain() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/client/main_test.go:17 +0x4c main.main() github.com/tendermint/tendermint/rpc/client/_test/_testmain.go:76 +0x1cd Goroutine 47 (running) created at: net/http.(*Server).Serve() /usr/lib/go-1.9/src/net/http/server.go:2720 +0x37c net/http.Serve() /usr/lib/go-1.9/src/net/http/server.go:2323 +0xe2 github.com/tendermint/tendermint/rpc/lib/server.StartHTTPServer.func1() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:35 +0xb3 ```
7 years ago
10 years ago
abci: localClient improvements & bugfixes & pubsub Unsubscribe issues (#2748) * use READ lock/unlock in ConsensusState#GetLastHeight Refs #2721 * do not use defers when there's no need * fix peer formatting (output its address instead of the pointer) ``` [54310]: E[11-02|11:59:39.851] Connection failed @ sendRoutine module=p2p peer=0xb78f00 conn=MConn{74.207.236.148:26656} err="pong timeout" ``` https://github.com/tendermint/tendermint/issues/2721#issuecomment-435326581 * panic if peer has no state https://github.com/tendermint/tendermint/issues/2721#issuecomment-435347165 It's confusing that sometimes we check if peer has a state, but most of the times we expect it to be there 1. https://github.com/tendermint/tendermint/blob/add79700b5fe84417538202b6c927c8cc5383672/mempool/reactor.go#L138 2. https://github.com/tendermint/tendermint/blob/add79700b5fe84417538202b6c927c8cc5383672/rpc/core/consensus.go#L196 (edited) I will change everything to always assume peer has a state and panic otherwise that should help identify issues earlier * abci/localclient: extend lock on app callback App callback should be protected by lock as well (note this was already done for InitChainAsync, why not for others???). Otherwise, when we execute the block, tx might come in and call the callback in the same time we're updating it in execBlockOnProxyApp => DATA RACE Fixes #2721 Consensus state is locked ``` goroutine 113333 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00180009c, 0xc0000c7e00) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*RWMutex).RLock(0xc001800090) /usr/local/go/src/sync/rwmutex.go:50 +0x4e github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).GetRoundState(0xc001800000, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:218 +0x46 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusReactor).queryMaj23Routine(0xc0017def80, 0x11104a0, 0xc0072488f0, 0xc007248 9c0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/reactor.go:735 +0x16d created by github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusReactor).AddPeer /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/reactor.go:172 +0x236 ``` because localClient is locked ``` goroutine 1899 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00003363c, 0xc0000cb500) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*Mutex).Lock(0xc000033638) /usr/local/go/src/sync/mutex.go:134 +0xff github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client.(*localClient).SetResponseCallback(0xc0001fb560, 0xc007868540) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client/local_client.go:32 +0x33 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy.(*appConnConsensus).SetResponseCallback(0xc00002f750, 0xc007868540) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy/app_conn.go:57 +0x40 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state.execBlockOnProxyApp(0x1104e20, 0xc002ca0ba0, 0x11092a0, 0xc00002f750, 0xc0001fe960, 0xc000bfc660, 0x110cfe0, 0xc000090330, 0xc9d12, 0xc000d9d5a0, ...) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state/execution.go:230 +0x1fd github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state.(*BlockExecutor).ApplyBlock(0xc002c2a230, 0x7, 0x0, 0xc000eae880, 0x6, 0xc002e52c60, 0x16, 0x1f927, 0xc9d12, 0xc000d9d5a0, ...) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state/execution.go:96 +0x142 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).finalizeCommit(0xc001800000, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1339 +0xa3e github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).tryFinalizeCommit(0xc001800000, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1270 +0x451 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit.func1(0xc001800000, 0x0, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1218 +0x90 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit(0xc001800000, 0x1f928, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1247 +0x6b8 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).addVote(0xc001800000, 0xc003d8dea0, 0xc000cf4cc0, 0x28, 0xf1, 0xc003bc7ad0, 0xc003bc7b10) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1659 +0xbad github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).tryAddVote(0xc001800000, 0xc003d8dea0, 0xc000cf4cc0, 0x28, 0xf1, 0xf1, 0xf1) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1517 +0x59 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).handleMsg(0xc001800000, 0xd98200, 0xc0070dbed0, 0xc000cf4cc0, 0x28) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:660 +0x64b github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine(0xc001800000, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:617 +0x670 created by github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).OnStart /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:311 +0x132 ``` tx comes in and CheckTx is executed right when we execute the block ``` goroutine 111044 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00003363c, 0x0) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*Mutex).Lock(0xc000033638) /usr/local/go/src/sync/mutex.go:134 +0xff github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client.(*localClient).CheckTxAsync(0xc0001fb0e0, 0xc002d94500, 0x13f, 0x280, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client/local_client.go:85 +0x47 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy.(*appConnMempool).CheckTxAsync(0xc00002f720, 0xc002d94500, 0x13f, 0x280, 0x1) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy/app_conn.go:114 +0x51 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/mempool.(*Mempool).CheckTx(0xc002d3a320, 0xc002d94500, 0x13f, 0x280, 0xc0072355f0, 0x0, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/mempool/mempool.go:316 +0x17b github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/core.BroadcastTxSync(0xc002d94500, 0x13f, 0x280, 0x0, 0x0, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/core/mempool.go:93 +0xb8 reflect.Value.call(0xd85560, 0x10326c0, 0x13, 0xec7b8b, 0x4, 0xc00663f180, 0x1, 0x1, 0xc00663f180, 0xc00663f188, ...) /usr/local/go/src/reflect/value.go:447 +0x449 reflect.Value.Call(0xd85560, 0x10326c0, 0x13, 0xc00663f180, 0x1, 0x1, 0x0, 0x0, 0xc005cc9344) /usr/local/go/src/reflect/value.go:308 +0xa4 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.makeHTTPHandler.func2(0x1102060, 0xc00663f100, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/handlers.go:269 +0x188 net/http.HandlerFunc.ServeHTTP(0xc002c81f20, 0x1102060, 0xc00663f100, 0xc0082d7900) /usr/local/go/src/net/http/server.go:1964 +0x44 net/http.(*ServeMux).ServeHTTP(0xc002c81b60, 0x1102060, 0xc00663f100, 0xc0082d7900) /usr/local/go/src/net/http/server.go:2361 +0x127 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.maxBytesHandler.ServeHTTP(0x10f8a40, 0xc002c81b60, 0xf4240, 0x1102060, 0xc00663f100, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:219 +0xcf github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.RecoverAndLogHandler.func1(0x1103220, 0xc00121e620, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:192 +0x394 net/http.HandlerFunc.ServeHTTP(0xc002c06ea0, 0x1103220, 0xc00121e620, 0xc0082d7900) /usr/local/go/src/net/http/server.go:1964 +0x44 net/http.serverHandler.ServeHTTP(0xc001a1aa90, 0x1103220, 0xc00121e620, 0xc0082d7900) /usr/local/go/src/net/http/server.go:2741 +0xab net/http.(*conn).serve(0xc00785a3c0, 0x11041a0, 0xc000f844c0) /usr/local/go/src/net/http/server.go:1847 +0x646 created by net/http.(*Server).Serve /usr/local/go/src/net/http/server.go:2851 +0x2f5 ``` * consensus: use read lock in Receive#VoteMessage * use defer to unlock mutex because application might panic * use defer in every method of the localClient * add a changelog entry * drain channels before Unsubscribe(All) Read https://github.com/tendermint/tendermint/blob/55362ed76630f3e1ebec159a598f6a9fb5892cb1/libs/pubsub/pubsub.go#L13 for the detailed explanation of the issue. We'll need to fix it someday. Make sure to keep an eye on https://github.com/tendermint/tendermint/blob/master/docs/architecture/adr-033-pubsub.md * retry instead of panic when peer has no state in reactors other than consensus in /dump_consensus_state RPC endpoint, skip a peer with no state * rpc/core/mempool: simplify error messages * rpc/core/mempool: use time.After instead of timer also, do not log DeliverTx result (to be consistent with other memthods) * unlock before calling the callback in reqRes#SetCallback
6 years ago
10 years ago
fix data race Closes #1442 ``` WARNING: DATA RACE Write at 0x00c4209de7c8 by goroutine 23: github.com/tendermint/tendermint/types.(*Block).fillHeader() /home/vagrant/go/src/github.com/tendermint/tendermint/types/block.go:88 +0x157 github.com/tendermint/tendermint/types.(*Block).Hash() /home/vagrant/go/src/github.com/tendermint/tendermint/types/block.go:104 +0x121 github.com/tendermint/tendermint/types.(*Block).HashesTo() /home/vagrant/go/src/github.com/tendermint/tendermint/types/block.go:135 +0x4f github.com/tendermint/tendermint/consensus.(*ConsensusState).enterPrecommit() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:1037 +0x182d github.com/tendermint/tendermint/consensus.(*ConsensusState).addVote() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:1425 +0x1a6c github.com/tendermint/tendermint/consensus.(*ConsensusState).tryAddVote() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:1318 +0x77 github.com/tendermint/tendermint/consensus.(*ConsensusState).handleMsg() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:581 +0x7a9 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:539 +0x6c3 Previous read at 0x00c4209de7c8 by goroutine 47: github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*HexBytes).MarshalJSON() <autogenerated>:1 +0x52 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.invokeMarshalJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:433 +0x88 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:82 +0x8d2 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).MarshalJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/amino.go:296 +0x182 github.com/tendermint/tendermint/rpc/lib/types.NewRPCSuccessResponse() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/types/types.go:100 +0x12c github.com/tendermint/tendermint/rpc/lib/server.makeJSONRPCHandler.func1() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/server/handlers.go:152 +0xab7 net/http.HandlerFunc.ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:1918 +0x51 net/http.(*ServeMux).ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:2254 +0xa2 github.com/tendermint/tendermint/rpc/lib/server.RecoverAndLogHandler.func1() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:138 +0x4fa net/http.HandlerFunc.ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:1918 +0x51 net/http.serverHandler.ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:2619 +0xbc net/http.(*conn).serve() /usr/lib/go-1.9/src/net/http/server.go:1801 +0x83b Goroutine 23 (running) created at: github.com/tendermint/tendermint/consensus.(*ConsensusState).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:250 +0x35b github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/consensus.(*ConsensusReactor).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/reactor.go:69 +0x1b4 github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/consensus.(*ConsensusReactor).Start() <autogenerated>:1 +0x43 github.com/tendermint/tendermint/p2p.(*Switch).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/p2p/switch.go:177 +0x124 github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/node.(*Node).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/node/node.go:416 +0xa1b github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/rpc/test.StartTendermint() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/test/helpers.go:100 +0x5b github.com/tendermint/tendermint/rpc/client_test.TestMain() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/client/main_test.go:17 +0x4c main.main() github.com/tendermint/tendermint/rpc/client/_test/_testmain.go:76 +0x1cd Goroutine 47 (running) created at: net/http.(*Server).Serve() /usr/lib/go-1.9/src/net/http/server.go:2720 +0x37c net/http.Serve() /usr/lib/go-1.9/src/net/http/server.go:2323 +0xe2 github.com/tendermint/tendermint/rpc/lib/server.StartHTTPServer.func1() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:35 +0xb3 ```
7 years ago
fix data race Closes #1442 ``` WARNING: DATA RACE Write at 0x00c4209de7c8 by goroutine 23: github.com/tendermint/tendermint/types.(*Block).fillHeader() /home/vagrant/go/src/github.com/tendermint/tendermint/types/block.go:88 +0x157 github.com/tendermint/tendermint/types.(*Block).Hash() /home/vagrant/go/src/github.com/tendermint/tendermint/types/block.go:104 +0x121 github.com/tendermint/tendermint/types.(*Block).HashesTo() /home/vagrant/go/src/github.com/tendermint/tendermint/types/block.go:135 +0x4f github.com/tendermint/tendermint/consensus.(*ConsensusState).enterPrecommit() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:1037 +0x182d github.com/tendermint/tendermint/consensus.(*ConsensusState).addVote() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:1425 +0x1a6c github.com/tendermint/tendermint/consensus.(*ConsensusState).tryAddVote() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:1318 +0x77 github.com/tendermint/tendermint/consensus.(*ConsensusState).handleMsg() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:581 +0x7a9 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:539 +0x6c3 Previous read at 0x00c4209de7c8 by goroutine 47: github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*HexBytes).MarshalJSON() <autogenerated>:1 +0x52 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.invokeMarshalJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:433 +0x88 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:82 +0x8d2 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSONStruct() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:348 +0x539 github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec)._encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:119 +0x83f github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).encodeReflectJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/json-encode.go:50 +0x10e github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino.(*Codec).MarshalJSON() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/go-amino/amino.go:296 +0x182 github.com/tendermint/tendermint/rpc/lib/types.NewRPCSuccessResponse() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/types/types.go:100 +0x12c github.com/tendermint/tendermint/rpc/lib/server.makeJSONRPCHandler.func1() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/server/handlers.go:152 +0xab7 net/http.HandlerFunc.ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:1918 +0x51 net/http.(*ServeMux).ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:2254 +0xa2 github.com/tendermint/tendermint/rpc/lib/server.RecoverAndLogHandler.func1() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:138 +0x4fa net/http.HandlerFunc.ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:1918 +0x51 net/http.serverHandler.ServeHTTP() /usr/lib/go-1.9/src/net/http/server.go:2619 +0xbc net/http.(*conn).serve() /usr/lib/go-1.9/src/net/http/server.go:1801 +0x83b Goroutine 23 (running) created at: github.com/tendermint/tendermint/consensus.(*ConsensusState).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/state.go:250 +0x35b github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/consensus.(*ConsensusReactor).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/consensus/reactor.go:69 +0x1b4 github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/consensus.(*ConsensusReactor).Start() <autogenerated>:1 +0x43 github.com/tendermint/tendermint/p2p.(*Switch).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/p2p/switch.go:177 +0x124 github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/node.(*Node).OnStart() /home/vagrant/go/src/github.com/tendermint/tendermint/node/node.go:416 +0xa1b github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common.(*BaseService).Start() /home/vagrant/go/src/github.com/tendermint/tendermint/vendor/github.com/tendermint/tmlibs/common/service.go:130 +0x5fc github.com/tendermint/tendermint/rpc/test.StartTendermint() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/test/helpers.go:100 +0x5b github.com/tendermint/tendermint/rpc/client_test.TestMain() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/client/main_test.go:17 +0x4c main.main() github.com/tendermint/tendermint/rpc/client/_test/_testmain.go:76 +0x1cd Goroutine 47 (running) created at: net/http.(*Server).Serve() /usr/lib/go-1.9/src/net/http/server.go:2720 +0x37c net/http.Serve() /usr/lib/go-1.9/src/net/http/server.go:2323 +0xe2 github.com/tendermint/tendermint/rpc/lib/server.StartHTTPServer.func1() /home/vagrant/go/src/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:35 +0xb3 ```
7 years ago
abci: localClient improvements & bugfixes & pubsub Unsubscribe issues (#2748) * use READ lock/unlock in ConsensusState#GetLastHeight Refs #2721 * do not use defers when there's no need * fix peer formatting (output its address instead of the pointer) ``` [54310]: E[11-02|11:59:39.851] Connection failed @ sendRoutine module=p2p peer=0xb78f00 conn=MConn{74.207.236.148:26656} err="pong timeout" ``` https://github.com/tendermint/tendermint/issues/2721#issuecomment-435326581 * panic if peer has no state https://github.com/tendermint/tendermint/issues/2721#issuecomment-435347165 It's confusing that sometimes we check if peer has a state, but most of the times we expect it to be there 1. https://github.com/tendermint/tendermint/blob/add79700b5fe84417538202b6c927c8cc5383672/mempool/reactor.go#L138 2. https://github.com/tendermint/tendermint/blob/add79700b5fe84417538202b6c927c8cc5383672/rpc/core/consensus.go#L196 (edited) I will change everything to always assume peer has a state and panic otherwise that should help identify issues earlier * abci/localclient: extend lock on app callback App callback should be protected by lock as well (note this was already done for InitChainAsync, why not for others???). Otherwise, when we execute the block, tx might come in and call the callback in the same time we're updating it in execBlockOnProxyApp => DATA RACE Fixes #2721 Consensus state is locked ``` goroutine 113333 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00180009c, 0xc0000c7e00) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*RWMutex).RLock(0xc001800090) /usr/local/go/src/sync/rwmutex.go:50 +0x4e github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).GetRoundState(0xc001800000, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:218 +0x46 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusReactor).queryMaj23Routine(0xc0017def80, 0x11104a0, 0xc0072488f0, 0xc007248 9c0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/reactor.go:735 +0x16d created by github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusReactor).AddPeer /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/reactor.go:172 +0x236 ``` because localClient is locked ``` goroutine 1899 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00003363c, 0xc0000cb500) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*Mutex).Lock(0xc000033638) /usr/local/go/src/sync/mutex.go:134 +0xff github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client.(*localClient).SetResponseCallback(0xc0001fb560, 0xc007868540) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client/local_client.go:32 +0x33 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy.(*appConnConsensus).SetResponseCallback(0xc00002f750, 0xc007868540) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy/app_conn.go:57 +0x40 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state.execBlockOnProxyApp(0x1104e20, 0xc002ca0ba0, 0x11092a0, 0xc00002f750, 0xc0001fe960, 0xc000bfc660, 0x110cfe0, 0xc000090330, 0xc9d12, 0xc000d9d5a0, ...) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state/execution.go:230 +0x1fd github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state.(*BlockExecutor).ApplyBlock(0xc002c2a230, 0x7, 0x0, 0xc000eae880, 0x6, 0xc002e52c60, 0x16, 0x1f927, 0xc9d12, 0xc000d9d5a0, ...) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state/execution.go:96 +0x142 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).finalizeCommit(0xc001800000, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1339 +0xa3e github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).tryFinalizeCommit(0xc001800000, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1270 +0x451 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit.func1(0xc001800000, 0x0, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1218 +0x90 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit(0xc001800000, 0x1f928, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1247 +0x6b8 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).addVote(0xc001800000, 0xc003d8dea0, 0xc000cf4cc0, 0x28, 0xf1, 0xc003bc7ad0, 0xc003bc7b10) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1659 +0xbad github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).tryAddVote(0xc001800000, 0xc003d8dea0, 0xc000cf4cc0, 0x28, 0xf1, 0xf1, 0xf1) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1517 +0x59 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).handleMsg(0xc001800000, 0xd98200, 0xc0070dbed0, 0xc000cf4cc0, 0x28) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:660 +0x64b github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine(0xc001800000, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:617 +0x670 created by github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).OnStart /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:311 +0x132 ``` tx comes in and CheckTx is executed right when we execute the block ``` goroutine 111044 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00003363c, 0x0) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*Mutex).Lock(0xc000033638) /usr/local/go/src/sync/mutex.go:134 +0xff github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client.(*localClient).CheckTxAsync(0xc0001fb0e0, 0xc002d94500, 0x13f, 0x280, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client/local_client.go:85 +0x47 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy.(*appConnMempool).CheckTxAsync(0xc00002f720, 0xc002d94500, 0x13f, 0x280, 0x1) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy/app_conn.go:114 +0x51 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/mempool.(*Mempool).CheckTx(0xc002d3a320, 0xc002d94500, 0x13f, 0x280, 0xc0072355f0, 0x0, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/mempool/mempool.go:316 +0x17b github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/core.BroadcastTxSync(0xc002d94500, 0x13f, 0x280, 0x0, 0x0, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/core/mempool.go:93 +0xb8 reflect.Value.call(0xd85560, 0x10326c0, 0x13, 0xec7b8b, 0x4, 0xc00663f180, 0x1, 0x1, 0xc00663f180, 0xc00663f188, ...) /usr/local/go/src/reflect/value.go:447 +0x449 reflect.Value.Call(0xd85560, 0x10326c0, 0x13, 0xc00663f180, 0x1, 0x1, 0x0, 0x0, 0xc005cc9344) /usr/local/go/src/reflect/value.go:308 +0xa4 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.makeHTTPHandler.func2(0x1102060, 0xc00663f100, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/handlers.go:269 +0x188 net/http.HandlerFunc.ServeHTTP(0xc002c81f20, 0x1102060, 0xc00663f100, 0xc0082d7900) /usr/local/go/src/net/http/server.go:1964 +0x44 net/http.(*ServeMux).ServeHTTP(0xc002c81b60, 0x1102060, 0xc00663f100, 0xc0082d7900) /usr/local/go/src/net/http/server.go:2361 +0x127 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.maxBytesHandler.ServeHTTP(0x10f8a40, 0xc002c81b60, 0xf4240, 0x1102060, 0xc00663f100, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:219 +0xcf github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.RecoverAndLogHandler.func1(0x1103220, 0xc00121e620, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:192 +0x394 net/http.HandlerFunc.ServeHTTP(0xc002c06ea0, 0x1103220, 0xc00121e620, 0xc0082d7900) /usr/local/go/src/net/http/server.go:1964 +0x44 net/http.serverHandler.ServeHTTP(0xc001a1aa90, 0x1103220, 0xc00121e620, 0xc0082d7900) /usr/local/go/src/net/http/server.go:2741 +0xab net/http.(*conn).serve(0xc00785a3c0, 0x11041a0, 0xc000f844c0) /usr/local/go/src/net/http/server.go:1847 +0x646 created by net/http.(*Server).Serve /usr/local/go/src/net/http/server.go:2851 +0x2f5 ``` * consensus: use read lock in Receive#VoteMessage * use defer to unlock mutex because application might panic * use defer in every method of the localClient * add a changelog entry * drain channels before Unsubscribe(All) Read https://github.com/tendermint/tendermint/blob/55362ed76630f3e1ebec159a598f6a9fb5892cb1/libs/pubsub/pubsub.go#L13 for the detailed explanation of the issue. We'll need to fix it someday. Make sure to keep an eye on https://github.com/tendermint/tendermint/blob/master/docs/architecture/adr-033-pubsub.md * retry instead of panic when peer has no state in reactors other than consensus in /dump_consensus_state RPC endpoint, skip a peer with no state * rpc/core/mempool: simplify error messages * rpc/core/mempool: use time.After instead of timer also, do not log DeliverTx result (to be consistent with other memthods) * unlock before calling the callback in reqRes#SetCallback
6 years ago
abci: localClient improvements & bugfixes & pubsub Unsubscribe issues (#2748) * use READ lock/unlock in ConsensusState#GetLastHeight Refs #2721 * do not use defers when there's no need * fix peer formatting (output its address instead of the pointer) ``` [54310]: E[11-02|11:59:39.851] Connection failed @ sendRoutine module=p2p peer=0xb78f00 conn=MConn{74.207.236.148:26656} err="pong timeout" ``` https://github.com/tendermint/tendermint/issues/2721#issuecomment-435326581 * panic if peer has no state https://github.com/tendermint/tendermint/issues/2721#issuecomment-435347165 It's confusing that sometimes we check if peer has a state, but most of the times we expect it to be there 1. https://github.com/tendermint/tendermint/blob/add79700b5fe84417538202b6c927c8cc5383672/mempool/reactor.go#L138 2. https://github.com/tendermint/tendermint/blob/add79700b5fe84417538202b6c927c8cc5383672/rpc/core/consensus.go#L196 (edited) I will change everything to always assume peer has a state and panic otherwise that should help identify issues earlier * abci/localclient: extend lock on app callback App callback should be protected by lock as well (note this was already done for InitChainAsync, why not for others???). Otherwise, when we execute the block, tx might come in and call the callback in the same time we're updating it in execBlockOnProxyApp => DATA RACE Fixes #2721 Consensus state is locked ``` goroutine 113333 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00180009c, 0xc0000c7e00) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*RWMutex).RLock(0xc001800090) /usr/local/go/src/sync/rwmutex.go:50 +0x4e github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).GetRoundState(0xc001800000, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:218 +0x46 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusReactor).queryMaj23Routine(0xc0017def80, 0x11104a0, 0xc0072488f0, 0xc007248 9c0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/reactor.go:735 +0x16d created by github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusReactor).AddPeer /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/reactor.go:172 +0x236 ``` because localClient is locked ``` goroutine 1899 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00003363c, 0xc0000cb500) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*Mutex).Lock(0xc000033638) /usr/local/go/src/sync/mutex.go:134 +0xff github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client.(*localClient).SetResponseCallback(0xc0001fb560, 0xc007868540) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client/local_client.go:32 +0x33 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy.(*appConnConsensus).SetResponseCallback(0xc00002f750, 0xc007868540) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy/app_conn.go:57 +0x40 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state.execBlockOnProxyApp(0x1104e20, 0xc002ca0ba0, 0x11092a0, 0xc00002f750, 0xc0001fe960, 0xc000bfc660, 0x110cfe0, 0xc000090330, 0xc9d12, 0xc000d9d5a0, ...) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state/execution.go:230 +0x1fd github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state.(*BlockExecutor).ApplyBlock(0xc002c2a230, 0x7, 0x0, 0xc000eae880, 0x6, 0xc002e52c60, 0x16, 0x1f927, 0xc9d12, 0xc000d9d5a0, ...) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/state/execution.go:96 +0x142 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).finalizeCommit(0xc001800000, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1339 +0xa3e github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).tryFinalizeCommit(0xc001800000, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1270 +0x451 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit.func1(0xc001800000, 0x0, 0x1f928) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1218 +0x90 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit(0xc001800000, 0x1f928, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1247 +0x6b8 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).addVote(0xc001800000, 0xc003d8dea0, 0xc000cf4cc0, 0x28, 0xf1, 0xc003bc7ad0, 0xc003bc7b10) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1659 +0xbad github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).tryAddVote(0xc001800000, 0xc003d8dea0, 0xc000cf4cc0, 0x28, 0xf1, 0xf1, 0xf1) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:1517 +0x59 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).handleMsg(0xc001800000, 0xd98200, 0xc0070dbed0, 0xc000cf4cc0, 0x28) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:660 +0x64b github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine(0xc001800000, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:617 +0x670 created by github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus.(*ConsensusState).OnStart /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/consensus/state.go:311 +0x132 ``` tx comes in and CheckTx is executed right when we execute the block ``` goroutine 111044 [semacquire, 309 minutes]: sync.runtime_SemacquireMutex(0xc00003363c, 0x0) /usr/local/go/src/runtime/sema.go:71 +0x3d sync.(*Mutex).Lock(0xc000033638) /usr/local/go/src/sync/mutex.go:134 +0xff github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client.(*localClient).CheckTxAsync(0xc0001fb0e0, 0xc002d94500, 0x13f, 0x280, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/abci/client/local_client.go:85 +0x47 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy.(*appConnMempool).CheckTxAsync(0xc00002f720, 0xc002d94500, 0x13f, 0x280, 0x1) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/proxy/app_conn.go:114 +0x51 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/mempool.(*Mempool).CheckTx(0xc002d3a320, 0xc002d94500, 0x13f, 0x280, 0xc0072355f0, 0x0, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/mempool/mempool.go:316 +0x17b github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/core.BroadcastTxSync(0xc002d94500, 0x13f, 0x280, 0x0, 0x0, 0x0) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/core/mempool.go:93 +0xb8 reflect.Value.call(0xd85560, 0x10326c0, 0x13, 0xec7b8b, 0x4, 0xc00663f180, 0x1, 0x1, 0xc00663f180, 0xc00663f188, ...) /usr/local/go/src/reflect/value.go:447 +0x449 reflect.Value.Call(0xd85560, 0x10326c0, 0x13, 0xc00663f180, 0x1, 0x1, 0x0, 0x0, 0xc005cc9344) /usr/local/go/src/reflect/value.go:308 +0xa4 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.makeHTTPHandler.func2(0x1102060, 0xc00663f100, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/handlers.go:269 +0x188 net/http.HandlerFunc.ServeHTTP(0xc002c81f20, 0x1102060, 0xc00663f100, 0xc0082d7900) /usr/local/go/src/net/http/server.go:1964 +0x44 net/http.(*ServeMux).ServeHTTP(0xc002c81b60, 0x1102060, 0xc00663f100, 0xc0082d7900) /usr/local/go/src/net/http/server.go:2361 +0x127 github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.maxBytesHandler.ServeHTTP(0x10f8a40, 0xc002c81b60, 0xf4240, 0x1102060, 0xc00663f100, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:219 +0xcf github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server.RecoverAndLogHandler.func1(0x1103220, 0xc00121e620, 0xc0082d7900) /root/go/src/github.com/MinterTeam/minter-go-node/vendor/github.com/tendermint/tendermint/rpc/lib/server/http_server.go:192 +0x394 net/http.HandlerFunc.ServeHTTP(0xc002c06ea0, 0x1103220, 0xc00121e620, 0xc0082d7900) /usr/local/go/src/net/http/server.go:1964 +0x44 net/http.serverHandler.ServeHTTP(0xc001a1aa90, 0x1103220, 0xc00121e620, 0xc0082d7900) /usr/local/go/src/net/http/server.go:2741 +0xab net/http.(*conn).serve(0xc00785a3c0, 0x11041a0, 0xc000f844c0) /usr/local/go/src/net/http/server.go:1847 +0x646 created by net/http.(*Server).Serve /usr/local/go/src/net/http/server.go:2851 +0x2f5 ``` * consensus: use read lock in Receive#VoteMessage * use defer to unlock mutex because application might panic * use defer in every method of the localClient * add a changelog entry * drain channels before Unsubscribe(All) Read https://github.com/tendermint/tendermint/blob/55362ed76630f3e1ebec159a598f6a9fb5892cb1/libs/pubsub/pubsub.go#L13 for the detailed explanation of the issue. We'll need to fix it someday. Make sure to keep an eye on https://github.com/tendermint/tendermint/blob/master/docs/architecture/adr-033-pubsub.md * retry instead of panic when peer has no state in reactors other than consensus in /dump_consensus_state RPC endpoint, skip a peer with no state * rpc/core/mempool: simplify error messages * rpc/core/mempool: use time.After instead of timer also, do not log DeliverTx result (to be consistent with other memthods) * unlock before calling the callback in reqRes#SetCallback
6 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
WAL: better errors and new fail point (#3246) * privval: more info in errors * wal: change Debug logs to Info * wal: log and return error on corrupted wal instead of panicing * fail: Exit right away instead of sending interupt * consensus: FAIL before handling our own vote allows to replicate #3089: - run using `FAIL_TEST_INDEX=0` - delete some bytes from the end of the WAL - start normally Results in logs like: ``` I[2019-02-03|18:12:58.225] Searching for height module=consensus wal=/Users/ethanbuchman/.tendermint/data/cs.wal/wal height=1 min=0 max=0 E[2019-02-03|18:12:58.225] Error on catchup replay. Proceeding to start ConsensusState anyway module=consensus err="failed to read data: EOF" I[2019-02-03|18:12:58.225] Started node module=main nodeInfo="{ProtocolVersion:{P2P:6 Block:9 App:1} ID_:35e87e93f2e31f305b65a5517fd2102331b56002 ListenAddr:tcp://0.0.0.0:26656 Network:test-chain-J8JvJH Version:0.29.1 Channels:4020212223303800 Moniker:Ethans-MacBook-Pro.local Other:{TxIndex:on RPCAddress:tcp://0.0.0.0:26657}}" E[2019-02-03|18:12:58.226] Couldn't connect to any seeds module=p2p I[2019-02-03|18:12:59.229] Timed out module=consensus dur=998.568ms height=1 round=0 step=RoundStepNewHeight I[2019-02-03|18:12:59.230] enterNewRound(1/0). Current: 1/0/RoundStepNewHeight module=consensus height=1 round=0 I[2019-02-03|18:12:59.230] enterPropose(1/0). Current: 1/0/RoundStepNewRound module=consensus height=1 round=0 I[2019-02-03|18:12:59.230] enterPropose: Our turn to propose module=consensus height=1 round=0 proposer=AD278B7767B05D7FBEB76207024C650988FA77D5 privValidator="PrivValidator{AD278B7767B05D7FBEB76207024C650988FA77D5 LH:1, LR:0, LS:2}" E[2019-02-03|18:12:59.230] enterPropose: Error signing proposal module=consensus height=1 round=0 err="Error signing proposal: Step regression at height 1 round 0. Got 1, last step 2" I[2019-02-03|18:13:02.233] Timed out module=consensus dur=3s height=1 round=0 step=RoundStepPropose I[2019-02-03|18:13:02.233] enterPrevote(1/0). Current: 1/0/RoundStepPropose module=consensus I[2019-02-03|18:13:02.233] enterPrevote: ProposalBlock is nil module=consensus height=1 round=0 E[2019-02-03|18:13:02.234] Error signing vote module=consensus height=1 round=0 vote="Vote{0:AD278B7767B0 1/00/1(Prevote) 000000000000 000000000000 @ 2019-02-04T02:13:02.233897Z}" err="Error signing vote: Conflicting data" ``` Notice the EOF, the step regression, and the conflicting data. * wal: change errors to be DataCorruptionError * exit on corrupt WAL * fix log * fix new line
6 years ago
10 years ago
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
9 years ago
9 years ago
9 years ago
8 years ago
cs: check for SkipTimeoutCommit or wait timeout in handleTxsAvailable (#3928) * cs: check for SkipTimeoutCommit or wait timeout in handleTxsAvailable Previously, if create_empty_blocks was set to false, TM sometimes could create 2 consecutive blocks without actually waiting for timeoutCommit (1 sec. by default). ``` I[2019-08-29|07:32:43.874] Executed block module=state height=47 validTxs=10 invalidTxs=0 I[2019-08-29|07:32:43.876] Committed state module=state height=47 txs=10 appHash=F88C010000000000 I[2019-08-29|07:32:44.885] Executed block module=state height=48 validTxs=2 invalidTxs=0 I[2019-08-29|07:32:44.887] Committed state module=state height=48 txs=2 appHash=FC8C010000000000 I[2019-08-29|07:32:44.908] Executed block module=state height=49 validTxs=8 invalidTxs=0 I[2019-08-29|07:32:44.909] Committed state module=state height=49 txs=8 appHash=8C8D010000000000 I[2019-08-29|07:32:45.886] Executed block module=state height=50 validTxs=2 invalidTxs=0 I[2019-08-29|07:32:45.895] Committed state module=state height=50 txs=2 appHash=908D010000000000 I[2019-08-29|07:32:45.908] Executed block module=state height=51 validTxs=8 invalidTxs=0 I[2019-08-29|07:32:45.909] Committed state module=state height=51 txs=8 appHash=A08D010000000000 ``` This commit fixes that by adding a check to handleTxsAvailable. Fixes #3908 * update changelog * schedule timeoutCommit if StartTime is in the future or SkipTimeoutCommit=true && we DON'T have all the votes * fix TestReactorCreatesBlockWhenEmptyBlocksFalse by checking if we have LastCommit or not * address Ethan's comments
5 years ago
cs: reset triggered timeout precommit (#3310) * Reset TriggeredTimeoutPrecommit as part of updateToState * Add failing test and fix * fix DATA RACE in TestResetTimeoutPrecommitUponNewHeight ``` WARNING: DATA RACE Read at 0x00c001691d28 by goroutine 691: github.com/tendermint/tendermint/consensus.decideProposal() /go/src/github.com/tendermint/tendermint/consensus/common_test.go:133 +0x121 github.com/tendermint/tendermint/consensus.TestResetTimeoutPrecommitUponNewHeight() /go/src/github.com/tendermint/tendermint/consensus/state_test.go:1389 +0x958 testing.tRunner() /usr/local/go/src/testing/testing.go:827 +0x162 Previous write at 0x00c001691d28 by goroutine 931: github.com/tendermint/tendermint/consensus.(*ConsensusState).updateToState() /go/src/github.com/tendermint/tendermint/consensus/state.go:562 +0x5b2 github.com/tendermint/tendermint/consensus.(*ConsensusState).finalizeCommit() /go/src/github.com/tendermint/tendermint/consensus/state.go:1340 +0x141e github.com/tendermint/tendermint/consensus.(*ConsensusState).tryFinalizeCommit() /go/src/github.com/tendermint/tendermint/consensus/state.go:1255 +0x66e github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit.func1() /go/src/github.com/tendermint/tendermint/consensus/state.go:1201 +0x135 github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit() /go/src/github.com/tendermint/tendermint/consensus/state.go:1232 +0x94b github.com/tendermint/tendermint/consensus.(*ConsensusState).addVote() /go/src/github.com/tendermint/tendermint/consensus/state.go:1657 +0x132e github.com/tendermint/tendermint/consensus.(*ConsensusState).tryAddVote() /go/src/github.com/tendermint/tendermint/consensus/state.go:1503 +0x8f github.com/tendermint/tendermint/consensus.(*ConsensusState).handleMsg() /go/src/github.com/tendermint/tendermint/consensus/state.go:694 +0xa1e github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:642 +0x948 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:642 +0x948 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:642 +0x948 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:655 +0x7dd github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:642 +0x948 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:655 +0x7dd Goroutine 691 (running) created at: testing.(*T).Run() /usr/local/go/src/testing/testing.go:878 +0x659 testing.runTests.func1() /usr/local/go/src/testing/testing.go:1119 +0xa8 testing.tRunner() /usr/local/go/src/testing/testing.go:827 +0x162 testing.runTests() testing.(*M).Run() /usr/local/go/src/testing/testing.go:1034 +0x2ee main.main() _testmain.go:216 +0x332 ``` * fix another DATA RACE by locking consensus ``` WARNING: DATA RACE Read at 0x00c009b835a8 by goroutine 871: github.com/tendermint/tendermint/consensus.(*ConsensusState).createProposalBlock() /go/src/github.com/tendermint/tendermint/consensus/state.go:955 +0x7c github.com/tendermint/tendermint/consensus.decideProposal() /go/src/github.com/tendermint/tendermint/consensus/common_test.go:127 +0x53 github.com/tendermint/tendermint/consensus.TestResetTimeoutPrecommitUponNewHeight() /go/src/github.com/tendermint/tendermint/consensus/state_test.go:1389 +0x958 testing.tRunner() /usr/local/go/src/testing/testing.go:827 +0x162 Previous write at 0x00c009b835a8 by goroutine 931: github.com/tendermint/tendermint/consensus.(*ConsensusState).updateHeight() /go/src/github.com/tendermint/tendermint/consensus/state.go:446 +0xb7 github.com/tendermint/tendermint/consensus.(*ConsensusState).updateToState() /go/src/github.com/tendermint/tendermint/consensus/state.go:542 +0x22f github.com/tendermint/tendermint/consensus.(*ConsensusState).finalizeCommit() /go/src/github.com/tendermint/tendermint/consensus/state.go:1340 +0x141e github.com/tendermint/tendermint/consensus.(*ConsensusState).tryFinalizeCommit() /go/src/github.com/tendermint/tendermint/consensus/state.go:1255 +0x66e github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit.func1() /go/src/github.com/tendermint/tendermint/consensus/state.go:1201 +0x135 github.com/tendermint/tendermint/consensus.(*ConsensusState).enterCommit() /go/src/github.com/tendermint/tendermint/consensus/state.go:1232 +0x94b github.com/tendermint/tendermint/consensus.(*ConsensusState).addVote() /go/src/github.com/tendermint/tendermint/consensus/state.go:1657 +0x132e github.com/tendermint/tendermint/consensus.(*ConsensusState).tryAddVote() /go/src/github.com/tendermint/tendermint/consensus/state.go:1503 +0x8f github.com/tendermint/tendermint/consensus.(*ConsensusState).handleMsg() /go/src/github.com/tendermint/tendermint/consensus/state.go:694 +0xa1e github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:642 +0x948 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:642 +0x948 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:642 +0x948 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:655 +0x7dd github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:642 +0x948 github.com/tendermint/tendermint/consensus.(*ConsensusState).receiveRoutine() /go/src/github.com/tendermint/tendermint/consensus/state.go:655 +0x7dd ``` * Fix failing test * Delete profile.out * fix data races
6 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
WAL: better errors and new fail point (#3246) * privval: more info in errors * wal: change Debug logs to Info * wal: log and return error on corrupted wal instead of panicing * fail: Exit right away instead of sending interupt * consensus: FAIL before handling our own vote allows to replicate #3089: - run using `FAIL_TEST_INDEX=0` - delete some bytes from the end of the WAL - start normally Results in logs like: ``` I[2019-02-03|18:12:58.225] Searching for height module=consensus wal=/Users/ethanbuchman/.tendermint/data/cs.wal/wal height=1 min=0 max=0 E[2019-02-03|18:12:58.225] Error on catchup replay. Proceeding to start ConsensusState anyway module=consensus err="failed to read data: EOF" I[2019-02-03|18:12:58.225] Started node module=main nodeInfo="{ProtocolVersion:{P2P:6 Block:9 App:1} ID_:35e87e93f2e31f305b65a5517fd2102331b56002 ListenAddr:tcp://0.0.0.0:26656 Network:test-chain-J8JvJH Version:0.29.1 Channels:4020212223303800 Moniker:Ethans-MacBook-Pro.local Other:{TxIndex:on RPCAddress:tcp://0.0.0.0:26657}}" E[2019-02-03|18:12:58.226] Couldn't connect to any seeds module=p2p I[2019-02-03|18:12:59.229] Timed out module=consensus dur=998.568ms height=1 round=0 step=RoundStepNewHeight I[2019-02-03|18:12:59.230] enterNewRound(1/0). Current: 1/0/RoundStepNewHeight module=consensus height=1 round=0 I[2019-02-03|18:12:59.230] enterPropose(1/0). Current: 1/0/RoundStepNewRound module=consensus height=1 round=0 I[2019-02-03|18:12:59.230] enterPropose: Our turn to propose module=consensus height=1 round=0 proposer=AD278B7767B05D7FBEB76207024C650988FA77D5 privValidator="PrivValidator{AD278B7767B05D7FBEB76207024C650988FA77D5 LH:1, LR:0, LS:2}" E[2019-02-03|18:12:59.230] enterPropose: Error signing proposal module=consensus height=1 round=0 err="Error signing proposal: Step regression at height 1 round 0. Got 1, last step 2" I[2019-02-03|18:13:02.233] Timed out module=consensus dur=3s height=1 round=0 step=RoundStepPropose I[2019-02-03|18:13:02.233] enterPrevote(1/0). Current: 1/0/RoundStepPropose module=consensus I[2019-02-03|18:13:02.233] enterPrevote: ProposalBlock is nil module=consensus height=1 round=0 E[2019-02-03|18:13:02.234] Error signing vote module=consensus height=1 round=0 vote="Vote{0:AD278B7767B0 1/00/1(Prevote) 000000000000 000000000000 @ 2019-02-04T02:13:02.233897Z}" err="Error signing vote: Conflicting data" ``` Notice the EOF, the step regression, and the conflicting data. * wal: change errors to be DataCorruptionError * exit on corrupt WAL * fix log * fix new line
6 years ago
8 years ago
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
cs: check for SkipTimeoutCommit or wait timeout in handleTxsAvailable (#3928) * cs: check for SkipTimeoutCommit or wait timeout in handleTxsAvailable Previously, if create_empty_blocks was set to false, TM sometimes could create 2 consecutive blocks without actually waiting for timeoutCommit (1 sec. by default). ``` I[2019-08-29|07:32:43.874] Executed block module=state height=47 validTxs=10 invalidTxs=0 I[2019-08-29|07:32:43.876] Committed state module=state height=47 txs=10 appHash=F88C010000000000 I[2019-08-29|07:32:44.885] Executed block module=state height=48 validTxs=2 invalidTxs=0 I[2019-08-29|07:32:44.887] Committed state module=state height=48 txs=2 appHash=FC8C010000000000 I[2019-08-29|07:32:44.908] Executed block module=state height=49 validTxs=8 invalidTxs=0 I[2019-08-29|07:32:44.909] Committed state module=state height=49 txs=8 appHash=8C8D010000000000 I[2019-08-29|07:32:45.886] Executed block module=state height=50 validTxs=2 invalidTxs=0 I[2019-08-29|07:32:45.895] Committed state module=state height=50 txs=2 appHash=908D010000000000 I[2019-08-29|07:32:45.908] Executed block module=state height=51 validTxs=8 invalidTxs=0 I[2019-08-29|07:32:45.909] Committed state module=state height=51 txs=8 appHash=A08D010000000000 ``` This commit fixes that by adding a check to handleTxsAvailable. Fixes #3908 * update changelog * schedule timeoutCommit if StartTime is in the future or SkipTimeoutCommit=true && we DON'T have all the votes * fix TestReactorCreatesBlockWhenEmptyBlocksFalse by checking if we have LastCommit or not * address Ethan's comments
5 years ago
cs: check for SkipTimeoutCommit or wait timeout in handleTxsAvailable (#3928) * cs: check for SkipTimeoutCommit or wait timeout in handleTxsAvailable Previously, if create_empty_blocks was set to false, TM sometimes could create 2 consecutive blocks without actually waiting for timeoutCommit (1 sec. by default). ``` I[2019-08-29|07:32:43.874] Executed block module=state height=47 validTxs=10 invalidTxs=0 I[2019-08-29|07:32:43.876] Committed state module=state height=47 txs=10 appHash=F88C010000000000 I[2019-08-29|07:32:44.885] Executed block module=state height=48 validTxs=2 invalidTxs=0 I[2019-08-29|07:32:44.887] Committed state module=state height=48 txs=2 appHash=FC8C010000000000 I[2019-08-29|07:32:44.908] Executed block module=state height=49 validTxs=8 invalidTxs=0 I[2019-08-29|07:32:44.909] Committed state module=state height=49 txs=8 appHash=8C8D010000000000 I[2019-08-29|07:32:45.886] Executed block module=state height=50 validTxs=2 invalidTxs=0 I[2019-08-29|07:32:45.895] Committed state module=state height=50 txs=2 appHash=908D010000000000 I[2019-08-29|07:32:45.908] Executed block module=state height=51 validTxs=8 invalidTxs=0 I[2019-08-29|07:32:45.909] Committed state module=state height=51 txs=8 appHash=A08D010000000000 ``` This commit fixes that by adding a check to handleTxsAvailable. Fixes #3908 * update changelog * schedule timeoutCommit if StartTime is in the future or SkipTimeoutCommit=true && we DON'T have all the votes * fix TestReactorCreatesBlockWhenEmptyBlocksFalse by checking if we have LastCommit or not * address Ethan's comments
5 years ago
10 years ago
10 years ago
10 years ago
10 years ago
7 years ago
7 years ago
10 years ago
10 years ago
cs: sync WAL more frequently (#3300) As per #3043, this adds a ticker to sync the WAL every 2s while the WAL is running. * Flush WAL every 2s This adds a ticker that flushes the WAL every 2s while the WAL is running. This is related to #3043. * Fix spelling * Increase timeout to 2mins for slower build environments * Make WAL sync interval configurable * Add TODO to replace testChan with more comprehensive testBus * Remove extraneous debug statement * Remove testChan in favour of using system time As per https://github.com/tendermint/tendermint/pull/3300#discussion_r255886586, this removes the `testChan` WAL member and replaces the approach with a system time-oriented one. In this new approach, we keep track of the system time at which each flush and periodic flush successfully occurred. The naming of the various functions is also updated here to be more consistent with "flushing" as opposed to "sync'ing". * Update naming convention and ensure lock for timestamp update * Add Flush method as part of WAL interface Adds a `Flush` method as part of the WAL interface to enforce the idea that we can manually trigger a WAL flush from outside of the WAL. This is employed in the consensus state management to flush the WAL prior to signing votes/proposals, as per https://github.com/tendermint/tendermint/issues/3043#issuecomment-453853630 * Update CHANGELOG_PENDING * Remove mutex approach and replace with DI The dependency injection approach to dealing with testing concerns could allow similar effects to some kind of "testing bus"-based approach. This commit introduces an example of this, where instead of relying on (potentially fragile) timing of things between the code and the test, we inject code into the function under test that can signal the test through a channel. This allows us to avoid the `time.Sleep()`-based approach previously employed. * Update comment on WAL flushing during vote signing Co-Authored-By: thanethomson <connect@thanethomson.com> * Simplify flush interval definition Co-Authored-By: thanethomson <connect@thanethomson.com> * Expand commentary on WAL disk flushing Co-Authored-By: thanethomson <connect@thanethomson.com> * Add broken test to illustrate WAL sync test problem Removes test-related state (dependency injection code) from the WAL data structure and adds test code to illustrate the problem with using `WALGenerateNBlocks` and `wal.SearchForEndHeight` to test periodic sync'ing. * Fix test error messages * Use WAL group buffer size to check for flush A function is added to `libs/autofile/group.go#Group` in order to return the size of the buffered data (i.e. data that has not yet been flushed to disk). The test now checks that, prior to a `time.Sleep`, the group buffer has data in it. After the `time.Sleep` (during which time the periodic flush should have been called), the buffer should be empty. * Remove config root dir removal from #3291 * Add godoc for NewWAL mentioning periodic sync
6 years ago
10 years ago
8 years ago
10 years ago
10 years ago
8 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
7 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
10 years ago
10 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
10 years ago
10 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
10 years ago
10 years ago
new pubsub package comment out failing consensus tests for now rewrite rpc httpclient to use new pubsub package import pubsub as tmpubsub, query as tmquery make event IDs constants EventKey -> EventTypeKey rename EventsPubsub to PubSub mempool does not use pubsub rename eventsSub to pubsub new subscribe API fix channel size issues and consensus tests bugs refactor rpc client add missing discardFromChan method add mutex rename pubsub to eventBus remove IsRunning from WSRPCConnection interface (not needed) add a comment in broadcastNewRoundStepsAndVotes rename registerEventCallbacks to broadcastNewRoundStepsAndVotes See https://dave.cheney.net/2014/03/19/channel-axioms stop eventBuses after reactor tests remove unnecessary Unsubscribe return subscribe helper function move discardFromChan to where it is used subscribe now returns an err this gives us ability to refuse to subscribe if pubsub is at its max capacity. use context for control overflow cache queries handle err when subscribing in replay_test rename testClientID to testSubscriber extract var set channel buffer capacity to 1 in replay_file fix byzantine_test unsubscribe from single event, not all events refactor httpclient to return events to appropriate channels return failing testReplayCrashBeforeWriteVote test fix TestValidatorSetChanges refactor code a bit fix testReplayCrashBeforeWriteVote add comment fix TestValidatorSetChanges fixes from Bucky's review update comment [ci skip] test TxEventBuffer update changelog fix TestValidatorSetChanges (2nd attempt) only do wg.Done when no errors benchmark event bus create pubsub server inside NewEventBus only expose config params (later if needed) set buffer capacity to 0 so we are not testing cache new tx event format: key = "Tx" plus a tag {"tx.hash": XYZ} This should allow to subscribe to all transactions! or a specific one using a query: "tm.events.type = Tx and tx.hash = '013ABF99434...'" use TimeoutCommit instead of afterPublishEventNewBlockTimeout TimeoutCommit is the time a node waits after committing a block, before it goes into the next height. So it will finish everything from the last block, but then wait a bit. The idea is this gives it time to hear more votes from other validators, to strengthen the commit it includes in the next block. But it also gives it time to hear about new transactions. waitForBlockWithUpdatedVals rewrite WAL crash tests Task: test that we can recover from any WAL crash. Solution: the old tests were relying on event hub being run in the same thread (we were injecting the private validator's last signature). when considering a rewrite, we considered two possible solutions: write a "fuzzy" testing system where WAL is crashing upon receiving a new message, or inject failures and trigger them in tests using something like https://github.com/coreos/gofail. remove sleep no cs.Lock around wal.Save test different cases (empty block, non-empty block, ...) comments add comments test 4 cases: empty block, non-empty block, non-empty block with smaller part size, many blocks fixes as per Bucky's last review reset subscriptions on UnsubscribeAll use a simple counter to track message for which we panicked also, set a smaller part size for all test cases
8 years ago
9 years ago
7 years ago
10 years ago
9 years ago
9 years ago
10 years ago
10 years ago
7 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
10 years ago
8 years ago
8 years ago
7 years ago
7 years ago
7 years ago
7 years ago
10 years ago
10 years ago
7 years ago
7 years ago
10 years ago
10 years ago
9 years ago
9 years ago
7 years ago
10 years ago
cs: sync WAL more frequently (#3300) As per #3043, this adds a ticker to sync the WAL every 2s while the WAL is running. * Flush WAL every 2s This adds a ticker that flushes the WAL every 2s while the WAL is running. This is related to #3043. * Fix spelling * Increase timeout to 2mins for slower build environments * Make WAL sync interval configurable * Add TODO to replace testChan with more comprehensive testBus * Remove extraneous debug statement * Remove testChan in favour of using system time As per https://github.com/tendermint/tendermint/pull/3300#discussion_r255886586, this removes the `testChan` WAL member and replaces the approach with a system time-oriented one. In this new approach, we keep track of the system time at which each flush and periodic flush successfully occurred. The naming of the various functions is also updated here to be more consistent with "flushing" as opposed to "sync'ing". * Update naming convention and ensure lock for timestamp update * Add Flush method as part of WAL interface Adds a `Flush` method as part of the WAL interface to enforce the idea that we can manually trigger a WAL flush from outside of the WAL. This is employed in the consensus state management to flush the WAL prior to signing votes/proposals, as per https://github.com/tendermint/tendermint/issues/3043#issuecomment-453853630 * Update CHANGELOG_PENDING * Remove mutex approach and replace with DI The dependency injection approach to dealing with testing concerns could allow similar effects to some kind of "testing bus"-based approach. This commit introduces an example of this, where instead of relying on (potentially fragile) timing of things between the code and the test, we inject code into the function under test that can signal the test through a channel. This allows us to avoid the `time.Sleep()`-based approach previously employed. * Update comment on WAL flushing during vote signing Co-Authored-By: thanethomson <connect@thanethomson.com> * Simplify flush interval definition Co-Authored-By: thanethomson <connect@thanethomson.com> * Expand commentary on WAL disk flushing Co-Authored-By: thanethomson <connect@thanethomson.com> * Add broken test to illustrate WAL sync test problem Removes test-related state (dependency injection code) from the WAL data structure and adds test code to illustrate the problem with using `WALGenerateNBlocks` and `wal.SearchForEndHeight` to test periodic sync'ing. * Fix test error messages * Use WAL group buffer size to check for flush A function is added to `libs/autofile/group.go#Group` in order to return the size of the buffered data (i.e. data that has not yet been flushed to disk). The test now checks that, prior to a `time.Sleep`, the group buffer has data in it. After the `time.Sleep` (during which time the periodic flush should have been called), the buffer should be empty. * Remove config root dir removal from #3291 * Add godoc for NewWAL mentioning periodic sync
6 years ago
10 years ago
  1. package consensus
  2. import (
  3. "bytes"
  4. "fmt"
  5. "reflect"
  6. "runtime/debug"
  7. "sync"
  8. "time"
  9. "github.com/pkg/errors"
  10. cmn "github.com/tendermint/tendermint/libs/common"
  11. "github.com/tendermint/tendermint/libs/fail"
  12. "github.com/tendermint/tendermint/libs/log"
  13. tmtime "github.com/tendermint/tendermint/types/time"
  14. cfg "github.com/tendermint/tendermint/config"
  15. cstypes "github.com/tendermint/tendermint/consensus/types"
  16. tmevents "github.com/tendermint/tendermint/libs/events"
  17. "github.com/tendermint/tendermint/p2p"
  18. sm "github.com/tendermint/tendermint/state"
  19. "github.com/tendermint/tendermint/types"
  20. )
  21. //-----------------------------------------------------------------------------
  22. // Errors
  23. var (
  24. ErrInvalidProposalSignature = errors.New("error invalid proposal signature")
  25. ErrInvalidProposalPOLRound = errors.New("error invalid proposal POL round")
  26. ErrAddingVote = errors.New("error adding vote")
  27. ErrVoteHeightMismatch = errors.New("error vote height mismatch")
  28. )
  29. //-----------------------------------------------------------------------------
  30. var (
  31. msgQueueSize = 1000
  32. )
  33. // msgs from the reactor which may update the state
  34. type msgInfo struct {
  35. Msg ConsensusMessage `json:"msg"`
  36. PeerID p2p.ID `json:"peer_key"`
  37. }
  38. // internally generated messages which may update the state
  39. type timeoutInfo struct {
  40. Duration time.Duration `json:"duration"`
  41. Height int64 `json:"height"`
  42. Round int `json:"round"`
  43. Step cstypes.RoundStepType `json:"step"`
  44. }
  45. func (ti *timeoutInfo) String() string {
  46. return fmt.Sprintf("%v ; %d/%d %v", ti.Duration, ti.Height, ti.Round, ti.Step)
  47. }
  48. // interface to the mempool
  49. type txNotifier interface {
  50. TxsAvailable() <-chan struct{}
  51. }
  52. // interface to the evidence pool
  53. type evidencePool interface {
  54. AddEvidence(types.Evidence) error
  55. }
  56. // ConsensusState handles execution of the consensus algorithm.
  57. // It processes votes and proposals, and upon reaching agreement,
  58. // commits blocks to the chain and executes them against the application.
  59. // The internal state machine receives input from peers, the internal validator, and from a timer.
  60. type ConsensusState struct {
  61. cmn.BaseService
  62. // config details
  63. config *cfg.ConsensusConfig
  64. privValidator types.PrivValidator // for signing votes
  65. // store blocks and commits
  66. blockStore sm.BlockStore
  67. // create and execute blocks
  68. blockExec *sm.BlockExecutor
  69. // notify us if txs are available
  70. txNotifier txNotifier
  71. // add evidence to the pool
  72. // when it's detected
  73. evpool evidencePool
  74. // internal state
  75. mtx sync.RWMutex
  76. cstypes.RoundState
  77. state sm.State // State until height-1.
  78. // state changes may be triggered by: msgs from peers,
  79. // msgs from ourself, or by timeouts
  80. peerMsgQueue chan msgInfo
  81. internalMsgQueue chan msgInfo
  82. timeoutTicker TimeoutTicker
  83. // information about about added votes and block parts are written on this channel
  84. // so statistics can be computed by reactor
  85. statsMsgQueue chan msgInfo
  86. // we use eventBus to trigger msg broadcasts in the reactor,
  87. // and to notify external subscribers, eg. through a websocket
  88. eventBus *types.EventBus
  89. // a Write-Ahead Log ensures we can recover from any kind of crash
  90. // and helps us avoid signing conflicting votes
  91. wal WAL
  92. replayMode bool // so we don't log signing errors during replay
  93. doWALCatchup bool // determines if we even try to do the catchup
  94. // for tests where we want to limit the number of transitions the state makes
  95. nSteps int
  96. // some functions can be overwritten for testing
  97. decideProposal func(height int64, round int)
  98. doPrevote func(height int64, round int)
  99. setProposal func(proposal *types.Proposal) error
  100. // closed when we finish shutting down
  101. done chan struct{}
  102. // synchronous pubsub between consensus state and reactor.
  103. // state only emits EventNewRoundStep and EventVote
  104. evsw tmevents.EventSwitch
  105. // for reporting metrics
  106. metrics *Metrics
  107. }
  108. // StateOption sets an optional parameter on the ConsensusState.
  109. type StateOption func(*ConsensusState)
  110. // NewConsensusState returns a new ConsensusState.
  111. func NewConsensusState(
  112. config *cfg.ConsensusConfig,
  113. state sm.State,
  114. blockExec *sm.BlockExecutor,
  115. blockStore sm.BlockStore,
  116. txNotifier txNotifier,
  117. evpool evidencePool,
  118. options ...StateOption,
  119. ) *ConsensusState {
  120. cs := &ConsensusState{
  121. config: config,
  122. blockExec: blockExec,
  123. blockStore: blockStore,
  124. txNotifier: txNotifier,
  125. peerMsgQueue: make(chan msgInfo, msgQueueSize),
  126. internalMsgQueue: make(chan msgInfo, msgQueueSize),
  127. timeoutTicker: NewTimeoutTicker(),
  128. statsMsgQueue: make(chan msgInfo, msgQueueSize),
  129. done: make(chan struct{}),
  130. doWALCatchup: true,
  131. wal: nilWAL{},
  132. evpool: evpool,
  133. evsw: tmevents.NewEventSwitch(),
  134. metrics: NopMetrics(),
  135. }
  136. // set function defaults (may be overwritten before calling Start)
  137. cs.decideProposal = cs.defaultDecideProposal
  138. cs.doPrevote = cs.defaultDoPrevote
  139. cs.setProposal = cs.defaultSetProposal
  140. cs.updateToState(state)
  141. // Don't call scheduleRound0 yet.
  142. // We do that upon Start().
  143. cs.reconstructLastCommit(state)
  144. cs.BaseService = *cmn.NewBaseService(nil, "ConsensusState", cs)
  145. for _, option := range options {
  146. option(cs)
  147. }
  148. return cs
  149. }
  150. //----------------------------------------
  151. // Public interface
  152. // SetLogger implements Service.
  153. func (cs *ConsensusState) SetLogger(l log.Logger) {
  154. cs.BaseService.Logger = l
  155. cs.timeoutTicker.SetLogger(l)
  156. }
  157. // SetEventBus sets event bus.
  158. func (cs *ConsensusState) SetEventBus(b *types.EventBus) {
  159. cs.eventBus = b
  160. cs.blockExec.SetEventBus(b)
  161. }
  162. // StateMetrics sets the metrics.
  163. func StateMetrics(metrics *Metrics) StateOption {
  164. return func(cs *ConsensusState) { cs.metrics = metrics }
  165. }
  166. // String returns a string.
  167. func (cs *ConsensusState) String() string {
  168. // better not to access shared variables
  169. return fmt.Sprintf("ConsensusState") //(H:%v R:%v S:%v", cs.Height, cs.Round, cs.Step)
  170. }
  171. // GetState returns a copy of the chain state.
  172. func (cs *ConsensusState) GetState() sm.State {
  173. cs.mtx.RLock()
  174. defer cs.mtx.RUnlock()
  175. return cs.state.Copy()
  176. }
  177. // GetLastHeight returns the last height committed.
  178. // If there were no blocks, returns 0.
  179. func (cs *ConsensusState) GetLastHeight() int64 {
  180. cs.mtx.RLock()
  181. defer cs.mtx.RUnlock()
  182. return cs.RoundState.Height - 1
  183. }
  184. // GetRoundState returns a shallow copy of the internal consensus state.
  185. func (cs *ConsensusState) GetRoundState() *cstypes.RoundState {
  186. cs.mtx.RLock()
  187. rs := cs.RoundState // copy
  188. cs.mtx.RUnlock()
  189. return &rs
  190. }
  191. // GetRoundStateJSON returns a json of RoundState, marshalled using go-amino.
  192. func (cs *ConsensusState) GetRoundStateJSON() ([]byte, error) {
  193. cs.mtx.RLock()
  194. defer cs.mtx.RUnlock()
  195. return cdc.MarshalJSON(cs.RoundState)
  196. }
  197. // GetRoundStateSimpleJSON returns a json of RoundStateSimple, marshalled using go-amino.
  198. func (cs *ConsensusState) GetRoundStateSimpleJSON() ([]byte, error) {
  199. cs.mtx.RLock()
  200. defer cs.mtx.RUnlock()
  201. return cdc.MarshalJSON(cs.RoundState.RoundStateSimple())
  202. }
  203. // GetValidators returns a copy of the current validators.
  204. func (cs *ConsensusState) GetValidators() (int64, []*types.Validator) {
  205. cs.mtx.RLock()
  206. defer cs.mtx.RUnlock()
  207. return cs.state.LastBlockHeight, cs.state.Validators.Copy().Validators
  208. }
  209. // SetPrivValidator sets the private validator account for signing votes.
  210. func (cs *ConsensusState) SetPrivValidator(priv types.PrivValidator) {
  211. cs.mtx.Lock()
  212. cs.privValidator = priv
  213. cs.mtx.Unlock()
  214. }
  215. // SetTimeoutTicker sets the local timer. It may be useful to overwrite for testing.
  216. func (cs *ConsensusState) SetTimeoutTicker(timeoutTicker TimeoutTicker) {
  217. cs.mtx.Lock()
  218. cs.timeoutTicker = timeoutTicker
  219. cs.mtx.Unlock()
  220. }
  221. // LoadCommit loads the commit for a given height.
  222. func (cs *ConsensusState) LoadCommit(height int64) *types.Commit {
  223. cs.mtx.RLock()
  224. defer cs.mtx.RUnlock()
  225. if height == cs.blockStore.Height() {
  226. return cs.blockStore.LoadSeenCommit(height)
  227. }
  228. return cs.blockStore.LoadBlockCommit(height)
  229. }
  230. // OnStart implements cmn.Service.
  231. // It loads the latest state via the WAL, and starts the timeout and receive routines.
  232. func (cs *ConsensusState) OnStart() error {
  233. if err := cs.evsw.Start(); err != nil {
  234. return err
  235. }
  236. // we may set the WAL in testing before calling Start,
  237. // so only OpenWAL if its still the nilWAL
  238. if _, ok := cs.wal.(nilWAL); ok {
  239. walFile := cs.config.WalFile()
  240. wal, err := cs.OpenWAL(walFile)
  241. if err != nil {
  242. cs.Logger.Error("Error loading ConsensusState wal", "err", err.Error())
  243. return err
  244. }
  245. cs.wal = wal
  246. }
  247. // we need the timeoutRoutine for replay so
  248. // we don't block on the tick chan.
  249. // NOTE: we will get a build up of garbage go routines
  250. // firing on the tockChan until the receiveRoutine is started
  251. // to deal with them (by that point, at most one will be valid)
  252. if err := cs.timeoutTicker.Start(); err != nil {
  253. return err
  254. }
  255. // we may have lost some votes if the process crashed
  256. // reload from consensus log to catchup
  257. if cs.doWALCatchup {
  258. if err := cs.catchupReplay(cs.Height); err != nil {
  259. // don't try to recover from data corruption error
  260. if IsDataCorruptionError(err) {
  261. cs.Logger.Error("Encountered corrupt WAL file", "err", err.Error())
  262. cs.Logger.Error("Please repair the WAL file before restarting")
  263. fmt.Println(`You can attempt to repair the WAL as follows:
  264. ----
  265. WALFILE=~/.tendermint/data/cs.wal/wal
  266. cp $WALFILE ${WALFILE}.bak # backup the file
  267. go run scripts/wal2json/main.go $WALFILE > wal.json # this will panic, but can be ignored
  268. rm $WALFILE # remove the corrupt file
  269. go run scripts/json2wal/main.go wal.json $WALFILE # rebuild the file without corruption
  270. ----`)
  271. return err
  272. }
  273. cs.Logger.Error("Error on catchup replay. Proceeding to start ConsensusState anyway", "err", err.Error())
  274. // NOTE: if we ever do return an error here,
  275. // make sure to stop the timeoutTicker
  276. }
  277. }
  278. // now start the receiveRoutine
  279. go cs.receiveRoutine(0)
  280. // schedule the first round!
  281. // use GetRoundState so we don't race the receiveRoutine for access
  282. cs.scheduleRound0(cs.GetRoundState())
  283. return nil
  284. }
  285. // timeoutRoutine: receive requests for timeouts on tickChan and fire timeouts on tockChan
  286. // receiveRoutine: serializes processing of proposoals, block parts, votes; coordinates state transitions
  287. func (cs *ConsensusState) startRoutines(maxSteps int) {
  288. err := cs.timeoutTicker.Start()
  289. if err != nil {
  290. cs.Logger.Error("Error starting timeout ticker", "err", err)
  291. return
  292. }
  293. go cs.receiveRoutine(maxSteps)
  294. }
  295. // OnStop implements cmn.Service.
  296. func (cs *ConsensusState) OnStop() {
  297. cs.evsw.Stop()
  298. cs.timeoutTicker.Stop()
  299. // WAL is stopped in receiveRoutine.
  300. }
  301. // Wait waits for the the main routine to return.
  302. // NOTE: be sure to Stop() the event switch and drain
  303. // any event channels or this may deadlock
  304. func (cs *ConsensusState) Wait() {
  305. <-cs.done
  306. }
  307. // OpenWAL opens a file to log all consensus messages and timeouts for deterministic accountability
  308. func (cs *ConsensusState) OpenWAL(walFile string) (WAL, error) {
  309. wal, err := NewWAL(walFile)
  310. if err != nil {
  311. cs.Logger.Error("Failed to open WAL for consensus state", "wal", walFile, "err", err)
  312. return nil, err
  313. }
  314. wal.SetLogger(cs.Logger.With("wal", walFile))
  315. if err := wal.Start(); err != nil {
  316. return nil, err
  317. }
  318. return wal, nil
  319. }
  320. //------------------------------------------------------------
  321. // Public interface for passing messages into the consensus state, possibly causing a state transition.
  322. // If peerID == "", the msg is considered internal.
  323. // Messages are added to the appropriate queue (peer or internal).
  324. // If the queue is full, the function may block.
  325. // TODO: should these return anything or let callers just use events?
  326. // AddVote inputs a vote.
  327. func (cs *ConsensusState) AddVote(vote *types.Vote, peerID p2p.ID) (added bool, err error) {
  328. if peerID == "" {
  329. cs.internalMsgQueue <- msgInfo{&VoteMessage{vote}, ""}
  330. } else {
  331. cs.peerMsgQueue <- msgInfo{&VoteMessage{vote}, peerID}
  332. }
  333. // TODO: wait for event?!
  334. return false, nil
  335. }
  336. // SetProposal inputs a proposal.
  337. func (cs *ConsensusState) SetProposal(proposal *types.Proposal, peerID p2p.ID) error {
  338. if peerID == "" {
  339. cs.internalMsgQueue <- msgInfo{&ProposalMessage{proposal}, ""}
  340. } else {
  341. cs.peerMsgQueue <- msgInfo{&ProposalMessage{proposal}, peerID}
  342. }
  343. // TODO: wait for event?!
  344. return nil
  345. }
  346. // AddProposalBlockPart inputs a part of the proposal block.
  347. func (cs *ConsensusState) AddProposalBlockPart(height int64, round int, part *types.Part, peerID p2p.ID) error {
  348. if peerID == "" {
  349. cs.internalMsgQueue <- msgInfo{&BlockPartMessage{height, round, part}, ""}
  350. } else {
  351. cs.peerMsgQueue <- msgInfo{&BlockPartMessage{height, round, part}, peerID}
  352. }
  353. // TODO: wait for event?!
  354. return nil
  355. }
  356. // SetProposalAndBlock inputs the proposal and all block parts.
  357. func (cs *ConsensusState) SetProposalAndBlock(
  358. proposal *types.Proposal,
  359. block *types.Block,
  360. parts *types.PartSet,
  361. peerID p2p.ID) error {
  362. if err := cs.SetProposal(proposal, peerID); err != nil {
  363. return err
  364. }
  365. for i := 0; i < parts.Total(); i++ {
  366. part := parts.GetPart(i)
  367. if err := cs.AddProposalBlockPart(proposal.Height, proposal.Round, part, peerID); err != nil {
  368. return err
  369. }
  370. }
  371. return nil
  372. }
  373. //------------------------------------------------------------
  374. // internal functions for managing the state
  375. func (cs *ConsensusState) updateHeight(height int64) {
  376. cs.metrics.Height.Set(float64(height))
  377. cs.Height = height
  378. }
  379. func (cs *ConsensusState) updateRoundStep(round int, step cstypes.RoundStepType) {
  380. cs.Round = round
  381. cs.Step = step
  382. }
  383. // enterNewRound(height, 0) at cs.StartTime.
  384. func (cs *ConsensusState) scheduleRound0(rs *cstypes.RoundState) {
  385. //cs.Logger.Info("scheduleRound0", "now", tmtime.Now(), "startTime", cs.StartTime)
  386. sleepDuration := rs.StartTime.Sub(tmtime.Now())
  387. cs.scheduleTimeout(sleepDuration, rs.Height, 0, cstypes.RoundStepNewHeight)
  388. }
  389. // Attempt to schedule a timeout (by sending timeoutInfo on the tickChan)
  390. func (cs *ConsensusState) scheduleTimeout(duration time.Duration, height int64, round int, step cstypes.RoundStepType) {
  391. cs.timeoutTicker.ScheduleTimeout(timeoutInfo{duration, height, round, step})
  392. }
  393. // send a msg into the receiveRoutine regarding our own proposal, block part, or vote
  394. func (cs *ConsensusState) sendInternalMessage(mi msgInfo) {
  395. select {
  396. case cs.internalMsgQueue <- mi:
  397. default:
  398. // NOTE: using the go-routine means our votes can
  399. // be processed out of order.
  400. // TODO: use CList here for strict determinism and
  401. // attempt push to internalMsgQueue in receiveRoutine
  402. cs.Logger.Info("Internal msg queue is full. Using a go-routine")
  403. go func() { cs.internalMsgQueue <- mi }()
  404. }
  405. }
  406. // Reconstruct LastCommit from SeenCommit, which we saved along with the block,
  407. // (which happens even before saving the state)
  408. func (cs *ConsensusState) reconstructLastCommit(state sm.State) {
  409. if state.LastBlockHeight == 0 {
  410. return
  411. }
  412. seenCommit := cs.blockStore.LoadSeenCommit(state.LastBlockHeight)
  413. lastPrecommits := types.CommitToVoteSet(state.ChainID, seenCommit, state.LastValidators)
  414. if !lastPrecommits.HasTwoThirdsMajority() {
  415. panic("Failed to reconstruct LastCommit: Does not have +2/3 maj")
  416. }
  417. cs.LastCommit = lastPrecommits
  418. }
  419. // Updates ConsensusState and increments height to match that of state.
  420. // The round becomes 0 and cs.Step becomes cstypes.RoundStepNewHeight.
  421. func (cs *ConsensusState) updateToState(state sm.State) {
  422. if cs.CommitRound > -1 && 0 < cs.Height && cs.Height != state.LastBlockHeight {
  423. panic(fmt.Sprintf("updateToState() expected state height of %v but found %v",
  424. cs.Height, state.LastBlockHeight))
  425. }
  426. if !cs.state.IsEmpty() && cs.state.LastBlockHeight+1 != cs.Height {
  427. // This might happen when someone else is mutating cs.state.
  428. // Someone forgot to pass in state.Copy() somewhere?!
  429. panic(fmt.Sprintf("Inconsistent cs.state.LastBlockHeight+1 %v vs cs.Height %v",
  430. cs.state.LastBlockHeight+1, cs.Height))
  431. }
  432. // If state isn't further out than cs.state, just ignore.
  433. // This happens when SwitchToConsensus() is called in the reactor.
  434. // We don't want to reset e.g. the Votes, but we still want to
  435. // signal the new round step, because other services (eg. txNotifier)
  436. // depend on having an up-to-date peer state!
  437. if !cs.state.IsEmpty() && (state.LastBlockHeight <= cs.state.LastBlockHeight) {
  438. cs.Logger.Info(
  439. "Ignoring updateToState()",
  440. "newHeight",
  441. state.LastBlockHeight+1,
  442. "oldHeight",
  443. cs.state.LastBlockHeight+1)
  444. cs.newStep()
  445. return
  446. }
  447. // Reset fields based on state.
  448. validators := state.Validators
  449. lastPrecommits := (*types.VoteSet)(nil)
  450. if cs.CommitRound > -1 && cs.Votes != nil {
  451. if !cs.Votes.Precommits(cs.CommitRound).HasTwoThirdsMajority() {
  452. panic("updateToState(state) called but last Precommit round didn't have +2/3")
  453. }
  454. lastPrecommits = cs.Votes.Precommits(cs.CommitRound)
  455. }
  456. // Next desired block height
  457. height := state.LastBlockHeight + 1
  458. // RoundState fields
  459. cs.updateHeight(height)
  460. cs.updateRoundStep(0, cstypes.RoundStepNewHeight)
  461. if cs.CommitTime.IsZero() {
  462. // "Now" makes it easier to sync up dev nodes.
  463. // We add timeoutCommit to allow transactions
  464. // to be gathered for the first block.
  465. // And alternative solution that relies on clocks:
  466. // cs.StartTime = state.LastBlockTime.Add(timeoutCommit)
  467. cs.StartTime = cs.config.Commit(tmtime.Now())
  468. } else {
  469. cs.StartTime = cs.config.Commit(cs.CommitTime)
  470. }
  471. cs.Validators = validators
  472. cs.Proposal = nil
  473. cs.ProposalBlock = nil
  474. cs.ProposalBlockParts = nil
  475. cs.LockedRound = -1
  476. cs.LockedBlock = nil
  477. cs.LockedBlockParts = nil
  478. cs.ValidRound = -1
  479. cs.ValidBlock = nil
  480. cs.ValidBlockParts = nil
  481. cs.Votes = cstypes.NewHeightVoteSet(state.ChainID, height, validators)
  482. cs.CommitRound = -1
  483. cs.LastCommit = lastPrecommits
  484. cs.LastValidators = state.LastValidators
  485. cs.TriggeredTimeoutPrecommit = false
  486. cs.state = state
  487. // Finally, broadcast RoundState
  488. cs.newStep()
  489. }
  490. func (cs *ConsensusState) newStep() {
  491. rs := cs.RoundStateEvent()
  492. cs.wal.Write(rs)
  493. cs.nSteps++
  494. // newStep is called by updateToState in NewConsensusState before the eventBus is set!
  495. if cs.eventBus != nil {
  496. cs.eventBus.PublishEventNewRoundStep(rs)
  497. cs.evsw.FireEvent(types.EventNewRoundStep, &cs.RoundState)
  498. }
  499. }
  500. //-----------------------------------------
  501. // the main go routines
  502. // receiveRoutine handles messages which may cause state transitions.
  503. // it's argument (n) is the number of messages to process before exiting - use 0 to run forever
  504. // It keeps the RoundState and is the only thing that updates it.
  505. // Updates (state transitions) happen on timeouts, complete proposals, and 2/3 majorities.
  506. // ConsensusState must be locked before any internal state is updated.
  507. func (cs *ConsensusState) receiveRoutine(maxSteps int) {
  508. onExit := func(cs *ConsensusState) {
  509. // NOTE: the internalMsgQueue may have signed messages from our
  510. // priv_val that haven't hit the WAL, but its ok because
  511. // priv_val tracks LastSig
  512. // close wal now that we're done writing to it
  513. cs.wal.Stop()
  514. cs.wal.Wait()
  515. close(cs.done)
  516. }
  517. defer func() {
  518. if r := recover(); r != nil {
  519. cs.Logger.Error("CONSENSUS FAILURE!!!", "err", r, "stack", string(debug.Stack()))
  520. // stop gracefully
  521. //
  522. // NOTE: We most probably shouldn't be running any further when there is
  523. // some unexpected panic. Some unknown error happened, and so we don't
  524. // know if that will result in the validator signing an invalid thing. It
  525. // might be worthwhile to explore a mechanism for manual resuming via
  526. // some console or secure RPC system, but for now, halting the chain upon
  527. // unexpected consensus bugs sounds like the better option.
  528. onExit(cs)
  529. }
  530. }()
  531. for {
  532. if maxSteps > 0 {
  533. if cs.nSteps >= maxSteps {
  534. cs.Logger.Info("reached max steps. exiting receive routine")
  535. cs.nSteps = 0
  536. return
  537. }
  538. }
  539. rs := cs.RoundState
  540. var mi msgInfo
  541. select {
  542. case <-cs.txNotifier.TxsAvailable():
  543. cs.handleTxsAvailable()
  544. case mi = <-cs.peerMsgQueue:
  545. cs.wal.Write(mi)
  546. // handles proposals, block parts, votes
  547. // may generate internal events (votes, complete proposals, 2/3 majorities)
  548. cs.handleMsg(mi)
  549. case mi = <-cs.internalMsgQueue:
  550. err := cs.wal.WriteSync(mi) // NOTE: fsync
  551. if err != nil {
  552. panic(fmt.Sprintf("Failed to write %v msg to consensus wal due to %v. Check your FS and restart the node", mi, err))
  553. }
  554. if _, ok := mi.Msg.(*VoteMessage); ok {
  555. // we actually want to simulate failing during
  556. // the previous WriteSync, but this isn't easy to do.
  557. // Equivalent would be to fail here and manually remove
  558. // some bytes from the end of the wal.
  559. fail.Fail() // XXX
  560. }
  561. // handles proposals, block parts, votes
  562. cs.handleMsg(mi)
  563. case ti := <-cs.timeoutTicker.Chan(): // tockChan:
  564. cs.wal.Write(ti)
  565. // if the timeout is relevant to the rs
  566. // go to the next step
  567. cs.handleTimeout(ti, rs)
  568. case <-cs.Quit():
  569. onExit(cs)
  570. return
  571. }
  572. }
  573. }
  574. // state transitions on complete-proposal, 2/3-any, 2/3-one
  575. func (cs *ConsensusState) handleMsg(mi msgInfo) {
  576. cs.mtx.Lock()
  577. defer cs.mtx.Unlock()
  578. var (
  579. added bool
  580. err error
  581. )
  582. msg, peerID := mi.Msg, mi.PeerID
  583. switch msg := msg.(type) {
  584. case *ProposalMessage:
  585. // will not cause transition.
  586. // once proposal is set, we can receive block parts
  587. err = cs.setProposal(msg.Proposal)
  588. case *BlockPartMessage:
  589. // if the proposal is complete, we'll enterPrevote or tryFinalizeCommit
  590. added, err = cs.addProposalBlockPart(msg, peerID)
  591. if added {
  592. cs.statsMsgQueue <- mi
  593. }
  594. if err != nil && msg.Round != cs.Round {
  595. cs.Logger.Debug(
  596. "Received block part from wrong round",
  597. "height",
  598. cs.Height,
  599. "csRound",
  600. cs.Round,
  601. "blockRound",
  602. msg.Round)
  603. err = nil
  604. }
  605. case *VoteMessage:
  606. // attempt to add the vote and dupeout the validator if its a duplicate signature
  607. // if the vote gives us a 2/3-any or 2/3-one, we transition
  608. added, err = cs.tryAddVote(msg.Vote, peerID)
  609. if added {
  610. cs.statsMsgQueue <- mi
  611. }
  612. // if err == ErrAddingVote {
  613. // TODO: punish peer
  614. // We probably don't want to stop the peer here. The vote does not
  615. // necessarily comes from a malicious peer but can be just broadcasted by
  616. // a typical peer.
  617. // https://github.com/tendermint/tendermint/issues/1281
  618. // }
  619. // NOTE: the vote is broadcast to peers by the reactor listening
  620. // for vote events
  621. // TODO: If rs.Height == vote.Height && rs.Round < vote.Round,
  622. // the peer is sending us CatchupCommit precommits.
  623. // We could make note of this and help filter in broadcastHasVoteMessage().
  624. default:
  625. cs.Logger.Error("Unknown msg type", "type", reflect.TypeOf(msg))
  626. return
  627. }
  628. if err != nil { // nolint:staticcheck
  629. // Causes TestReactorValidatorSetChanges to timeout
  630. // https://github.com/tendermint/tendermint/issues/3406
  631. // cs.Logger.Error("Error with msg", "height", cs.Height, "round", cs.Round,
  632. // "peer", peerID, "err", err, "msg", msg)
  633. }
  634. }
  635. func (cs *ConsensusState) handleTimeout(ti timeoutInfo, rs cstypes.RoundState) {
  636. cs.Logger.Debug("Received tock", "timeout", ti.Duration, "height", ti.Height, "round", ti.Round, "step", ti.Step)
  637. // timeouts must be for current height, round, step
  638. if ti.Height != rs.Height || ti.Round < rs.Round || (ti.Round == rs.Round && ti.Step < rs.Step) {
  639. cs.Logger.Debug("Ignoring tock because we're ahead", "height", rs.Height, "round", rs.Round, "step", rs.Step)
  640. return
  641. }
  642. // the timeout will now cause a state transition
  643. cs.mtx.Lock()
  644. defer cs.mtx.Unlock()
  645. switch ti.Step {
  646. case cstypes.RoundStepNewHeight:
  647. // NewRound event fired from enterNewRound.
  648. // XXX: should we fire timeout here (for timeout commit)?
  649. cs.enterNewRound(ti.Height, 0)
  650. case cstypes.RoundStepNewRound:
  651. cs.enterPropose(ti.Height, 0)
  652. case cstypes.RoundStepPropose:
  653. cs.eventBus.PublishEventTimeoutPropose(cs.RoundStateEvent())
  654. cs.enterPrevote(ti.Height, ti.Round)
  655. case cstypes.RoundStepPrevoteWait:
  656. cs.eventBus.PublishEventTimeoutWait(cs.RoundStateEvent())
  657. cs.enterPrecommit(ti.Height, ti.Round)
  658. case cstypes.RoundStepPrecommitWait:
  659. cs.eventBus.PublishEventTimeoutWait(cs.RoundStateEvent())
  660. cs.enterPrecommit(ti.Height, ti.Round)
  661. cs.enterNewRound(ti.Height, ti.Round+1)
  662. default:
  663. panic(fmt.Sprintf("Invalid timeout step: %v", ti.Step))
  664. }
  665. }
  666. func (cs *ConsensusState) handleTxsAvailable() {
  667. cs.mtx.Lock()
  668. defer cs.mtx.Unlock()
  669. // We only need to do this for round 0.
  670. if cs.Round != 0 {
  671. return
  672. }
  673. switch cs.Step {
  674. case cstypes.RoundStepNewHeight: // timeoutCommit phase
  675. if cs.needProofBlock(cs.Height) {
  676. // enterPropose will be called by enterNewRound
  677. return
  678. }
  679. // +1ms to ensure RoundStepNewRound timeout always happens after RoundStepNewHeight
  680. timeoutCommit := cs.StartTime.Sub(tmtime.Now()) + 1*time.Millisecond
  681. cs.scheduleTimeout(timeoutCommit, cs.Height, 0, cstypes.RoundStepNewRound)
  682. case cstypes.RoundStepNewRound: // after timeoutCommit
  683. cs.enterPropose(cs.Height, 0)
  684. }
  685. }
  686. //-----------------------------------------------------------------------------
  687. // State functions
  688. // Used internally by handleTimeout and handleMsg to make state transitions
  689. // Enter: `timeoutNewHeight` by startTime (commitTime+timeoutCommit),
  690. // or, if SkipTimeoutCommit==true, after receiving all precommits from (height,round-1)
  691. // Enter: `timeoutPrecommits` after any +2/3 precommits from (height,round-1)
  692. // Enter: +2/3 precommits for nil at (height,round-1)
  693. // Enter: +2/3 prevotes any or +2/3 precommits for block or any from (height, round)
  694. // NOTE: cs.StartTime was already set for height.
  695. func (cs *ConsensusState) enterNewRound(height int64, round int) {
  696. logger := cs.Logger.With("height", height, "round", round)
  697. if cs.Height != height || round < cs.Round || (cs.Round == round && cs.Step != cstypes.RoundStepNewHeight) {
  698. logger.Debug(fmt.Sprintf(
  699. "enterNewRound(%v/%v): Invalid args. Current step: %v/%v/%v",
  700. height,
  701. round,
  702. cs.Height,
  703. cs.Round,
  704. cs.Step))
  705. return
  706. }
  707. if now := tmtime.Now(); cs.StartTime.After(now) {
  708. logger.Info("Need to set a buffer and log message here for sanity.", "startTime", cs.StartTime, "now", now)
  709. }
  710. logger.Info(fmt.Sprintf("enterNewRound(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
  711. // Increment validators if necessary
  712. validators := cs.Validators
  713. if cs.Round < round {
  714. validators = validators.Copy()
  715. validators.IncrementProposerPriority(round - cs.Round)
  716. }
  717. // Setup new round
  718. // we don't fire newStep for this step,
  719. // but we fire an event, so update the round step first
  720. cs.updateRoundStep(round, cstypes.RoundStepNewRound)
  721. cs.Validators = validators
  722. if round == 0 {
  723. // We've already reset these upon new height,
  724. // and meanwhile we might have received a proposal
  725. // for round 0.
  726. } else {
  727. logger.Info("Resetting Proposal info")
  728. cs.Proposal = nil
  729. cs.ProposalBlock = nil
  730. cs.ProposalBlockParts = nil
  731. }
  732. cs.Votes.SetRound(round + 1) // also track next round (round+1) to allow round-skipping
  733. cs.TriggeredTimeoutPrecommit = false
  734. cs.eventBus.PublishEventNewRound(cs.NewRoundEvent())
  735. cs.metrics.Rounds.Set(float64(round))
  736. // Wait for txs to be available in the mempool
  737. // before we enterPropose in round 0. If the last block changed the app hash,
  738. // we may need an empty "proof" block, and enterPropose immediately.
  739. waitForTxs := cs.config.WaitForTxs() && round == 0 && !cs.needProofBlock(height)
  740. if waitForTxs {
  741. if cs.config.CreateEmptyBlocksInterval > 0 {
  742. cs.scheduleTimeout(cs.config.CreateEmptyBlocksInterval, height, round,
  743. cstypes.RoundStepNewRound)
  744. }
  745. } else {
  746. cs.enterPropose(height, round)
  747. }
  748. }
  749. // needProofBlock returns true on the first height (so the genesis app hash is signed right away)
  750. // and where the last block (height-1) caused the app hash to change
  751. func (cs *ConsensusState) needProofBlock(height int64) bool {
  752. if height == 1 {
  753. return true
  754. }
  755. lastBlockMeta := cs.blockStore.LoadBlockMeta(height - 1)
  756. return !bytes.Equal(cs.state.AppHash, lastBlockMeta.Header.AppHash)
  757. }
  758. // Enter (CreateEmptyBlocks): from enterNewRound(height,round)
  759. // Enter (CreateEmptyBlocks, CreateEmptyBlocksInterval > 0 ):
  760. // after enterNewRound(height,round), after timeout of CreateEmptyBlocksInterval
  761. // Enter (!CreateEmptyBlocks) : after enterNewRound(height,round), once txs are in the mempool
  762. func (cs *ConsensusState) enterPropose(height int64, round int) {
  763. logger := cs.Logger.With("height", height, "round", round)
  764. if cs.Height != height || round < cs.Round || (cs.Round == round && cstypes.RoundStepPropose <= cs.Step) {
  765. logger.Debug(fmt.Sprintf(
  766. "enterPropose(%v/%v): Invalid args. Current step: %v/%v/%v",
  767. height,
  768. round,
  769. cs.Height,
  770. cs.Round,
  771. cs.Step))
  772. return
  773. }
  774. logger.Info(fmt.Sprintf("enterPropose(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
  775. defer func() {
  776. // Done enterPropose:
  777. cs.updateRoundStep(round, cstypes.RoundStepPropose)
  778. cs.newStep()
  779. // If we have the whole proposal + POL, then goto Prevote now.
  780. // else, we'll enterPrevote when the rest of the proposal is received (in AddProposalBlockPart),
  781. // or else after timeoutPropose
  782. if cs.isProposalComplete() {
  783. cs.enterPrevote(height, cs.Round)
  784. }
  785. }()
  786. // If we don't get the proposal and all block parts quick enough, enterPrevote
  787. cs.scheduleTimeout(cs.config.Propose(round), height, round, cstypes.RoundStepPropose)
  788. // Nothing more to do if we're not a validator
  789. if cs.privValidator == nil {
  790. logger.Debug("This node is not a validator")
  791. return
  792. }
  793. // if not a validator, we're done
  794. address := cs.privValidator.GetPubKey().Address()
  795. if !cs.Validators.HasAddress(address) {
  796. logger.Debug("This node is not a validator", "addr", address, "vals", cs.Validators)
  797. return
  798. }
  799. logger.Debug("This node is a validator")
  800. if cs.isProposer(address) {
  801. logger.Info("enterPropose: Our turn to propose",
  802. "proposer",
  803. cs.Validators.GetProposer().Address,
  804. "privValidator",
  805. cs.privValidator)
  806. cs.decideProposal(height, round)
  807. } else {
  808. logger.Info("enterPropose: Not our turn to propose",
  809. "proposer",
  810. cs.Validators.GetProposer().Address,
  811. "privValidator",
  812. cs.privValidator)
  813. }
  814. }
  815. func (cs *ConsensusState) isProposer(address []byte) bool {
  816. return bytes.Equal(cs.Validators.GetProposer().Address, address)
  817. }
  818. func (cs *ConsensusState) defaultDecideProposal(height int64, round int) {
  819. var block *types.Block
  820. var blockParts *types.PartSet
  821. // Decide on block
  822. if cs.ValidBlock != nil {
  823. // If there is valid block, choose that.
  824. block, blockParts = cs.ValidBlock, cs.ValidBlockParts
  825. } else {
  826. // Create a new proposal block from state/txs from the mempool.
  827. block, blockParts = cs.createProposalBlock()
  828. if block == nil { // on error
  829. return
  830. }
  831. }
  832. // Flush the WAL. Otherwise, we may not recompute the same proposal to sign,
  833. // and the privValidator will refuse to sign anything.
  834. cs.wal.FlushAndSync()
  835. // Make proposal
  836. propBlockID := types.BlockID{Hash: block.Hash(), PartsHeader: blockParts.Header()}
  837. proposal := types.NewProposal(height, round, cs.ValidRound, propBlockID)
  838. if err := cs.privValidator.SignProposal(cs.state.ChainID, proposal); err == nil {
  839. // send proposal and block parts on internal msg queue
  840. cs.sendInternalMessage(msgInfo{&ProposalMessage{proposal}, ""})
  841. for i := 0; i < blockParts.Total(); i++ {
  842. part := blockParts.GetPart(i)
  843. cs.sendInternalMessage(msgInfo{&BlockPartMessage{cs.Height, cs.Round, part}, ""})
  844. }
  845. cs.Logger.Info("Signed proposal", "height", height, "round", round, "proposal", proposal)
  846. cs.Logger.Debug(fmt.Sprintf("Signed proposal block: %v", block))
  847. } else if !cs.replayMode {
  848. cs.Logger.Error("enterPropose: Error signing proposal", "height", height, "round", round, "err", err)
  849. }
  850. }
  851. // Returns true if the proposal block is complete &&
  852. // (if POLRound was proposed, we have +2/3 prevotes from there).
  853. func (cs *ConsensusState) isProposalComplete() bool {
  854. if cs.Proposal == nil || cs.ProposalBlock == nil {
  855. return false
  856. }
  857. // we have the proposal. if there's a POLRound,
  858. // make sure we have the prevotes from it too
  859. if cs.Proposal.POLRound < 0 {
  860. return true
  861. }
  862. // if this is false the proposer is lying or we haven't received the POL yet
  863. return cs.Votes.Prevotes(cs.Proposal.POLRound).HasTwoThirdsMajority()
  864. }
  865. // Create the next block to propose and return it.
  866. // We really only need to return the parts, but the block
  867. // is returned for convenience so we can log the proposal block.
  868. // Returns nil block upon error.
  869. // NOTE: keep it side-effect free for clarity.
  870. func (cs *ConsensusState) createProposalBlock() (block *types.Block, blockParts *types.PartSet) {
  871. var commit *types.Commit
  872. switch {
  873. case cs.Height == 1:
  874. // We're creating a proposal for the first block.
  875. // The commit is empty, but not nil.
  876. commit = types.NewCommit(types.BlockID{}, nil)
  877. case cs.LastCommit.HasTwoThirdsMajority():
  878. // Make the commit from LastCommit
  879. commit = cs.LastCommit.MakeCommit()
  880. default:
  881. // This shouldn't happen.
  882. cs.Logger.Error("enterPropose: Cannot propose anything: No commit for the previous block.")
  883. return
  884. }
  885. proposerAddr := cs.privValidator.GetPubKey().Address()
  886. return cs.blockExec.CreateProposalBlock(cs.Height, cs.state, commit, proposerAddr)
  887. }
  888. // Enter: `timeoutPropose` after entering Propose.
  889. // Enter: proposal block and POL is ready.
  890. // Prevote for LockedBlock if we're locked, or ProposalBlock if valid.
  891. // Otherwise vote nil.
  892. func (cs *ConsensusState) enterPrevote(height int64, round int) {
  893. if cs.Height != height || round < cs.Round || (cs.Round == round && cstypes.RoundStepPrevote <= cs.Step) {
  894. cs.Logger.Debug(fmt.Sprintf(
  895. "enterPrevote(%v/%v): Invalid args. Current step: %v/%v/%v",
  896. height,
  897. round,
  898. cs.Height,
  899. cs.Round,
  900. cs.Step))
  901. return
  902. }
  903. defer func() {
  904. // Done enterPrevote:
  905. cs.updateRoundStep(round, cstypes.RoundStepPrevote)
  906. cs.newStep()
  907. }()
  908. cs.Logger.Info(fmt.Sprintf("enterPrevote(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
  909. // Sign and broadcast vote as necessary
  910. cs.doPrevote(height, round)
  911. // Once `addVote` hits any +2/3 prevotes, we will go to PrevoteWait
  912. // (so we have more time to try and collect +2/3 prevotes for a single block)
  913. }
  914. func (cs *ConsensusState) defaultDoPrevote(height int64, round int) {
  915. logger := cs.Logger.With("height", height, "round", round)
  916. // If a block is locked, prevote that.
  917. if cs.LockedBlock != nil {
  918. logger.Info("enterPrevote: Block was locked")
  919. cs.signAddVote(types.PrevoteType, cs.LockedBlock.Hash(), cs.LockedBlockParts.Header())
  920. return
  921. }
  922. // If ProposalBlock is nil, prevote nil.
  923. if cs.ProposalBlock == nil {
  924. logger.Info("enterPrevote: ProposalBlock is nil")
  925. cs.signAddVote(types.PrevoteType, nil, types.PartSetHeader{})
  926. return
  927. }
  928. // Validate proposal block
  929. err := cs.blockExec.ValidateBlock(cs.state, cs.ProposalBlock)
  930. if err != nil {
  931. // ProposalBlock is invalid, prevote nil.
  932. logger.Error("enterPrevote: ProposalBlock is invalid", "err", err)
  933. cs.signAddVote(types.PrevoteType, nil, types.PartSetHeader{})
  934. return
  935. }
  936. // Prevote cs.ProposalBlock
  937. // NOTE: the proposal signature is validated when it is received,
  938. // and the proposal block parts are validated as they are received (against the merkle hash in the proposal)
  939. logger.Info("enterPrevote: ProposalBlock is valid")
  940. cs.signAddVote(types.PrevoteType, cs.ProposalBlock.Hash(), cs.ProposalBlockParts.Header())
  941. }
  942. // Enter: any +2/3 prevotes at next round.
  943. func (cs *ConsensusState) enterPrevoteWait(height int64, round int) {
  944. logger := cs.Logger.With("height", height, "round", round)
  945. if cs.Height != height || round < cs.Round || (cs.Round == round && cstypes.RoundStepPrevoteWait <= cs.Step) {
  946. logger.Debug(fmt.Sprintf(
  947. "enterPrevoteWait(%v/%v): Invalid args. Current step: %v/%v/%v",
  948. height,
  949. round,
  950. cs.Height,
  951. cs.Round,
  952. cs.Step))
  953. return
  954. }
  955. if !cs.Votes.Prevotes(round).HasTwoThirdsAny() {
  956. panic(fmt.Sprintf("enterPrevoteWait(%v/%v), but Prevotes does not have any +2/3 votes", height, round))
  957. }
  958. logger.Info(fmt.Sprintf("enterPrevoteWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
  959. defer func() {
  960. // Done enterPrevoteWait:
  961. cs.updateRoundStep(round, cstypes.RoundStepPrevoteWait)
  962. cs.newStep()
  963. }()
  964. // Wait for some more prevotes; enterPrecommit
  965. cs.scheduleTimeout(cs.config.Prevote(round), height, round, cstypes.RoundStepPrevoteWait)
  966. }
  967. // Enter: `timeoutPrevote` after any +2/3 prevotes.
  968. // Enter: `timeoutPrecommit` after any +2/3 precommits.
  969. // Enter: +2/3 precomits for block or nil.
  970. // Lock & precommit the ProposalBlock if we have enough prevotes for it (a POL in this round)
  971. // else, unlock an existing lock and precommit nil if +2/3 of prevotes were nil,
  972. // else, precommit nil otherwise.
  973. func (cs *ConsensusState) enterPrecommit(height int64, round int) {
  974. logger := cs.Logger.With("height", height, "round", round)
  975. if cs.Height != height || round < cs.Round || (cs.Round == round && cstypes.RoundStepPrecommit <= cs.Step) {
  976. logger.Debug(fmt.Sprintf(
  977. "enterPrecommit(%v/%v): Invalid args. Current step: %v/%v/%v",
  978. height,
  979. round,
  980. cs.Height,
  981. cs.Round,
  982. cs.Step))
  983. return
  984. }
  985. logger.Info(fmt.Sprintf("enterPrecommit(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
  986. defer func() {
  987. // Done enterPrecommit:
  988. cs.updateRoundStep(round, cstypes.RoundStepPrecommit)
  989. cs.newStep()
  990. }()
  991. // check for a polka
  992. blockID, ok := cs.Votes.Prevotes(round).TwoThirdsMajority()
  993. // If we don't have a polka, we must precommit nil.
  994. if !ok {
  995. if cs.LockedBlock != nil {
  996. logger.Info("enterPrecommit: No +2/3 prevotes during enterPrecommit while we're locked. Precommitting nil")
  997. } else {
  998. logger.Info("enterPrecommit: No +2/3 prevotes during enterPrecommit. Precommitting nil.")
  999. }
  1000. cs.signAddVote(types.PrecommitType, nil, types.PartSetHeader{})
  1001. return
  1002. }
  1003. // At this point +2/3 prevoted for a particular block or nil.
  1004. cs.eventBus.PublishEventPolka(cs.RoundStateEvent())
  1005. // the latest POLRound should be this round.
  1006. polRound, _ := cs.Votes.POLInfo()
  1007. if polRound < round {
  1008. panic(fmt.Sprintf("This POLRound should be %v but got %v", round, polRound))
  1009. }
  1010. // +2/3 prevoted nil. Unlock and precommit nil.
  1011. if len(blockID.Hash) == 0 {
  1012. if cs.LockedBlock == nil {
  1013. logger.Info("enterPrecommit: +2/3 prevoted for nil.")
  1014. } else {
  1015. logger.Info("enterPrecommit: +2/3 prevoted for nil. Unlocking")
  1016. cs.LockedRound = -1
  1017. cs.LockedBlock = nil
  1018. cs.LockedBlockParts = nil
  1019. cs.eventBus.PublishEventUnlock(cs.RoundStateEvent())
  1020. }
  1021. cs.signAddVote(types.PrecommitType, nil, types.PartSetHeader{})
  1022. return
  1023. }
  1024. // At this point, +2/3 prevoted for a particular block.
  1025. // If we're already locked on that block, precommit it, and update the LockedRound
  1026. if cs.LockedBlock.HashesTo(blockID.Hash) {
  1027. logger.Info("enterPrecommit: +2/3 prevoted locked block. Relocking")
  1028. cs.LockedRound = round
  1029. cs.eventBus.PublishEventRelock(cs.RoundStateEvent())
  1030. cs.signAddVote(types.PrecommitType, blockID.Hash, blockID.PartsHeader)
  1031. return
  1032. }
  1033. // If +2/3 prevoted for proposal block, stage and precommit it
  1034. if cs.ProposalBlock.HashesTo(blockID.Hash) {
  1035. logger.Info("enterPrecommit: +2/3 prevoted proposal block. Locking", "hash", blockID.Hash)
  1036. // Validate the block.
  1037. if err := cs.blockExec.ValidateBlock(cs.state, cs.ProposalBlock); err != nil {
  1038. panic(fmt.Sprintf("enterPrecommit: +2/3 prevoted for an invalid block: %v", err))
  1039. }
  1040. cs.LockedRound = round
  1041. cs.LockedBlock = cs.ProposalBlock
  1042. cs.LockedBlockParts = cs.ProposalBlockParts
  1043. cs.eventBus.PublishEventLock(cs.RoundStateEvent())
  1044. cs.signAddVote(types.PrecommitType, blockID.Hash, blockID.PartsHeader)
  1045. return
  1046. }
  1047. // There was a polka in this round for a block we don't have.
  1048. // Fetch that block, unlock, and precommit nil.
  1049. // The +2/3 prevotes for this round is the POL for our unlock.
  1050. // TODO: In the future save the POL prevotes for justification.
  1051. cs.LockedRound = -1
  1052. cs.LockedBlock = nil
  1053. cs.LockedBlockParts = nil
  1054. if !cs.ProposalBlockParts.HasHeader(blockID.PartsHeader) {
  1055. cs.ProposalBlock = nil
  1056. cs.ProposalBlockParts = types.NewPartSetFromHeader(blockID.PartsHeader)
  1057. }
  1058. cs.eventBus.PublishEventUnlock(cs.RoundStateEvent())
  1059. cs.signAddVote(types.PrecommitType, nil, types.PartSetHeader{})
  1060. }
  1061. // Enter: any +2/3 precommits for next round.
  1062. func (cs *ConsensusState) enterPrecommitWait(height int64, round int) {
  1063. logger := cs.Logger.With("height", height, "round", round)
  1064. if cs.Height != height || round < cs.Round || (cs.Round == round && cs.TriggeredTimeoutPrecommit) {
  1065. logger.Debug(
  1066. fmt.Sprintf(
  1067. "enterPrecommitWait(%v/%v): Invalid args. "+
  1068. "Current state is Height/Round: %v/%v/, TriggeredTimeoutPrecommit:%v",
  1069. height, round, cs.Height, cs.Round, cs.TriggeredTimeoutPrecommit))
  1070. return
  1071. }
  1072. if !cs.Votes.Precommits(round).HasTwoThirdsAny() {
  1073. panic(fmt.Sprintf("enterPrecommitWait(%v/%v), but Precommits does not have any +2/3 votes", height, round))
  1074. }
  1075. logger.Info(fmt.Sprintf("enterPrecommitWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step))
  1076. defer func() {
  1077. // Done enterPrecommitWait:
  1078. cs.TriggeredTimeoutPrecommit = true
  1079. cs.newStep()
  1080. }()
  1081. // Wait for some more precommits; enterNewRound
  1082. cs.scheduleTimeout(cs.config.Precommit(round), height, round, cstypes.RoundStepPrecommitWait)
  1083. }
  1084. // Enter: +2/3 precommits for block
  1085. func (cs *ConsensusState) enterCommit(height int64, commitRound int) {
  1086. logger := cs.Logger.With("height", height, "commitRound", commitRound)
  1087. if cs.Height != height || cstypes.RoundStepCommit <= cs.Step {
  1088. logger.Debug(fmt.Sprintf(
  1089. "enterCommit(%v/%v): Invalid args. Current step: %v/%v/%v",
  1090. height,
  1091. commitRound,
  1092. cs.Height,
  1093. cs.Round,
  1094. cs.Step))
  1095. return
  1096. }
  1097. logger.Info(fmt.Sprintf("enterCommit(%v/%v). Current: %v/%v/%v", height, commitRound, cs.Height, cs.Round, cs.Step))
  1098. defer func() {
  1099. // Done enterCommit:
  1100. // keep cs.Round the same, commitRound points to the right Precommits set.
  1101. cs.updateRoundStep(cs.Round, cstypes.RoundStepCommit)
  1102. cs.CommitRound = commitRound
  1103. cs.CommitTime = tmtime.Now()
  1104. cs.newStep()
  1105. // Maybe finalize immediately.
  1106. cs.tryFinalizeCommit(height)
  1107. }()
  1108. blockID, ok := cs.Votes.Precommits(commitRound).TwoThirdsMajority()
  1109. if !ok {
  1110. panic("RunActionCommit() expects +2/3 precommits")
  1111. }
  1112. // The Locked* fields no longer matter.
  1113. // Move them over to ProposalBlock if they match the commit hash,
  1114. // otherwise they'll be cleared in updateToState.
  1115. if cs.LockedBlock.HashesTo(blockID.Hash) {
  1116. logger.Info("Commit is for locked block. Set ProposalBlock=LockedBlock", "blockHash", blockID.Hash)
  1117. cs.ProposalBlock = cs.LockedBlock
  1118. cs.ProposalBlockParts = cs.LockedBlockParts
  1119. }
  1120. // If we don't have the block being committed, set up to get it.
  1121. if !cs.ProposalBlock.HashesTo(blockID.Hash) {
  1122. if !cs.ProposalBlockParts.HasHeader(blockID.PartsHeader) {
  1123. logger.Info(
  1124. "Commit is for a block we don't know about. Set ProposalBlock=nil",
  1125. "proposal",
  1126. cs.ProposalBlock.Hash(),
  1127. "commit",
  1128. blockID.Hash)
  1129. // We're getting the wrong block.
  1130. // Set up ProposalBlockParts and keep waiting.
  1131. cs.ProposalBlock = nil
  1132. cs.ProposalBlockParts = types.NewPartSetFromHeader(blockID.PartsHeader)
  1133. cs.eventBus.PublishEventValidBlock(cs.RoundStateEvent())
  1134. cs.evsw.FireEvent(types.EventValidBlock, &cs.RoundState)
  1135. }
  1136. // else {
  1137. // We just need to keep waiting.
  1138. // }
  1139. }
  1140. }
  1141. // If we have the block AND +2/3 commits for it, finalize.
  1142. func (cs *ConsensusState) tryFinalizeCommit(height int64) {
  1143. logger := cs.Logger.With("height", height)
  1144. if cs.Height != height {
  1145. panic(fmt.Sprintf("tryFinalizeCommit() cs.Height: %v vs height: %v", cs.Height, height))
  1146. }
  1147. blockID, ok := cs.Votes.Precommits(cs.CommitRound).TwoThirdsMajority()
  1148. if !ok || len(blockID.Hash) == 0 {
  1149. logger.Error("Attempt to finalize failed. There was no +2/3 majority, or +2/3 was for <nil>.")
  1150. return
  1151. }
  1152. if !cs.ProposalBlock.HashesTo(blockID.Hash) {
  1153. // TODO: this happens every time if we're not a validator (ugly logs)
  1154. // TODO: ^^ wait, why does it matter that we're a validator?
  1155. logger.Info(
  1156. "Attempt to finalize failed. We don't have the commit block.",
  1157. "proposal-block",
  1158. cs.ProposalBlock.Hash(),
  1159. "commit-block",
  1160. blockID.Hash)
  1161. return
  1162. }
  1163. // go
  1164. cs.finalizeCommit(height)
  1165. }
  1166. // Increment height and goto cstypes.RoundStepNewHeight
  1167. func (cs *ConsensusState) finalizeCommit(height int64) {
  1168. if cs.Height != height || cs.Step != cstypes.RoundStepCommit {
  1169. cs.Logger.Debug(fmt.Sprintf(
  1170. "finalizeCommit(%v): Invalid args. Current step: %v/%v/%v",
  1171. height,
  1172. cs.Height,
  1173. cs.Round,
  1174. cs.Step))
  1175. return
  1176. }
  1177. blockID, ok := cs.Votes.Precommits(cs.CommitRound).TwoThirdsMajority()
  1178. block, blockParts := cs.ProposalBlock, cs.ProposalBlockParts
  1179. if !ok {
  1180. panic(fmt.Sprintf("Cannot finalizeCommit, commit does not have two thirds majority"))
  1181. }
  1182. if !blockParts.HasHeader(blockID.PartsHeader) {
  1183. panic(fmt.Sprintf("Expected ProposalBlockParts header to be commit header"))
  1184. }
  1185. if !block.HashesTo(blockID.Hash) {
  1186. panic(fmt.Sprintf("Cannot finalizeCommit, ProposalBlock does not hash to commit hash"))
  1187. }
  1188. if err := cs.blockExec.ValidateBlock(cs.state, block); err != nil {
  1189. panic(fmt.Sprintf("+2/3 committed an invalid block: %v", err))
  1190. }
  1191. cs.Logger.Info("Finalizing commit of block with N txs",
  1192. "height", block.Height,
  1193. "hash", block.Hash(),
  1194. "root", block.AppHash,
  1195. "N", len(block.Txs))
  1196. cs.Logger.Info(fmt.Sprintf("%v", block))
  1197. fail.Fail() // XXX
  1198. // Save to blockStore.
  1199. if cs.blockStore.Height() < block.Height {
  1200. // NOTE: the seenCommit is local justification to commit this block,
  1201. // but may differ from the LastCommit included in the next block
  1202. precommits := cs.Votes.Precommits(cs.CommitRound)
  1203. seenCommit := precommits.MakeCommit()
  1204. cs.blockStore.SaveBlock(block, blockParts, seenCommit)
  1205. } else {
  1206. // Happens during replay if we already saved the block but didn't commit
  1207. cs.Logger.Info("Calling finalizeCommit on already stored block", "height", block.Height)
  1208. }
  1209. fail.Fail() // XXX
  1210. // Write EndHeightMessage{} for this height, implying that the blockstore
  1211. // has saved the block.
  1212. //
  1213. // If we crash before writing this EndHeightMessage{}, we will recover by
  1214. // running ApplyBlock during the ABCI handshake when we restart. If we
  1215. // didn't save the block to the blockstore before writing
  1216. // EndHeightMessage{}, we'd have to change WAL replay -- currently it
  1217. // complains about replaying for heights where an #ENDHEIGHT entry already
  1218. // exists.
  1219. //
  1220. // Either way, the ConsensusState should not be resumed until we
  1221. // successfully call ApplyBlock (ie. later here, or in Handshake after
  1222. // restart).
  1223. endMsg := EndHeightMessage{height}
  1224. if err := cs.wal.WriteSync(endMsg); err != nil { // NOTE: fsync
  1225. panic(fmt.Sprintf("Failed to write %v msg to consensus wal due to %v. Check your FS and restart the node", endMsg, err))
  1226. }
  1227. fail.Fail() // XXX
  1228. // Create a copy of the state for staging and an event cache for txs.
  1229. stateCopy := cs.state.Copy()
  1230. // Execute and commit the block, update and save the state, and update the mempool.
  1231. // NOTE The block.AppHash wont reflect these txs until the next block.
  1232. var err error
  1233. stateCopy, err = cs.blockExec.ApplyBlock(
  1234. stateCopy,
  1235. types.BlockID{Hash: block.Hash(), PartsHeader: blockParts.Header()},
  1236. block)
  1237. if err != nil {
  1238. cs.Logger.Error("Error on ApplyBlock. Did the application crash? Please restart tendermint", "err", err)
  1239. err := cmn.Kill()
  1240. if err != nil {
  1241. cs.Logger.Error("Failed to kill this process - please do so manually", "err", err)
  1242. }
  1243. return
  1244. }
  1245. fail.Fail() // XXX
  1246. // must be called before we update state
  1247. cs.recordMetrics(height, block)
  1248. // NewHeightStep!
  1249. cs.updateToState(stateCopy)
  1250. fail.Fail() // XXX
  1251. // cs.StartTime is already set.
  1252. // Schedule Round0 to start soon.
  1253. cs.scheduleRound0(&cs.RoundState)
  1254. // By here,
  1255. // * cs.Height has been increment to height+1
  1256. // * cs.Step is now cstypes.RoundStepNewHeight
  1257. // * cs.StartTime is set to when we will start round0.
  1258. }
  1259. func (cs *ConsensusState) recordMetrics(height int64, block *types.Block) {
  1260. cs.metrics.Validators.Set(float64(cs.Validators.Size()))
  1261. cs.metrics.ValidatorsPower.Set(float64(cs.Validators.TotalVotingPower()))
  1262. missingValidators := 0
  1263. missingValidatorsPower := int64(0)
  1264. for i, val := range cs.Validators.Validators {
  1265. var vote *types.CommitSig
  1266. if i < len(block.LastCommit.Precommits) {
  1267. vote = block.LastCommit.Precommits[i]
  1268. }
  1269. if vote == nil {
  1270. missingValidators++
  1271. missingValidatorsPower += val.VotingPower
  1272. }
  1273. }
  1274. cs.metrics.MissingValidators.Set(float64(missingValidators))
  1275. cs.metrics.MissingValidatorsPower.Set(float64(missingValidatorsPower))
  1276. cs.metrics.ByzantineValidators.Set(float64(len(block.Evidence.Evidence)))
  1277. byzantineValidatorsPower := int64(0)
  1278. for _, ev := range block.Evidence.Evidence {
  1279. if _, val := cs.Validators.GetByAddress(ev.Address()); val != nil {
  1280. byzantineValidatorsPower += val.VotingPower
  1281. }
  1282. }
  1283. cs.metrics.ByzantineValidatorsPower.Set(float64(byzantineValidatorsPower))
  1284. if height > 1 {
  1285. lastBlockMeta := cs.blockStore.LoadBlockMeta(height - 1)
  1286. cs.metrics.BlockIntervalSeconds.Set(
  1287. block.Time.Sub(lastBlockMeta.Header.Time).Seconds(),
  1288. )
  1289. }
  1290. cs.metrics.NumTxs.Set(float64(len(block.Data.Txs)))
  1291. cs.metrics.TotalTxs.Add(float64(len(block.Data.Txs)))
  1292. cs.metrics.BlockSizeBytes.Set(float64(block.Size()))
  1293. cs.metrics.CommittedHeight.Set(float64(block.Height))
  1294. }
  1295. //-----------------------------------------------------------------------------
  1296. func (cs *ConsensusState) defaultSetProposal(proposal *types.Proposal) error {
  1297. // Already have one
  1298. // TODO: possibly catch double proposals
  1299. if cs.Proposal != nil {
  1300. return nil
  1301. }
  1302. // Does not apply
  1303. if proposal.Height != cs.Height || proposal.Round != cs.Round {
  1304. return nil
  1305. }
  1306. // Verify POLRound, which must be -1 or in range [0, proposal.Round).
  1307. if proposal.POLRound < -1 ||
  1308. (proposal.POLRound >= 0 && proposal.POLRound >= proposal.Round) {
  1309. return ErrInvalidProposalPOLRound
  1310. }
  1311. // Verify signature
  1312. if !cs.Validators.GetProposer().PubKey.VerifyBytes(proposal.SignBytes(cs.state.ChainID), proposal.Signature) {
  1313. return ErrInvalidProposalSignature
  1314. }
  1315. cs.Proposal = proposal
  1316. // We don't update cs.ProposalBlockParts if it is already set.
  1317. // This happens if we're already in cstypes.RoundStepCommit or if there is a valid block in the current round.
  1318. // TODO: We can check if Proposal is for a different block as this is a sign of misbehavior!
  1319. if cs.ProposalBlockParts == nil {
  1320. cs.ProposalBlockParts = types.NewPartSetFromHeader(proposal.BlockID.PartsHeader)
  1321. }
  1322. cs.Logger.Info("Received proposal", "proposal", proposal)
  1323. return nil
  1324. }
  1325. // NOTE: block is not necessarily valid.
  1326. // Asynchronously triggers either enterPrevote (before we timeout of propose) or tryFinalizeCommit,
  1327. // once we have the full block.
  1328. func (cs *ConsensusState) addProposalBlockPart(msg *BlockPartMessage, peerID p2p.ID) (added bool, err error) {
  1329. height, round, part := msg.Height, msg.Round, msg.Part
  1330. // Blocks might be reused, so round mismatch is OK
  1331. if cs.Height != height {
  1332. cs.Logger.Debug("Received block part from wrong height", "height", height, "round", round)
  1333. return false, nil
  1334. }
  1335. // We're not expecting a block part.
  1336. if cs.ProposalBlockParts == nil {
  1337. // NOTE: this can happen when we've gone to a higher round and
  1338. // then receive parts from the previous round - not necessarily a bad peer.
  1339. cs.Logger.Info("Received a block part when we're not expecting any",
  1340. "height", height, "round", round, "index", part.Index, "peer", peerID)
  1341. return false, nil
  1342. }
  1343. added, err = cs.ProposalBlockParts.AddPart(part)
  1344. if err != nil {
  1345. return added, err
  1346. }
  1347. if added && cs.ProposalBlockParts.IsComplete() {
  1348. // Added and completed!
  1349. _, err = cdc.UnmarshalBinaryLengthPrefixedReader(
  1350. cs.ProposalBlockParts.GetReader(),
  1351. &cs.ProposalBlock,
  1352. cs.state.ConsensusParams.Block.MaxBytes,
  1353. )
  1354. if err != nil {
  1355. return added, err
  1356. }
  1357. // NOTE: it's possible to receive complete proposal blocks for future rounds without having the proposal
  1358. cs.Logger.Info("Received complete proposal block", "height", cs.ProposalBlock.Height, "hash", cs.ProposalBlock.Hash())
  1359. cs.eventBus.PublishEventCompleteProposal(cs.CompleteProposalEvent())
  1360. // Update Valid* if we can.
  1361. prevotes := cs.Votes.Prevotes(cs.Round)
  1362. blockID, hasTwoThirds := prevotes.TwoThirdsMajority()
  1363. if hasTwoThirds && !blockID.IsZero() && (cs.ValidRound < cs.Round) {
  1364. if cs.ProposalBlock.HashesTo(blockID.Hash) {
  1365. cs.Logger.Info("Updating valid block to new proposal block",
  1366. "valid-round", cs.Round, "valid-block-hash", cs.ProposalBlock.Hash())
  1367. cs.ValidRound = cs.Round
  1368. cs.ValidBlock = cs.ProposalBlock
  1369. cs.ValidBlockParts = cs.ProposalBlockParts
  1370. }
  1371. // TODO: In case there is +2/3 majority in Prevotes set for some
  1372. // block and cs.ProposalBlock contains different block, either
  1373. // proposer is faulty or voting power of faulty processes is more
  1374. // than 1/3. We should trigger in the future accountability
  1375. // procedure at this point.
  1376. }
  1377. if cs.Step <= cstypes.RoundStepPropose && cs.isProposalComplete() {
  1378. // Move onto the next step
  1379. cs.enterPrevote(height, cs.Round)
  1380. if hasTwoThirds { // this is optimisation as this will be triggered when prevote is added
  1381. cs.enterPrecommit(height, cs.Round)
  1382. }
  1383. } else if cs.Step == cstypes.RoundStepCommit {
  1384. // If we're waiting on the proposal block...
  1385. cs.tryFinalizeCommit(height)
  1386. }
  1387. return added, nil
  1388. }
  1389. return added, nil
  1390. }
  1391. // Attempt to add the vote. if its a duplicate signature, dupeout the validator
  1392. func (cs *ConsensusState) tryAddVote(vote *types.Vote, peerID p2p.ID) (bool, error) {
  1393. added, err := cs.addVote(vote, peerID)
  1394. if err != nil {
  1395. // If the vote height is off, we'll just ignore it,
  1396. // But if it's a conflicting sig, add it to the cs.evpool.
  1397. // If it's otherwise invalid, punish peer.
  1398. if err == ErrVoteHeightMismatch {
  1399. return added, err
  1400. } else if voteErr, ok := err.(*types.ErrVoteConflictingVotes); ok {
  1401. addr := cs.privValidator.GetPubKey().Address()
  1402. if bytes.Equal(vote.ValidatorAddress, addr) {
  1403. cs.Logger.Error(
  1404. "Found conflicting vote from ourselves. Did you unsafe_reset a validator?",
  1405. "height",
  1406. vote.Height,
  1407. "round",
  1408. vote.Round,
  1409. "type",
  1410. vote.Type)
  1411. return added, err
  1412. }
  1413. cs.evpool.AddEvidence(voteErr.DuplicateVoteEvidence)
  1414. return added, err
  1415. } else {
  1416. // Either
  1417. // 1) bad peer OR
  1418. // 2) not a bad peer? this can also err sometimes with "Unexpected step" OR
  1419. // 3) tmkms use with multiple validators connecting to a single tmkms instance
  1420. // (https://github.com/tendermint/tendermint/issues/3839).
  1421. cs.Logger.Info("Error attempting to add vote", "err", err)
  1422. return added, ErrAddingVote
  1423. }
  1424. }
  1425. return added, nil
  1426. }
  1427. //-----------------------------------------------------------------------------
  1428. func (cs *ConsensusState) addVote(
  1429. vote *types.Vote,
  1430. peerID p2p.ID) (added bool, err error) {
  1431. cs.Logger.Debug(
  1432. "addVote",
  1433. "voteHeight",
  1434. vote.Height,
  1435. "voteType",
  1436. vote.Type,
  1437. "valIndex",
  1438. vote.ValidatorIndex,
  1439. "csHeight",
  1440. cs.Height)
  1441. // A precommit for the previous height?
  1442. // These come in while we wait timeoutCommit
  1443. if vote.Height+1 == cs.Height {
  1444. if !(cs.Step == cstypes.RoundStepNewHeight && vote.Type == types.PrecommitType) {
  1445. // TODO: give the reason ..
  1446. // fmt.Errorf("tryAddVote: Wrong height, not a LastCommit straggler commit.")
  1447. return added, ErrVoteHeightMismatch
  1448. }
  1449. added, err = cs.LastCommit.AddVote(vote)
  1450. if !added {
  1451. return added, err
  1452. }
  1453. cs.Logger.Info(fmt.Sprintf("Added to lastPrecommits: %v", cs.LastCommit.StringShort()))
  1454. cs.eventBus.PublishEventVote(types.EventDataVote{Vote: vote})
  1455. cs.evsw.FireEvent(types.EventVote, vote)
  1456. // if we can skip timeoutCommit and have all the votes now,
  1457. if cs.config.SkipTimeoutCommit && cs.LastCommit.HasAll() {
  1458. // go straight to new round (skip timeout commit)
  1459. // cs.scheduleTimeout(time.Duration(0), cs.Height, 0, cstypes.RoundStepNewHeight)
  1460. cs.enterNewRound(cs.Height, 0)
  1461. }
  1462. return
  1463. }
  1464. // Height mismatch is ignored.
  1465. // Not necessarily a bad peer, but not favourable behaviour.
  1466. if vote.Height != cs.Height {
  1467. err = ErrVoteHeightMismatch
  1468. cs.Logger.Info("Vote ignored and not added", "voteHeight", vote.Height, "csHeight", cs.Height, "peerID", peerID)
  1469. return
  1470. }
  1471. height := cs.Height
  1472. added, err = cs.Votes.AddVote(vote, peerID)
  1473. if !added {
  1474. // Either duplicate, or error upon cs.Votes.AddByIndex()
  1475. return
  1476. }
  1477. cs.eventBus.PublishEventVote(types.EventDataVote{Vote: vote})
  1478. cs.evsw.FireEvent(types.EventVote, vote)
  1479. switch vote.Type {
  1480. case types.PrevoteType:
  1481. prevotes := cs.Votes.Prevotes(vote.Round)
  1482. cs.Logger.Info("Added to prevote", "vote", vote, "prevotes", prevotes.StringShort())
  1483. // If +2/3 prevotes for a block or nil for *any* round:
  1484. if blockID, ok := prevotes.TwoThirdsMajority(); ok {
  1485. // There was a polka!
  1486. // If we're locked but this is a recent polka, unlock.
  1487. // If it matches our ProposalBlock, update the ValidBlock
  1488. // Unlock if `cs.LockedRound < vote.Round <= cs.Round`
  1489. // NOTE: If vote.Round > cs.Round, we'll deal with it when we get to vote.Round
  1490. if (cs.LockedBlock != nil) &&
  1491. (cs.LockedRound < vote.Round) &&
  1492. (vote.Round <= cs.Round) &&
  1493. !cs.LockedBlock.HashesTo(blockID.Hash) {
  1494. cs.Logger.Info("Unlocking because of POL.", "lockedRound", cs.LockedRound, "POLRound", vote.Round)
  1495. cs.LockedRound = -1
  1496. cs.LockedBlock = nil
  1497. cs.LockedBlockParts = nil
  1498. cs.eventBus.PublishEventUnlock(cs.RoundStateEvent())
  1499. }
  1500. // Update Valid* if we can.
  1501. // NOTE: our proposal block may be nil or not what received a polka..
  1502. if len(blockID.Hash) != 0 && (cs.ValidRound < vote.Round) && (vote.Round == cs.Round) {
  1503. if cs.ProposalBlock.HashesTo(blockID.Hash) {
  1504. cs.Logger.Info(
  1505. "Updating ValidBlock because of POL.", "validRound", cs.ValidRound, "POLRound", vote.Round)
  1506. cs.ValidRound = vote.Round
  1507. cs.ValidBlock = cs.ProposalBlock
  1508. cs.ValidBlockParts = cs.ProposalBlockParts
  1509. } else {
  1510. cs.Logger.Info(
  1511. "Valid block we don't know about. Set ProposalBlock=nil",
  1512. "proposal", cs.ProposalBlock.Hash(), "blockId", blockID.Hash)
  1513. // We're getting the wrong block.
  1514. cs.ProposalBlock = nil
  1515. }
  1516. if !cs.ProposalBlockParts.HasHeader(blockID.PartsHeader) {
  1517. cs.ProposalBlockParts = types.NewPartSetFromHeader(blockID.PartsHeader)
  1518. }
  1519. cs.evsw.FireEvent(types.EventValidBlock, &cs.RoundState)
  1520. cs.eventBus.PublishEventValidBlock(cs.RoundStateEvent())
  1521. }
  1522. }
  1523. // If +2/3 prevotes for *anything* for future round:
  1524. switch {
  1525. case cs.Round < vote.Round && prevotes.HasTwoThirdsAny():
  1526. // Round-skip if there is any 2/3+ of votes ahead of us
  1527. cs.enterNewRound(height, vote.Round)
  1528. case cs.Round == vote.Round && cstypes.RoundStepPrevote <= cs.Step: // current round
  1529. blockID, ok := prevotes.TwoThirdsMajority()
  1530. if ok && (cs.isProposalComplete() || len(blockID.Hash) == 0) {
  1531. cs.enterPrecommit(height, vote.Round)
  1532. } else if prevotes.HasTwoThirdsAny() {
  1533. cs.enterPrevoteWait(height, vote.Round)
  1534. }
  1535. case cs.Proposal != nil && 0 <= cs.Proposal.POLRound && cs.Proposal.POLRound == vote.Round:
  1536. // If the proposal is now complete, enter prevote of cs.Round.
  1537. if cs.isProposalComplete() {
  1538. cs.enterPrevote(height, cs.Round)
  1539. }
  1540. }
  1541. case types.PrecommitType:
  1542. precommits := cs.Votes.Precommits(vote.Round)
  1543. cs.Logger.Info("Added to precommit", "vote", vote, "precommits", precommits.StringShort())
  1544. blockID, ok := precommits.TwoThirdsMajority()
  1545. if ok {
  1546. // Executed as TwoThirdsMajority could be from a higher round
  1547. cs.enterNewRound(height, vote.Round)
  1548. cs.enterPrecommit(height, vote.Round)
  1549. if len(blockID.Hash) != 0 {
  1550. cs.enterCommit(height, vote.Round)
  1551. if cs.config.SkipTimeoutCommit && precommits.HasAll() {
  1552. cs.enterNewRound(cs.Height, 0)
  1553. }
  1554. } else {
  1555. cs.enterPrecommitWait(height, vote.Round)
  1556. }
  1557. } else if cs.Round <= vote.Round && precommits.HasTwoThirdsAny() {
  1558. cs.enterNewRound(height, vote.Round)
  1559. cs.enterPrecommitWait(height, vote.Round)
  1560. }
  1561. default:
  1562. panic(fmt.Sprintf("Unexpected vote type %X", vote.Type)) // go-amino should prevent this.
  1563. }
  1564. return added, err
  1565. }
  1566. func (cs *ConsensusState) signVote(
  1567. type_ types.SignedMsgType,
  1568. hash []byte,
  1569. header types.PartSetHeader) (*types.Vote, error) {
  1570. // Flush the WAL. Otherwise, we may not recompute the same vote to sign,
  1571. // and the privValidator will refuse to sign anything.
  1572. cs.wal.FlushAndSync()
  1573. addr := cs.privValidator.GetPubKey().Address()
  1574. valIndex, _ := cs.Validators.GetByAddress(addr)
  1575. vote := &types.Vote{
  1576. ValidatorAddress: addr,
  1577. ValidatorIndex: valIndex,
  1578. Height: cs.Height,
  1579. Round: cs.Round,
  1580. Timestamp: cs.voteTime(),
  1581. Type: type_,
  1582. BlockID: types.BlockID{Hash: hash, PartsHeader: header},
  1583. }
  1584. err := cs.privValidator.SignVote(cs.state.ChainID, vote)
  1585. return vote, err
  1586. }
  1587. func (cs *ConsensusState) voteTime() time.Time {
  1588. now := tmtime.Now()
  1589. minVoteTime := now
  1590. // TODO: We should remove next line in case we don't vote for v in case cs.ProposalBlock == nil,
  1591. // even if cs.LockedBlock != nil. See https://github.com/tendermint/spec.
  1592. timeIotaMs := time.Duration(cs.state.ConsensusParams.Block.TimeIotaMs) * time.Millisecond
  1593. if cs.LockedBlock != nil {
  1594. // See the BFT time spec https://tendermint.com/docs/spec/consensus/bft-time.html
  1595. minVoteTime = cs.LockedBlock.Time.Add(timeIotaMs)
  1596. } else if cs.ProposalBlock != nil {
  1597. minVoteTime = cs.ProposalBlock.Time.Add(timeIotaMs)
  1598. }
  1599. if now.After(minVoteTime) {
  1600. return now
  1601. }
  1602. return minVoteTime
  1603. }
  1604. // sign the vote and publish on internalMsgQueue
  1605. func (cs *ConsensusState) signAddVote(type_ types.SignedMsgType, hash []byte, header types.PartSetHeader) *types.Vote {
  1606. // if we don't have a key or we're not in the validator set, do nothing
  1607. if cs.privValidator == nil || !cs.Validators.HasAddress(cs.privValidator.GetPubKey().Address()) {
  1608. return nil
  1609. }
  1610. vote, err := cs.signVote(type_, hash, header)
  1611. if err == nil {
  1612. cs.sendInternalMessage(msgInfo{&VoteMessage{vote}, ""})
  1613. cs.Logger.Info("Signed and pushed vote", "height", cs.Height, "round", cs.Round, "vote", vote, "err", err)
  1614. return vote
  1615. }
  1616. //if !cs.replayMode {
  1617. cs.Logger.Error("Error signing vote", "height", cs.Height, "round", cs.Round, "vote", vote, "err", err)
  1618. //}
  1619. return nil
  1620. }
  1621. //---------------------------------------------------------
  1622. func CompareHRS(h1 int64, r1 int, s1 cstypes.RoundStepType, h2 int64, r2 int, s2 cstypes.RoundStepType) int {
  1623. if h1 < h2 {
  1624. return -1
  1625. } else if h1 > h2 {
  1626. return 1
  1627. }
  1628. if r1 < r2 {
  1629. return -1
  1630. } else if r1 > r2 {
  1631. return 1
  1632. }
  1633. if s1 < s2 {
  1634. return -1
  1635. } else if s1 > s2 {
  1636. return 1
  1637. }
  1638. return 0
  1639. }