From 7dcb567e5366f215887783c8cae1e7683f852916 Mon Sep 17 00:00:00 2001 From: Ethan Buchman Date: Tue, 11 Oct 2016 11:44:07 -0400 Subject: [PATCH 1/4] replay test data --- consensus/replay_test.go | 194 +++++++++++++------------- consensus/state.go | 2 +- consensus/test_data/README.md | 36 +++++ consensus/test_data/empty_block.cswal | 8 ++ consensus/test_data/small_block.cswal | 8 ++ 5 files changed, 151 insertions(+), 97 deletions(-) create mode 100644 consensus/test_data/README.md create mode 100644 consensus/test_data/empty_block.cswal create mode 100644 consensus/test_data/small_block.cswal diff --git a/consensus/replay_test.go b/consensus/replay_test.go index db7d7546..01e48c7f 100644 --- a/consensus/replay_test.go +++ b/consensus/replay_test.go @@ -4,6 +4,7 @@ import ( "fmt" "io/ioutil" "os" + "path" "strings" "testing" "time" @@ -13,54 +14,16 @@ import ( "github.com/tendermint/tendermint/types" ) -/* - The easiest way to generate this data is to copy ~/.tendermint_test/somedir/* to ~/.tendermint - and to run a local node. - Be sure to set the db to "leveldb" to create a cswal file in ~/.tendermint/data/cswal. +var data_dir = "test_data" // TODO - If you need to change the signatures, you can use a script as follows: - The privBytes comes from config/tendermint_test/... +type testCase struct { + name string + log string //full cswal + stepMap map[int]int8 // map lines of log to privval step +} - ``` - package main - - import ( - "encoding/hex" - "fmt" - - "github.com/tendermint/go-crypto" - ) - - func main() { - signBytes, err := hex.DecodeString("7B22636861696E5F6964223A2274656E6465726D696E745F74657374222C22766F7465223A7B22626C6F636B5F68617368223A2242453544373939433846353044354645383533364334333932464443384537423342313830373638222C22626C6F636B5F70617274735F686561646572223A506172745365747B543A31204236323237323535464632307D2C22686569676874223A312C22726F756E64223A302C2274797065223A327D7D") - if err != nil { - panic(err) - } - privBytes, err := hex.DecodeString("27F82582AEFAE7AB151CFB01C48BB6C1A0DA78F9BDDA979A9F70A84D074EB07D3B3069C422E19688B45CBFAE7BB009FC0FA1B1EA86593519318B7214853803C8") - if err != nil { - panic(err) - } - privKey := crypto.PrivKeyEd25519{} - copy(privKey[:], privBytes) - signature := privKey.Sign(signBytes) - signatureEd25519 := signature.(crypto.SignatureEd25519) - fmt.Printf("Signature Bytes: %X\n", signatureEd25519[:]) - } - ``` -*/ - -var testLog = `{"time":"2016-04-03T11:23:54.387Z","msg":[3,{"duration":972835254,"height":1,"round":0,"step":1}]} -{"time":"2016-04-03T11:23:54.388Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPropose"}]} -{"time":"2016-04-03T11:23:54.388Z","msg":[2,{"msg":[17,{"Proposal":{"height":1,"round":0,"block_parts_header":{"total":1,"hash":"3BA1E90CB868DA6B4FD7F3589826EC461E9EB4EF"},"pol_round":-1,"signature":"3A2ECD5023B21EC144EC16CFF1B992A4321317B83EEDD8969FDFEA6EB7BF4389F38DDA3E7BB109D63A07491C16277A197B241CF1F05F5E485C59882ECACD9E07"}}],"peer_key":""}]} -{"time":"2016-04-03T11:23:54.389Z","msg":[2,{"msg":[19,{"Height":1,"Round":0,"Part":{"index":0,"bytes":"0101010F74656E6465726D696E745F7465737401011441D59F4B718AC00000000000000114C4B01D3810579550997AC5641E759E20D99B51C10001000100","proof":{"aunts":[]}}}],"peer_key":""}]} -{"time":"2016-04-03T11:23:54.390Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPrevote"}]} -{"time":"2016-04-03T11:23:54.390Z","msg":[2,{"msg":[20,{"ValidatorIndex":0,"Vote":{"height":1,"round":0,"type":1,"block_hash":"4291966B8A9DFBA00AEC7C700F2718E61DF4331D","block_parts_header":{"total":1,"hash":"3BA1E90CB868DA6B4FD7F3589826EC461E9EB4EF"},"signature":"47D2A75A4E2F15DB1F0D1B656AC0637AF9AADDFEB6A156874F6553C73895E5D5DC948DBAEF15E61276C5342D0E638DFCB77C971CD282096EA8735A564A90F008"}}],"peer_key":""}]} -{"time":"2016-04-03T11:23:54.392Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPrecommit"}]} -{"time":"2016-04-03T11:23:54.392Z","msg":[2,{"msg":[20,{"ValidatorIndex":0,"Vote":{"height":1,"round":0,"type":2,"block_hash":"4291966B8A9DFBA00AEC7C700F2718E61DF4331D","block_parts_header":{"total":1,"hash":"3BA1E90CB868DA6B4FD7F3589826EC461E9EB4EF"},"signature":"39147DA595F08B73CF8C899967C8403B5872FD9042FFA4E239159E0B6C5D9665C9CA81D766EACA2AE658872F94C2FCD1E34BF51859CD5B274DA8512BACE4B50D"}}],"peer_key":""}]} -` - -// map lines in the above wal to privVal step -var mapPrivValStep = map[int]int8{ +// mapping for one validator and blocks with one part +var baseStepMap = map[int]int8{ 0: 0, 1: 0, 2: 1, @@ -71,6 +34,32 @@ var mapPrivValStep = map[int]int8{ 7: 3, } +var testCases = []*testCase{ + &testCase{ + name: "empty_block", + stepMap: baseStepMap, + }, + &testCase{ + name: "small_block", + stepMap: baseStepMap, + }, +} + +// populate test logs by reading files +func init() { + for _, c := range testCases { + c.log = readWAL(path.Join(data_dir, c.name+".cswal")) + } +} + +func readWAL(p string) string { + b, err := ioutil.ReadFile(p) + if err != nil { + panic(err) + } + return string(b) +} + func writeWAL(log string) string { fmt.Println("writing", log) // write the needed wal to file @@ -88,27 +77,29 @@ func writeWAL(log string) string { return name } -func waitForBlock(newBlockCh chan interface{}) { +func waitForBlock(newBlockCh chan interface{}, thisCase *testCase, i int) { after := time.After(time.Second * 10) select { case <-newBlockCh: case <-after: - panic("Timed out waiting for new block") + panic(Fmt("Timed out waiting for new block for case '%s' line %d", thisCase.name, i)) } } -func runReplayTest(t *testing.T, cs *ConsensusState, fileName string, newBlockCh chan interface{}) { +func runReplayTest(t *testing.T, cs *ConsensusState, fileName string, newBlockCh chan interface{}, + thisCase *testCase, i int) { + cs.config.Set("cswal", fileName) cs.Start() // Wait to make a new block. // This is just a signal that we haven't halted; its not something contained in the WAL itself. // Assuming the consensus state is running, replay of any WAL, including the empty one, // should eventually be followed by a new block, or else something is wrong - waitForBlock(newBlockCh) + waitForBlock(newBlockCh, thisCase, i) cs.Stop() } -func setupReplayTest(nLines int, crashAfter bool) (*ConsensusState, chan interface{}, string, string) { +func setupReplayTest(thisCase *testCase, nLines int, crashAfter bool) (*ConsensusState, chan interface{}, string, string) { fmt.Println("-------------------------------------") log.Notice(Fmt("Starting replay test of %d lines of WAL (crash before write)", nLines)) @@ -117,7 +108,7 @@ func setupReplayTest(nLines int, crashAfter bool) (*ConsensusState, chan interfa lineStep -= 1 } - split := strings.Split(testLog, "\n") + split := strings.Split(thisCase.log, "\n") lastMsg := split[nLines] // we write those lines up to (not including) one with the signature @@ -127,7 +118,7 @@ func setupReplayTest(nLines int, crashAfter bool) (*ConsensusState, chan interfa // set the last step according to when we crashed vs the wal cs.privValidator.LastHeight = 1 // first block - cs.privValidator.LastStep = mapPrivValStep[lineStep] + cs.privValidator.LastStep = thisCase.stepMap[lineStep] fmt.Println("LAST STEP", cs.privValidator.LastStep) @@ -141,10 +132,12 @@ func setupReplayTest(nLines int, crashAfter bool) (*ConsensusState, chan interfa // as if the log was written after signing, before the crash func TestReplayCrashAfterWrite(t *testing.T) { - split := strings.Split(testLog, "\n") - for i := 0; i < len(split)-1; i++ { - cs, newBlockCh, _, f := setupReplayTest(i+1, true) - runReplayTest(t, cs, f, newBlockCh) + for _, thisCase := range testCases { + split := strings.Split(thisCase.log, "\n") + for i := 0; i < len(split)-1; i++ { + cs, newBlockCh, _, f := setupReplayTest(thisCase, i+1, true) + runReplayTest(t, cs, f, newBlockCh, thisCase, i+1) + } } } @@ -153,50 +146,59 @@ func TestReplayCrashAfterWrite(t *testing.T) { // This relies on privValidator.LastSignature being set func TestReplayCrashBeforeWritePropose(t *testing.T) { - cs, newBlockCh, proposalMsg, f := setupReplayTest(2, false) // propose - // Set LastSig - var err error - var msg ConsensusLogMessage - wire.ReadJSON(&msg, []byte(proposalMsg), &err) - proposal := msg.Msg.(msgInfo).Msg.(*ProposalMessage) - if err != nil { - t.Fatalf("Error reading json data: %v", err) + for _, thisCase := range testCases { + lineNum := 2 + cs, newBlockCh, proposalMsg, f := setupReplayTest(thisCase, lineNum, false) // propose + // Set LastSig + var err error + var msg ConsensusLogMessage + wire.ReadJSON(&msg, []byte(proposalMsg), &err) + proposal := msg.Msg.(msgInfo).Msg.(*ProposalMessage) + if err != nil { + t.Fatalf("Error reading json data: %v", err) + } + cs.privValidator.LastSignBytes = types.SignBytes(cs.state.ChainID, proposal.Proposal) + cs.privValidator.LastSignature = proposal.Proposal.Signature + runReplayTest(t, cs, f, newBlockCh, thisCase, lineNum) } - cs.privValidator.LastSignBytes = types.SignBytes(cs.state.ChainID, proposal.Proposal) - cs.privValidator.LastSignature = proposal.Proposal.Signature - runReplayTest(t, cs, f, newBlockCh) } func TestReplayCrashBeforeWritePrevote(t *testing.T) { - cs, newBlockCh, voteMsg, f := setupReplayTest(5, false) // prevote - types.AddListenerForEvent(cs.evsw, "tester", types.EventStringCompleteProposal(), func(data types.TMEventData) { - // Set LastSig - var err error - var msg ConsensusLogMessage - wire.ReadJSON(&msg, []byte(voteMsg), &err) - vote := msg.Msg.(msgInfo).Msg.(*VoteMessage) - if err != nil { - t.Fatalf("Error reading json data: %v", err) - } - cs.privValidator.LastSignBytes = types.SignBytes(cs.state.ChainID, vote.Vote) - cs.privValidator.LastSignature = vote.Vote.Signature - }) - runReplayTest(t, cs, f, newBlockCh) + for _, thisCase := range testCases { + lineNum := 5 + cs, newBlockCh, voteMsg, f := setupReplayTest(thisCase, lineNum, false) // prevote + types.AddListenerForEvent(cs.evsw, "tester", types.EventStringCompleteProposal(), func(data types.TMEventData) { + // Set LastSig + var err error + var msg ConsensusLogMessage + wire.ReadJSON(&msg, []byte(voteMsg), &err) + vote := msg.Msg.(msgInfo).Msg.(*VoteMessage) + if err != nil { + t.Fatalf("Error reading json data: %v", err) + } + cs.privValidator.LastSignBytes = types.SignBytes(cs.state.ChainID, vote.Vote) + cs.privValidator.LastSignature = vote.Vote.Signature + }) + runReplayTest(t, cs, f, newBlockCh, thisCase, lineNum) + } } func TestReplayCrashBeforeWritePrecommit(t *testing.T) { - cs, newBlockCh, voteMsg, f := setupReplayTest(7, false) // precommit - types.AddListenerForEvent(cs.evsw, "tester", types.EventStringPolka(), func(data types.TMEventData) { - // Set LastSig - var err error - var msg ConsensusLogMessage - wire.ReadJSON(&msg, []byte(voteMsg), &err) - vote := msg.Msg.(msgInfo).Msg.(*VoteMessage) - if err != nil { - t.Fatalf("Error reading json data: %v", err) - } - cs.privValidator.LastSignBytes = types.SignBytes(cs.state.ChainID, vote.Vote) - cs.privValidator.LastSignature = vote.Vote.Signature - }) - runReplayTest(t, cs, f, newBlockCh) + for _, thisCase := range testCases { + lineNum := 7 + cs, newBlockCh, voteMsg, f := setupReplayTest(thisCase, lineNum, false) // precommit + types.AddListenerForEvent(cs.evsw, "tester", types.EventStringPolka(), func(data types.TMEventData) { + // Set LastSig + var err error + var msg ConsensusLogMessage + wire.ReadJSON(&msg, []byte(voteMsg), &err) + vote := msg.Msg.(msgInfo).Msg.(*VoteMessage) + if err != nil { + t.Fatalf("Error reading json data: %v", err) + } + cs.privValidator.LastSignBytes = types.SignBytes(cs.state.ChainID, vote.Vote) + cs.privValidator.LastSignature = vote.Vote.Signature + }) + runReplayTest(t, cs, f, newBlockCh, thisCase, lineNum) + } } diff --git a/consensus/state.go b/consensus/state.go index b393bc30..9cfe6dce 100644 --- a/consensus/state.go +++ b/consensus/state.go @@ -1498,7 +1498,7 @@ func (cs *ConsensusState) addVote(valIndex int, vote *types.Vote, peerKey string } // Height mismatch, bad peer? - log.Info("Vote ignored and not added", "voteHeight", vote.Height, "csHeight", cs.Height) + log.Info("Vote ignored and not added", "voteHeight", vote.Height, "csHeight", cs.Height, "err", err) return } diff --git a/consensus/test_data/README.md b/consensus/test_data/README.md new file mode 100644 index 00000000..e3bfca70 --- /dev/null +++ b/consensus/test_data/README.md @@ -0,0 +1,36 @@ +# Generating test data + +The easiest way to generate this data is to copy `~/.tendermint_test/somedir/*` to `~/.tendermint` +and to run a local node. +Be sure to set the db to "leveldb" to create a cswal file in `~/.tendermint/data/cswal`. + +If you need to change the signatures, you can use a script as follows: +The privBytes comes from `config/tendermint_test/...`: + +``` +package main + +import ( + "encoding/hex" + "fmt" + + "github.com/tendermint/go-crypto" +) + +func main() { + signBytes, err := hex.DecodeString("7B22636861696E5F6964223A2274656E6465726D696E745F74657374222C22766F7465223A7B22626C6F636B5F68617368223A2242453544373939433846353044354645383533364334333932464443384537423342313830373638222C22626C6F636B5F70617274735F686561646572223A506172745365747B543A31204236323237323535464632307D2C22686569676874223A312C22726F756E64223A302C2274797065223A327D7D") + if err != nil { + panic(err) + } + privBytes, err := hex.DecodeString("27F82582AEFAE7AB151CFB01C48BB6C1A0DA78F9BDDA979A9F70A84D074EB07D3B3069C422E19688B45CBFAE7BB009FC0FA1B1EA86593519318B7214853803C8") + if err != nil { + panic(err) + } + privKey := crypto.PrivKeyEd25519{} + copy(privKey[:], privBytes) + signature := privKey.Sign(signBytes) + signatureEd25519 := signature.(crypto.SignatureEd25519) + fmt.Printf("Signature Bytes: %X\n", signatureEd25519[:]) +} +``` + diff --git a/consensus/test_data/empty_block.cswal b/consensus/test_data/empty_block.cswal new file mode 100644 index 00000000..65800c42 --- /dev/null +++ b/consensus/test_data/empty_block.cswal @@ -0,0 +1,8 @@ +{"time":"2016-04-03T11:23:54.387Z","msg":[3,{"duration":972835254,"height":1,"round":0,"step":1}]} +{"time":"2016-04-03T11:23:54.388Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPropose"}]} +{"time":"2016-04-03T11:23:54.388Z","msg":[2,{"msg":[17,{"Proposal":{"height":1,"round":0,"block_parts_header":{"total":1,"hash":"3BA1E90CB868DA6B4FD7F3589826EC461E9EB4EF"},"pol_round":-1,"signature":"3A2ECD5023B21EC144EC16CFF1B992A4321317B83EEDD8969FDFEA6EB7BF4389F38DDA3E7BB109D63A07491C16277A197B241CF1F05F5E485C59882ECACD9E07"}}],"peer_key":""}]} +{"time":"2016-04-03T11:23:54.389Z","msg":[2,{"msg":[19,{"Height":1,"Round":0,"Part":{"index":0,"bytes":"0101010F74656E6465726D696E745F7465737401011441D59F4B718AC00000000000000114C4B01D3810579550997AC5641E759E20D99B51C10001000100","proof":{"aunts":[]}}}],"peer_key":""}]} +{"time":"2016-04-03T11:23:54.390Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPrevote"}]} +{"time":"2016-04-03T11:23:54.390Z","msg":[2,{"msg":[20,{"ValidatorIndex":0,"Vote":{"height":1,"round":0,"type":1,"block_hash":"4291966B8A9DFBA00AEC7C700F2718E61DF4331D","block_parts_header":{"total":1,"hash":"3BA1E90CB868DA6B4FD7F3589826EC461E9EB4EF"},"signature":"47D2A75A4E2F15DB1F0D1B656AC0637AF9AADDFEB6A156874F6553C73895E5D5DC948DBAEF15E61276C5342D0E638DFCB77C971CD282096EA8735A564A90F008"}}],"peer_key":""}]} +{"time":"2016-04-03T11:23:54.392Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPrecommit"}]} +{"time":"2016-04-03T11:23:54.392Z","msg":[2,{"msg":[20,{"ValidatorIndex":0,"Vote":{"height":1,"round":0,"type":2,"block_hash":"4291966B8A9DFBA00AEC7C700F2718E61DF4331D","block_parts_header":{"total":1,"hash":"3BA1E90CB868DA6B4FD7F3589826EC461E9EB4EF"},"signature":"39147DA595F08B73CF8C899967C8403B5872FD9042FFA4E239159E0B6C5D9665C9CA81D766EACA2AE658872F94C2FCD1E34BF51859CD5B274DA8512BACE4B50D"}}],"peer_key":""}]} diff --git a/consensus/test_data/small_block.cswal b/consensus/test_data/small_block.cswal new file mode 100644 index 00000000..738f7951 --- /dev/null +++ b/consensus/test_data/small_block.cswal @@ -0,0 +1,8 @@ +{"time":"2016-10-11T15:29:08.113Z","msg":[3,{"duration":0,"height":1,"round":0,"step":1}]} +{"time":"2016-10-11T15:29:08.115Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPropose"}]} +{"time":"2016-10-11T15:29:08.115Z","msg":[2,{"msg":[17,{"Proposal":{"height":1,"round":0,"block_parts_header":{"total":1,"hash":"A2C0B5D384DFF2692FF679D00CEAE93A55DCDD1A"},"pol_round":-1,"signature":"116961B715FB54C09983209F7F3BFD95C7DA2E0D7AB9CFE9F0750F2402E2AEB715CFD55FB2C5DB88F485391D426A48705E0474AB94328463290D086D88BAD704"}}],"peer_key":""}]} +{"time":"2016-10-11T15:29:08.116Z","msg":[2,{"msg":[19,{"Height":1,"Round":0,"Part":{"index":0,"bytes":"0101010F74656E6465726D696E745F746573740101147C83D983CBE6400185000000000114CA4CC7A87B85A9FB7DBFEF8A342B66DF2B03CFB30114C4B01D3810579550997AC5641E759E20D99B51C100010185010F616263643234353D64636261323435010F616263643234363D64636261323436010F616263643234373D64636261323437010F616263643234383D64636261323438010F616263643234393D64636261323439010F616263643235303D64636261323530010F616263643235313D64636261323531010F616263643235323D64636261323532010F616263643235333D64636261323533010F616263643235343D64636261323534010F616263643235353D64636261323535010F616263643235363D64636261323536010F616263643235373D64636261323537010F616263643235383D64636261323538010F616263643235393D64636261323539010F616263643236303D64636261323630010F616263643236313D64636261323631010F616263643236323D64636261323632010F616263643236333D64636261323633010F616263643236343D64636261323634010F616263643236353D64636261323635010F616263643236363D64636261323636010F616263643236373D64636261323637010F616263643236383D64636261323638010F616263643236393D64636261323639010F616263643237303D64636261323730010F616263643237313D64636261323731010F616263643237323D64636261323732010F616263643237333D64636261323733010F616263643237343D64636261323734010F616263643237353D64636261323735010F616263643237363D64636261323736010F616263643237373D64636261323737010F616263643237383D64636261323738010F616263643237393D64636261323739010F616263643238303D64636261323830010F616263643238313D64636261323831010F616263643238323D64636261323832010F616263643238333D64636261323833010F616263643238343D64636261323834010F616263643238353D64636261323835010F616263643238363D64636261323836010F616263643238373D64636261323837010F616263643238383D64636261323838010F616263643238393D64636261323839010F616263643239303D64636261323930010F616263643239313D64636261323931010F616263643239323D64636261323932010F616263643239333D64636261323933010F616263643239343D64636261323934010F616263643239353D64636261323935010F616263643239363D64636261323936010F616263643239373D64636261323937010F616263643239383D64636261323938010F616263643239393D64636261323939010F616263643330303D64636261333030010F616263643330313D64636261333031010F616263643330323D64636261333032010F616263643330333D64636261333033010F616263643330343D64636261333034010F616263643330353D64636261333035010F616263643330363D64636261333036010F616263643330373D64636261333037010F616263643330383D64636261333038010F616263643330393D64636261333039010F616263643331303D64636261333130010F616263643331313D64636261333131010F616263643331323D64636261333132010F616263643331333D64636261333133010F616263643331343D64636261333134010F616263643331353D64636261333135010F616263643331363D64636261333136010F616263643331373D64636261333137010F616263643331383D64636261333138010F616263643331393D64636261333139010F616263643332303D64636261333230010F616263643332313D64636261333231010F616263643332323D64636261333232010F616263643332333D64636261333233010F616263643332343D64636261333234010F616263643332353D64636261333235010F616263643332363D64636261333236010F616263643332373D64636261333237010F616263643332383D64636261333238010F616263643332393D64636261333239010F616263643333303D64636261333330010F616263643333313D64636261333331010F616263643333323D64636261333332010F616263643333333D64636261333333010F616263643333343D64636261333334010F616263643333353D64636261333335010F616263643333363D64636261333336010F616263643333373D64636261333337010F616263643333383D64636261333338010F616263643333393D64636261333339010F616263643334303D64636261333430010F616263643334313D64636261333431010F616263643334323D64636261333432010F616263643334333D64636261333433010F616263643334343D64636261333434010F616263643334353D64636261333435010F616263643334363D64636261333436010F616263643334373D64636261333437010F616263643334383D64636261333438010F616263643334393D64636261333439010F616263643335303D64636261333530010F616263643335313D64636261333531010F616263643335323D64636261333532010F616263643335333D64636261333533010F616263643335343D64636261333534010F616263643335353D64636261333535010F616263643335363D64636261333536010F616263643335373D64636261333537010F616263643335383D64636261333538010F616263643335393D64636261333539010F616263643336303D64636261333630010F616263643336313D64636261333631010F616263643336323D64636261333632010F616263643336333D64636261333633010F616263643336343D64636261333634010F616263643336353D64636261333635010F616263643336363D64636261333636010F616263643336373D64636261333637010F616263643336383D64636261333638010F616263643336393D64636261333639010F616263643337303D64636261333730010F616263643337313D64636261333731010F616263643337323D64636261333732010F616263643337333D64636261333733010F616263643337343D64636261333734010F616263643337353D64636261333735010F616263643337363D64636261333736010F616263643337373D646362613337370100","proof":{"aunts":[]}}}],"peer_key":""}]} +{"time":"2016-10-11T15:29:08.117Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPrevote"}]} +{"time":"2016-10-11T15:29:08.117Z","msg":[2,{"msg":[20,{"ValidatorIndex":0,"Vote":{"height":1,"round":0,"type":1,"block_hash":"FB2F51D0C6D25AD8D4ED9C33DF145E358D414A79","block_parts_header":{"total":1,"hash":"A2C0B5D384DFF2692FF679D00CEAE93A55DCDD1A"},"signature":"9BA7F5DEF2CE51CDF078DE42E3BB74D6DB6BC84767F212A88D34B3393E5915A4DC0E6C478E1C955E099617800722582E4D90AB1AC293EE5C19BC1FCC04C3CA05"}}],"peer_key":""}]} +{"time":"2016-10-11T15:29:08.118Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPrecommit"}]} +{"time":"2016-10-11T15:29:08.118Z","msg":[2,{"msg":[20,{"ValidatorIndex":0,"Vote":{"height":1,"round":0,"type":2,"block_hash":"FB2F51D0C6D25AD8D4ED9C33DF145E358D414A79","block_parts_header":{"total":1,"hash":"A2C0B5D384DFF2692FF679D00CEAE93A55DCDD1A"},"signature":"9DA197CC1D7D0463FF211FB55EA12B3B0647B319E0011308C7AC3FB36E66688B4AC92EA51BD7B055814F9E4E6AB97B1AD0891EDAC42B47877100770FF467BF0A"}}],"peer_key":""}]} From 3c18d841fa44093d6a501ed55a11c25145944e0a Mon Sep 17 00:00:00 2001 From: Ethan Buchman Date: Tue, 11 Oct 2016 12:51:48 -0400 Subject: [PATCH 2/4] replay: larger read buffer --- consensus/common_test.go | 11 +++++++++++ consensus/replay.go | 10 ++++++++-- consensus/replay_test.go | 2 +- 3 files changed, 20 insertions(+), 3 deletions(-) diff --git a/consensus/common_test.go b/consensus/common_test.go index 12eeeb56..7cb3418c 100644 --- a/consensus/common_test.go +++ b/consensus/common_test.go @@ -18,6 +18,7 @@ import ( tmsp "github.com/tendermint/tmsp/types" "github.com/tendermint/tmsp/example/counter" + "github.com/tendermint/tmsp/example/dummy" ) var config cfg.Config // NOTE: must be reset for each _test.go file @@ -320,6 +321,16 @@ func fixedConsensusState() *ConsensusState { return cs } +func fixedConsensusStateDummy() *ConsensusState { + stateDB := dbm.NewMemDB() + state := sm.MakeGenesisStateFromFile(stateDB, config.GetString("genesis_file")) + privValidatorFile := config.GetString("priv_validator_file") + privValidator := types.LoadOrGenPrivValidator(privValidatorFile) + privValidator.Reset() + cs := newConsensusState(state, privValidator, dummy.NewDummyApplication()) + return cs +} + func newConsensusState(state *sm.State, pv *types.PrivValidator, app tmsp.Application) *ConsensusState { // Get BlockStore blockDB := dbm.NewMemDB() diff --git a/consensus/replay.go b/consensus/replay.go index 9bb0fb05..c77d0558 100644 --- a/consensus/replay.go +++ b/consensus/replay.go @@ -116,20 +116,26 @@ func (cs *ConsensusState) catchupReplay(height int) error { // now we can replay the latest nLines on consensus state // note we can't use scan because we've already been reading from the file - reader := bufio.NewReader(cs.wal.fp) + // XXX: if a msg is too big we need to find out why or increase this for that case ... + maxMsgSize := 1000000 + reader := bufio.NewReaderSize(cs.wal.fp, maxMsgSize) for i := 0; i < nLines; i++ { msgBytes, err := reader.ReadBytes('\n') if err == io.EOF { + log.Warn("Replay: EOF", "bytes", string(msgBytes)) break } else if err != nil { return err } else if len(msgBytes) == 0 { + log.Warn("Replay: msg bytes is 0") continue } else if len(msgBytes) == 1 && msgBytes[0] == '\n' { + log.Warn("Replay: new line") continue } // the first msg is the NewHeight event (if we're not at the beginning), so we can ignore it if !beginning && i == 1 { + log.Warn("Replay: not beginning and 1") continue } @@ -140,7 +146,7 @@ func (cs *ConsensusState) catchupReplay(height int) error { return err } } - log.Notice("Done catchup replay") + log.Notice("Replay: Done") return nil } diff --git a/consensus/replay_test.go b/consensus/replay_test.go index 01e48c7f..9fed2e8e 100644 --- a/consensus/replay_test.go +++ b/consensus/replay_test.go @@ -114,7 +114,7 @@ func setupReplayTest(thisCase *testCase, nLines int, crashAfter bool) (*Consensu // we write those lines up to (not including) one with the signature fileName := writeWAL(strings.Join(split[:nLines], "\n") + "\n") - cs := fixedConsensusState() + cs := fixedConsensusStateDummy() // set the last step according to when we crashed vs the wal cs.privValidator.LastHeight = 1 // first block From 9365d3324365069900f163c94367fc2e75d55cb3 Mon Sep 17 00:00:00 2001 From: Ethan Buchman Date: Tue, 11 Oct 2016 12:55:04 -0400 Subject: [PATCH 3/4] replay: more tests --- consensus/replay_test.go | 73 +++++++++++-------- .../{small_block.cswal => small_block1.cswal} | 0 consensus/test_data/small_block2.cswal | 10 +++ 3 files changed, 52 insertions(+), 31 deletions(-) rename consensus/test_data/{small_block.cswal => small_block1.cswal} (100%) create mode 100644 consensus/test_data/small_block2.cswal diff --git a/consensus/replay_test.go b/consensus/replay_test.go index 9fed2e8e..1e7c1e81 100644 --- a/consensus/replay_test.go +++ b/consensus/replay_test.go @@ -14,42 +14,53 @@ import ( "github.com/tendermint/tendermint/types" ) -var data_dir = "test_data" // TODO +var data_dir = path.Join(GoPath, "src/github.com/tendermint/tendermint/consensus", "test_data") + +// the priv validator changes step at these lines for a block with 1 val and 1 part +var baseStepChanges = []int{2, 5, 7} + +// test recovery from each line in each testCase +var testCases = []*testCase{ + newTestCase("empty_block", baseStepChanges), // empty block (has 1 block part) + newTestCase("small_block1", baseStepChanges), // small block with txs in 1 block part + newTestCase("small_block2", []int{2, 7, 9}), // small block with txs across 3 smaller block parts +} type testCase struct { name string log string //full cswal stepMap map[int]int8 // map lines of log to privval step + + proposeLine int + prevoteLine int + precommitLine int } -// mapping for one validator and blocks with one part -var baseStepMap = map[int]int8{ - 0: 0, - 1: 0, - 2: 1, - 3: 1, - 4: 1, - 5: 2, - 6: 2, - 7: 3, -} - -var testCases = []*testCase{ - &testCase{ - name: "empty_block", - stepMap: baseStepMap, - }, - &testCase{ - name: "small_block", - stepMap: baseStepMap, - }, -} - -// populate test logs by reading files -func init() { - for _, c := range testCases { - c.log = readWAL(path.Join(data_dir, c.name+".cswal")) +func newTestCase(name string, stepChanges []int) *testCase { + if len(stepChanges) != 3 { + panic(Fmt("a full wal has 3 step changes! Got array %v", stepChanges)) } + return &testCase{ + name: name, + log: readWAL(path.Join(data_dir, name+".cswal")), + stepMap: newMapFromChanges(stepChanges), + + proposeLine: stepChanges[0], + prevoteLine: stepChanges[1], + precommitLine: stepChanges[2], + } +} + +func newMapFromChanges(changes []int) map[int]int8 { + changes = append(changes, changes[2]+1) // so we add the last step change to the map + m := make(map[int]int8) + var count int + for changeNum, nextChange := range changes { + for ; count < nextChange; count++ { + m[count] = int8(changeNum) + } + } + return m } func readWAL(p string) string { @@ -147,7 +158,7 @@ func TestReplayCrashAfterWrite(t *testing.T) { func TestReplayCrashBeforeWritePropose(t *testing.T) { for _, thisCase := range testCases { - lineNum := 2 + lineNum := thisCase.proposeLine cs, newBlockCh, proposalMsg, f := setupReplayTest(thisCase, lineNum, false) // propose // Set LastSig var err error @@ -165,7 +176,7 @@ func TestReplayCrashBeforeWritePropose(t *testing.T) { func TestReplayCrashBeforeWritePrevote(t *testing.T) { for _, thisCase := range testCases { - lineNum := 5 + lineNum := thisCase.prevoteLine cs, newBlockCh, voteMsg, f := setupReplayTest(thisCase, lineNum, false) // prevote types.AddListenerForEvent(cs.evsw, "tester", types.EventStringCompleteProposal(), func(data types.TMEventData) { // Set LastSig @@ -185,7 +196,7 @@ func TestReplayCrashBeforeWritePrevote(t *testing.T) { func TestReplayCrashBeforeWritePrecommit(t *testing.T) { for _, thisCase := range testCases { - lineNum := 7 + lineNum := thisCase.precommitLine cs, newBlockCh, voteMsg, f := setupReplayTest(thisCase, lineNum, false) // precommit types.AddListenerForEvent(cs.evsw, "tester", types.EventStringPolka(), func(data types.TMEventData) { // Set LastSig diff --git a/consensus/test_data/small_block.cswal b/consensus/test_data/small_block1.cswal similarity index 100% rename from consensus/test_data/small_block.cswal rename to consensus/test_data/small_block1.cswal diff --git a/consensus/test_data/small_block2.cswal b/consensus/test_data/small_block2.cswal new file mode 100644 index 00000000..fdb07b0b --- /dev/null +++ b/consensus/test_data/small_block2.cswal @@ -0,0 +1,10 @@ +{"time":"2016-10-11T16:21:23.438Z","msg":[3,{"duration":0,"height":1,"round":0,"step":1}]} +{"time":"2016-10-11T16:21:23.440Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPropose"}]} +{"time":"2016-10-11T16:21:23.440Z","msg":[2,{"msg":[17,{"Proposal":{"height":1,"round":0,"block_parts_header":{"total":3,"hash":"88BC082C86DED0A5E2BBC3677B610D155FEDBCEA"},"pol_round":-1,"signature":"8F74F7032E50DFBC17E8B42DD15FD54858B45EEB1B8DAF6432AFBBB1333AC1E850290DE82DF613A10430EB723023527498D45C106FD2946FEF03A9C8B301020B"}}],"peer_key":""}]} +{"time":"2016-10-11T16:21:23.440Z","msg":[2,{"msg":[19,{"Height":1,"Round":0,"Part":{"index":0,"bytes":"0101010F74656E6465726D696E745F746573740101147C86B383BAB78001A60000000001148A3835062BB5E79BE490FAB65168D69BD716AD530114C4B01D3810579550997AC5641E759E20D99B51C1000101A6010F616263643139363D64636261313936010F616263643139373D64636261313937010F616263643139383D64636261313938010F616263643139393D64636261313939010F616263643230303D64636261323030010F616263643230313D64636261323031010F616263643230323D64636261323032010F616263643230333D64636261323033010F616263643230343D64636261323034010F616263643230353D64636261323035010F616263643230363D64636261323036010F616263643230373D64636261323037010F616263643230383D64636261323038010F616263643230393D64636261323039010F616263643231303D64636261323130010F616263643231313D64636261323131010F616263643231323D64636261323132010F616263643231333D64636261323133010F616263643231343D64636261323134010F616263643231353D64636261323135010F616263643231363D64636261323136010F616263643231373D64636261323137010F616263643231383D64636261323138010F616263643231393D64636261323139010F616263643232303D64636261323230010F616263643232313D64636261323231010F616263643232323D64636261323232010F616263643232333D64636261323233010F616263643232343D64636261323234010F616263643232353D64636261323235010F616263643232363D64636261323236010F616263643232373D64636261323237010F616263643232383D64636261323238010F616263643232393D64636261323239010F616263643233303D64636261323330010F616263643233313D64636261323331010F616263643233323D64636261323332010F616263643233333D64636261323333010F616263643233343D64636261323334010F616263643233353D64636261323335010F616263643233363D64636261323336010F616263643233373D64636261323337010F616263643233383D64636261323338010F616263643233393D64636261323339010F616263643234303D64636261323430010F616263643234313D64636261323431010F616263643234323D64636261323432010F616263643234333D64636261323433010F616263643234343D64636261323434010F616263643234353D64636261323435010F616263643234363D64636261323436010F616263643234373D64636261323437010F616263643234383D64636261323438010F616263643234393D64636261323439010F616263643235303D64636261323530010F61626364","proof":{"aunts":["22516491F7E1B5ADD8F12B309E9E8F6F04C034AB","C65A9589F377F2B6CF44B9BAFEBB535DF3C3A4FB"]}}}],"peer_key":""}]} +{"time":"2016-10-11T16:21:23.441Z","msg":[2,{"msg":[19,{"Height":1,"Round":0,"Part":{"index":1,"bytes":"3235313D64636261323531010F616263643235323D64636261323532010F616263643235333D64636261323533010F616263643235343D64636261323534010F616263643235353D64636261323535010F616263643235363D64636261323536010F616263643235373D64636261323537010F616263643235383D64636261323538010F616263643235393D64636261323539010F616263643236303D64636261323630010F616263643236313D64636261323631010F616263643236323D64636261323632010F616263643236333D64636261323633010F616263643236343D64636261323634010F616263643236353D64636261323635010F616263643236363D64636261323636010F616263643236373D64636261323637010F616263643236383D64636261323638010F616263643236393D64636261323639010F616263643237303D64636261323730010F616263643237313D64636261323731010F616263643237323D64636261323732010F616263643237333D64636261323733010F616263643237343D64636261323734010F616263643237353D64636261323735010F616263643237363D64636261323736010F616263643237373D64636261323737010F616263643237383D64636261323738010F616263643237393D64636261323739010F616263643238303D64636261323830010F616263643238313D64636261323831010F616263643238323D64636261323832010F616263643238333D64636261323833010F616263643238343D64636261323834010F616263643238353D64636261323835010F616263643238363D64636261323836010F616263643238373D64636261323837010F616263643238383D64636261323838010F616263643238393D64636261323839010F616263643239303D64636261323930010F616263643239313D64636261323931010F616263643239323D64636261323932010F616263643239333D64636261323933010F616263643239343D64636261323934010F616263643239353D64636261323935010F616263643239363D64636261323936010F616263643239373D64636261323937010F616263643239383D64636261323938010F616263643239393D64636261323939010F616263643330303D64636261333030010F616263643330313D64636261333031010F616263643330323D64636261333032010F616263643330333D64636261333033010F616263643330343D64636261333034010F616263643330353D64636261333035010F616263643330363D64636261333036010F616263643330373D64636261333037010F616263643330383D64636261333038010F616263643330393D64636261333039010F616263643331303D64636261333130010F616263643331313D","proof":{"aunts":["F730990451BAB63C3CF6AC8E6ED4F52259CA5F53","C65A9589F377F2B6CF44B9BAFEBB535DF3C3A4FB"]}}}],"peer_key":""}]} +{"time":"2016-10-11T16:21:23.441Z","msg":[2,{"msg":[19,{"Height":1,"Round":0,"Part":{"index":2,"bytes":"64636261333131010F616263643331323D64636261333132010F616263643331333D64636261333133010F616263643331343D64636261333134010F616263643331353D64636261333135010F616263643331363D64636261333136010F616263643331373D64636261333137010F616263643331383D64636261333138010F616263643331393D64636261333139010F616263643332303D64636261333230010F616263643332313D64636261333231010F616263643332323D64636261333232010F616263643332333D64636261333233010F616263643332343D64636261333234010F616263643332353D64636261333235010F616263643332363D64636261333236010F616263643332373D64636261333237010F616263643332383D64636261333238010F616263643332393D64636261333239010F616263643333303D64636261333330010F616263643333313D64636261333331010F616263643333323D64636261333332010F616263643333333D64636261333333010F616263643333343D64636261333334010F616263643333353D64636261333335010F616263643333363D64636261333336010F616263643333373D64636261333337010F616263643333383D64636261333338010F616263643333393D64636261333339010F616263643334303D64636261333430010F616263643334313D64636261333431010F616263643334323D64636261333432010F616263643334333D64636261333433010F616263643334343D64636261333434010F616263643334353D64636261333435010F616263643334363D64636261333436010F616263643334373D64636261333437010F616263643334383D64636261333438010F616263643334393D64636261333439010F616263643335303D64636261333530010F616263643335313D64636261333531010F616263643335323D64636261333532010F616263643335333D64636261333533010F616263643335343D64636261333534010F616263643335353D64636261333535010F616263643335363D64636261333536010F616263643335373D64636261333537010F616263643335383D64636261333538010F616263643335393D64636261333539010F616263643336303D64636261333630010F616263643336313D646362613336310100","proof":{"aunts":["56EF782EE04E0359D0B38271FD22B312A546FC3A"]}}}],"peer_key":""}]} +{"time":"2016-10-11T16:21:23.447Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPrevote"}]} +{"time":"2016-10-11T16:21:23.447Z","msg":[2,{"msg":[20,{"ValidatorIndex":0,"Vote":{"height":1,"round":0,"type":1,"block_hash":"AAE0ECF64D818A61F6E3D6D11E60F343C3FC8800","block_parts_header":{"total":3,"hash":"88BC082C86DED0A5E2BBC3677B610D155FEDBCEA"},"signature":"0870A9C3FF59DE0F5574B77F030BD160C1E2966AECE815E7C97CFA8BC4A6B01D7A10D91416B1AA02D49EFF7F08A239048CD9CD93E7AE4F80871FBFFF7DBFC50C"}}],"peer_key":""}]} +{"time":"2016-10-11T16:21:23.448Z","msg":[1,{"height":1,"round":0,"step":"RoundStepPrecommit"}]} +{"time":"2016-10-11T16:21:23.448Z","msg":[2,{"msg":[20,{"ValidatorIndex":0,"Vote":{"height":1,"round":0,"type":2,"block_hash":"AAE0ECF64D818A61F6E3D6D11E60F343C3FC8800","block_parts_header":{"total":3,"hash":"88BC082C86DED0A5E2BBC3677B610D155FEDBCEA"},"signature":"0CEEA8A987D88D0A0870C0076DB8D1B57D3B051D017745B46C4710BBE6DF0F9AE8D5A95B49E4158A1A8C8C6475B8A8E91275303B9C10A5C0C18F40EBB0DA0905"}}],"peer_key":""}]} From 71baad59dfa202f0a6a93fe572908dd83dcefd06 Mon Sep 17 00:00:00 2001 From: Ethan Buchman Date: Tue, 11 Oct 2016 16:06:46 -0400 Subject: [PATCH 4/4] replay: ensure cs.height and wal.height match --- blockchain/reactor.go | 2 +- consensus/replay.go | 18 +++++++++++++++--- 2 files changed, 16 insertions(+), 4 deletions(-) diff --git a/blockchain/reactor.go b/blockchain/reactor.go index 9a68ad88..5946e77d 100644 --- a/blockchain/reactor.go +++ b/blockchain/reactor.go @@ -129,7 +129,7 @@ func (bcR *BlockchainReactor) Receive(chID byte, src *p2p.Peer, msgBytes []byte) return } - log.Notice("Receive", "src", src, "chID", chID, "msg", msg) + log.Info("Receive", "src", src, "chID", chID, "msg", msg) switch msg := msg.(type) { case *bcBlockRequestMessage: diff --git a/consensus/replay.go b/consensus/replay.go index c77d0558..afdbcf9f 100644 --- a/consensus/replay.go +++ b/consensus/replay.go @@ -77,7 +77,7 @@ func (cs *ConsensusState) readReplayMessage(msgBytes []byte, newStepCh chan inte // replay only those messages since the last block. // timeoutRoutine should run concurrently to read off tickChan -func (cs *ConsensusState) catchupReplay(height int) error { +func (cs *ConsensusState) catchupReplay(csHeight int) error { if !cs.wal.Exists() { return nil } @@ -88,6 +88,7 @@ func (cs *ConsensusState) catchupReplay(height int) error { // starting from end of file, // read messages until a new height is found + var walHeight int nLines, err := cs.wal.SeekFromEnd(func(lineBytes []byte) bool { var err error var msg ConsensusLogMessage @@ -96,8 +97,8 @@ func (cs *ConsensusState) catchupReplay(height int) error { panic(Fmt("Failed to read cs_msg_log json: %v", err)) } m, ok := msg.Msg.(types.EventDataRoundState) + walHeight = m.Height if ok && m.Step == RoundStepNewHeight.String() { - // TODO: ensure the height matches return true } return false @@ -107,12 +108,23 @@ func (cs *ConsensusState) catchupReplay(height int) error { return err } + // ensure the height matches + if walHeight != csHeight { + var err error + if walHeight > csHeight { + err = errors.New(Fmt("WAL height (%d) exceeds cs height (%d). Is your cs.state corrupted?", walHeight, csHeight)) + } else { + log.Notice("Replay: nothing to do", "cs.height", csHeight, "wal.height", walHeight) + } + return err + } + var beginning bool // if we had to go back to the beginning if c, _ := cs.wal.fp.Seek(0, 1); c == 0 { beginning = true } - log.Notice("Catchup by replaying consensus messages", "n", nLines) + log.Notice("Catchup by replaying consensus messages", "n", nLines, "height", walHeight) // now we can replay the latest nLines on consensus state // note we can't use scan because we've already been reading from the file