diff --git a/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/height_vote_set.go b/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/height_vote_set.go index 691c8d74a305b8c896dc4129f5c1aa5c0c397b16..f0683ae878b37c40abb1742a337e62c7f1acb11c 100644 --- a/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/height_vote_set.go +++ b/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/height_vote_set.go @@ -78,7 +78,7 @@ func (hvs *HeightVoteSet) addRound(round int) { if _, ok := hvs.roundVoteSets[round]; ok { PanicSanity("addRound() for an existing round") } - log.Info("addRound(round)", "round", round) + log.Debug("addRound(round)", "round", round) prevotes := NewVoteSet(hvs.height, round, types.VoteTypePrevote, hvs.valSet) precommits := NewVoteSet(hvs.height, round, types.VoteTypePrecommit, hvs.valSet) hvs.roundVoteSets[round] = RoundVoteSet{ @@ -135,7 +135,7 @@ func (hvs *HeightVoteSet) POLRound() int { } func (hvs *HeightVoteSet) getVoteSet(round int, type_ byte) *VoteSet { - log.Info("getVoteSet(round)", "round", round, "type", type_) + log.Debug("getVoteSet(round)", "round", round, "type", type_) rvs, ok := hvs.roundVoteSets[round] if !ok { return nil diff --git a/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/reactor.go b/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/reactor.go index b1157ef7f422b0d59128c72fd769f93d03dd7798..218ff002dd4310a43487df55fffca357b78db1bc 100644 --- a/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/reactor.go +++ b/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/reactor.go @@ -342,7 +342,7 @@ OUTER_LOOP: // Send proposal Block parts? if rs.ProposalBlockParts.HasHeader(prs.ProposalBlockPartsHeader) { - //log.Info("ProposalBlockParts matched", "blockParts", prs.ProposalBlockParts) + //log.Debug("ProposalBlockParts matched", "blockParts", prs.ProposalBlockParts) if index, ok := rs.ProposalBlockParts.BitArray().Sub(prs.ProposalBlockParts.Copy()).PickRandom(); ok { part := rs.ProposalBlockParts.GetPart(index) msg := &BlockPartMessage{ @@ -358,12 +358,12 @@ OUTER_LOOP: // If the peer is on a previous height, help catch up. if (0 < prs.Height) && (prs.Height < rs.Height) { - //log.Info("Data catchup", "height", rs.Height, "peerHeight", prs.Height, "peerProposalBlockParts", prs.ProposalBlockParts) + //log.Debug("Data catchup", "height", rs.Height, "peerHeight", prs.Height, "peerProposalBlockParts", prs.ProposalBlockParts) if index, ok := prs.ProposalBlockParts.Not().PickRandom(); ok { // Ensure that the peer's PartSetHeader is correct blockMeta := conR.blockStore.LoadBlockMeta(prs.Height) if !blockMeta.PartsHeader.Equals(prs.ProposalBlockPartsHeader) { - log.Info("Peer ProposalBlockPartsHeader mismatch, sleeping", + log.Debug("Peer ProposalBlockPartsHeader mismatch, sleeping", "peerHeight", prs.Height, "blockPartsHeader", blockMeta.PartsHeader, "peerBlockPartsHeader", prs.ProposalBlockPartsHeader) time.Sleep(peerGossipSleepDuration) continue OUTER_LOOP @@ -386,7 +386,7 @@ OUTER_LOOP: ps.SetHasProposalBlockPart(prs.Height, prs.Round, index) continue OUTER_LOOP } else { - //log.Info("No parts to send in catch-up, sleeping") + //log.Debug("No parts to send in catch-up, sleeping") time.Sleep(peerGossipSleepDuration) continue OUTER_LOOP } @@ -394,7 +394,7 @@ OUTER_LOOP: // If height and round don't match, sleep. if (rs.Height != prs.Height) || (rs.Round != prs.Round) { - //log.Info("Peer Height|Round mismatch, sleeping", "peerHeight", prs.Height, "peerRound", prs.Round, "peer", peer) + //log.Debug("Peer Height|Round mismatch, sleeping", "peerHeight", prs.Height, "peerRound", prs.Round, "peer", peer) time.Sleep(peerGossipSleepDuration) continue OUTER_LOOP } @@ -464,35 +464,35 @@ OUTER_LOOP: // If there are lastCommits to send... if prs.Step == RoundStepNewHeight { if ps.PickSendVote(rs.LastCommit) { - log.Info("Picked rs.LastCommit to send") + log.Debug("Picked rs.LastCommit to send") continue OUTER_LOOP } } // If there are prevotes to send... if rs.Round == prs.Round && prs.Step <= RoundStepPrevote { if ps.PickSendVote(rs.Votes.Prevotes(rs.Round)) { - log.Info("Picked rs.Prevotes(rs.Round) to send") + log.Debug("Picked rs.Prevotes(rs.Round) to send") continue OUTER_LOOP } } // If there are precommits to send... if rs.Round == prs.Round && prs.Step <= RoundStepPrecommit { if ps.PickSendVote(rs.Votes.Precommits(rs.Round)) { - log.Info("Picked rs.Precommits(rs.Round) to send") + log.Debug("Picked rs.Precommits(rs.Round) to send") continue OUTER_LOOP } } // If there are prevotes to send for the last round... if rs.Round == prs.Round+1 && prs.Step <= RoundStepPrevote { if ps.PickSendVote(rs.Votes.Prevotes(prs.Round)) { - log.Info("Picked rs.Prevotes(prs.Round) to send") + log.Debug("Picked rs.Prevotes(prs.Round) to send") continue OUTER_LOOP } } // If there are precommits to send for the last round... if rs.Round == prs.Round+1 && prs.Step <= RoundStepPrecommit { if ps.PickSendVote(rs.Votes.Precommits(prs.Round)) { - log.Info("Picked rs.Precommits(prs.Round) to send") + log.Debug("Picked rs.Precommits(prs.Round) to send") continue OUTER_LOOP } } @@ -500,7 +500,7 @@ OUTER_LOOP: if 0 <= prs.ProposalPOLRound { if polPrevotes := rs.Votes.Prevotes(prs.ProposalPOLRound); polPrevotes != nil { if ps.PickSendVote(polPrevotes) { - log.Info("Picked rs.Prevotes(prs.ProposalPOLRound) to send") + log.Debug("Picked rs.Prevotes(prs.ProposalPOLRound) to send") continue OUTER_LOOP } } @@ -511,7 +511,7 @@ OUTER_LOOP: // If peer is lagging by height 1, send LastCommit. if prs.Height != 0 && rs.Height == prs.Height+1 { if ps.PickSendVote(rs.LastCommit) { - log.Info("Picked rs.LastCommit to send") + log.Debug("Picked rs.LastCommit to send") continue OUTER_LOOP } } @@ -522,9 +522,9 @@ OUTER_LOOP: // Load the block validation for prs.Height, // which contains precommit signatures for prs.Height. validation := conR.blockStore.LoadBlockValidation(prs.Height) - log.Info("Loaded BlockValidation for catch-up", "height", prs.Height, "validation", validation) + log.Debug("Loaded BlockValidation for catch-up", "height", prs.Height, "validation", validation) if ps.PickSendVote(validation) { - log.Info("Picked Catchup validation to send") + log.Debug("Picked Catchup validation to send") continue OUTER_LOOP } } @@ -532,7 +532,7 @@ OUTER_LOOP: if sleeping == 0 { // We sent nothing. Sleep... sleeping = 1 - log.Info("No votes to send, sleeping", "peer", peer, + log.Debug("No votes to send, sleeping", "peer", peer, "localPV", rs.Votes.Prevotes(rs.Round).BitArray(), "peerPV", prs.Prevotes, "localPC", rs.Votes.Precommits(rs.Round).BitArray(), "peerPC", prs.Precommits) } else if sleeping == 2 { @@ -768,23 +768,23 @@ func (ps *PeerState) setHasVote(height int, round int, type_ byte, index int) { switch type_ { case types.VoteTypePrevote: ps.Prevotes.SetIndex(index, true) - log.Info("SetHasVote(round-match)", "prevotes", ps.Prevotes, "index", index) + log.Debug("SetHasVote(round-match)", "prevotes", ps.Prevotes, "index", index) case types.VoteTypePrecommit: ps.Precommits.SetIndex(index, true) - log.Info("SetHasVote(round-match)", "precommits", ps.Precommits, "index", index) + log.Debug("SetHasVote(round-match)", "precommits", ps.Precommits, "index", index) } } else if ps.CatchupCommitRound == round { switch type_ { case types.VoteTypePrevote: case types.VoteTypePrecommit: ps.CatchupCommit.SetIndex(index, true) - log.Info("SetHasVote(CatchupCommit)", "precommits", ps.Precommits, "index", index) + log.Debug("SetHasVote(CatchupCommit)", "precommits", ps.Precommits, "index", index) } } else if ps.ProposalPOLRound == round { switch type_ { case types.VoteTypePrevote: ps.ProposalPOL.SetIndex(index, true) - log.Info("SetHasVote(ProposalPOL)", "prevotes", ps.Prevotes, "index", index) + log.Debug("SetHasVote(ProposalPOL)", "prevotes", ps.Prevotes, "index", index) case types.VoteTypePrecommit: } } @@ -794,7 +794,7 @@ func (ps *PeerState) setHasVote(height int, round int, type_ byte, index int) { case types.VoteTypePrevote: case types.VoteTypePrecommit: ps.LastCommit.SetIndex(index, true) - log.Info("setHasVote(LastCommit)", "lastCommit", ps.LastCommit, "index", index) + log.Debug("setHasVote(LastCommit)", "lastCommit", ps.LastCommit, "index", index) } } } else { diff --git a/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/state.go b/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/state.go index c92867723bfdce886a4f134e796802c8a2729bbb..32cec68c1abd571e74ffe6e56917acdef890c41d 100644 --- a/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/state.go +++ b/Godeps/_workspace/src/github.com/tendermint/tendermint/consensus/state.go @@ -372,7 +372,7 @@ func (cs *ConsensusState) OnStop() { // EnterNewRound(height, 0) at cs.StartTime. func (cs *ConsensusState) scheduleRound0(height int) { - //log.Info("scheduleRound0", "now", time.Now(), "startTime", cs.StartTime) + //log.Debug("scheduleRound0", "now", time.Now(), "startTime", cs.StartTime) sleepDuration := cs.StartTime.Sub(time.Now()) go func() { if 0 < sleepDuration { @@ -489,7 +489,7 @@ func (cs *ConsensusState) EnterNewRound(height int, round int) { cs.mtx.Lock() defer cs.mtx.Unlock() if cs.Height != height || round < cs.Round || (cs.Round == round && cs.Step != RoundStepNewHeight) { - log.Info(Fmt("EnterNewRound(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterNewRound(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) return } if now := time.Now(); cs.StartTime.After(now) { @@ -528,10 +528,10 @@ func (cs *ConsensusState) EnterPropose(height int, round int) { cs.mtx.Lock() defer cs.mtx.Unlock() if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPropose <= cs.Step) { - log.Info(Fmt("EnterPropose(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPropose(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) return } - log.Info(Fmt("EnterPropose(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPropose(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) defer func() { // Done EnterPropose: @@ -557,9 +557,9 @@ func (cs *ConsensusState) EnterPropose(height int, round int) { } if !bytes.Equal(cs.Validators.Proposer().Address, cs.privValidator.Address) { - log.Info("EnterPropose: Not our turn to propose", "proposer", cs.Validators.Proposer().Address, "privValidator", cs.privValidator) + log.Debug("EnterPropose: Not our turn to propose", "proposer", cs.Validators.Proposer().Address, "privValidator", cs.privValidator) } else { - log.Info("EnterPropose: Our turn to propose", "proposer", cs.Validators.Proposer().Address, "privValidator", cs.privValidator) + log.Debug("EnterPropose: Our turn to propose", "proposer", cs.Validators.Proposer().Address, "privValidator", cs.privValidator) cs.decideProposal(height, round) } } @@ -582,8 +582,8 @@ func (cs *ConsensusState) decideProposal(height int, round int) { proposal := NewProposal(height, round, blockParts.Header(), cs.Votes.POLRound()) err := cs.privValidator.SignProposal(cs.state.ChainID, proposal) if err == nil { - log.Notice("Signed and set proposal", "height", height, "round", round, "proposal", proposal) - log.Info(Fmt("Signed and set proposal block: %v", block)) + log.Debug("Signed and set proposal", "height", height, "round", round, "proposal", proposal) + log.Debug(Fmt("Signed and set proposal block: %v", block)) // Set fields cs.Proposal = proposal cs.ProposalBlock = block @@ -661,10 +661,10 @@ func (cs *ConsensusState) EnterPrevote(height int, round int) { cs.mtx.Lock() defer cs.mtx.Unlock() if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrevote <= cs.Step) { - log.Info(Fmt("EnterPrevote(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPrevote(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) return } - log.Info(Fmt("EnterPrevote(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPrevote(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) // Sign and broadcast vote as necessary cs.doPrevote(height, round) @@ -682,7 +682,7 @@ func (cs *ConsensusState) EnterPrevote(height int, round int) { func (cs *ConsensusState) doPrevote(height int, round int) { // If a block is locked, prevote that. if cs.LockedBlock != nil { - log.Info("EnterPrevote: Block was locked") + log.Debug("EnterPrevote: Block was locked") cs.signAddVote(types.VoteTypePrevote, cs.LockedBlock.Hash(), cs.LockedBlockParts.Header()) return } @@ -713,13 +713,13 @@ func (cs *ConsensusState) EnterPrevoteWait(height int, round int) { cs.mtx.Lock() defer cs.mtx.Unlock() if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrevoteWait <= cs.Step) { - log.Info(Fmt("EnterPrevoteWait(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPrevoteWait(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) return } if !cs.Votes.Prevotes(round).HasTwoThirdsAny() { PanicSanity(Fmt("EnterPrevoteWait(%v/%v), but Prevotes does not have any +2/3 votes", height, round)) } - log.Info(Fmt("EnterPrevoteWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPrevoteWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) // Done EnterPrevoteWait: cs.Round = round @@ -743,10 +743,10 @@ func (cs *ConsensusState) EnterPrecommit(height int, round int) { cs.mtx.Lock() defer cs.mtx.Unlock() if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrecommit <= cs.Step) { - log.Info(Fmt("EnterPrecommit(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPrecommit(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) return } - log.Info(Fmt("EnterPrecommit(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPrecommit(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) defer func() { // Done EnterPrecommit: @@ -764,10 +764,10 @@ func (cs *ConsensusState) EnterPrecommit(height int, round int) { // If we don't have two thirds of prevotes, just precommit locked block or nil if !ok { if cs.LockedBlock != nil { - log.Info("EnterPrecommit: No +2/3 prevotes during EnterPrecommit. Precommitting lock.") + log.Debug("EnterPrecommit: No +2/3 prevotes during EnterPrecommit. Precommitting lock.") cs.signAddVote(types.VoteTypePrecommit, cs.LockedBlock.Hash(), cs.LockedBlockParts.Header()) } else { - log.Info("EnterPrecommit: No +2/3 prevotes during EnterPrecommit. Precommitting nil.") + log.Debug("EnterPrecommit: No +2/3 prevotes during EnterPrecommit. Precommitting nil.") cs.signAddVote(types.VoteTypePrecommit, nil, types.PartSetHeader{}) } return @@ -776,9 +776,9 @@ func (cs *ConsensusState) EnterPrecommit(height int, round int) { // +2/3 prevoted nil. Unlock and precommit nil. if len(hash) == 0 { if cs.LockedBlock == nil { - log.Info("EnterPrecommit: +2/3 prevoted for nil.") + log.Debug("EnterPrecommit: +2/3 prevoted for nil.") } else { - log.Info("EnterPrecommit: +2/3 prevoted for nil. Unlocking") + log.Debug("EnterPrecommit: +2/3 prevoted for nil. Unlocking") cs.LockedRound = 0 cs.LockedBlock = nil cs.LockedBlockParts = nil @@ -791,14 +791,14 @@ func (cs *ConsensusState) EnterPrecommit(height int, round int) { // If +2/3 prevoted for already locked block, precommit it. if cs.LockedBlock.HashesTo(hash) { - log.Info("EnterPrecommit: +2/3 prevoted locked block.") + log.Debug("EnterPrecommit: +2/3 prevoted locked block.") cs.signAddVote(types.VoteTypePrecommit, hash, partsHeader) return } // If +2/3 prevoted for proposal block, stage and precommit it if cs.ProposalBlock.HashesTo(hash) { - log.Info("EnterPrecommit: +2/3 prevoted proposal block.") + log.Debug("EnterPrecommit: +2/3 prevoted proposal block.") // Validate the block. if err := cs.stageBlock(cs.ProposalBlock, cs.ProposalBlockParts); err != nil { PanicConsensus(Fmt("EnterPrecommit: +2/3 prevoted for an invalid block: %v", err)) @@ -832,13 +832,13 @@ func (cs *ConsensusState) EnterPrecommitWait(height int, round int) { cs.mtx.Lock() defer cs.mtx.Unlock() if cs.Height != height || round < cs.Round || (cs.Round == round && RoundStepPrecommitWait <= cs.Step) { - log.Info(Fmt("EnterPrecommitWait(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPrecommitWait(%v/%v): Invalid args. Current step: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) return } if !cs.Votes.Precommits(round).HasTwoThirdsAny() { PanicSanity(Fmt("EnterPrecommitWait(%v/%v), but Precommits does not have any +2/3 votes", height, round)) } - log.Info(Fmt("EnterPrecommitWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterPrecommitWait(%v/%v). Current: %v/%v/%v", height, round, cs.Height, cs.Round, cs.Step)) // Done EnterPrecommitWait: cs.Round = round @@ -861,10 +861,10 @@ func (cs *ConsensusState) EnterCommit(height int) { cs.mtx.Lock() defer cs.mtx.Unlock() if cs.Height != height || RoundStepCommit <= cs.Step { - log.Info(Fmt("EnterCommit(%v): Invalid args. Current step: %v/%v/%v", height, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterCommit(%v): Invalid args. Current step: %v/%v/%v", height, cs.Height, cs.Round, cs.Step)) return } - log.Info(Fmt("EnterCommit(%v). Current: %v/%v/%v", height, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("EnterCommit(%v). Current: %v/%v/%v", height, cs.Height, cs.Round, cs.Step)) defer func() { // Done Entercommit: @@ -931,7 +931,7 @@ func (cs *ConsensusState) FinalizeCommit(height int) { defer cs.mtx.Unlock() if cs.Height != height || cs.Step != RoundStepCommit { - log.Info(Fmt("FinalizeCommit(%v): Invalid args. Current step: %v/%v/%v", height, cs.Height, cs.Round, cs.Step)) + log.Debug(Fmt("FinalizeCommit(%v): Invalid args. Current step: %v/%v/%v", height, cs.Height, cs.Round, cs.Step)) return } @@ -950,7 +950,7 @@ func (cs *ConsensusState) FinalizeCommit(height int) { PanicConsensus(Fmt("+2/3 committed an invalid block: %v", err)) } - log.Info(Fmt("Finalizing commit of block: %v", cs.ProposalBlock)) + log.Debug(Fmt("Finalizing commit of block: %v", cs.ProposalBlock)) // We have the block, so stage/save/commit-vote. cs.saveBlock(cs.ProposalBlock, cs.ProposalBlockParts, cs.Votes.Precommits(cs.Round)) // Increment height. @@ -1029,7 +1029,7 @@ func (cs *ConsensusState) AddProposalBlockPart(height int, part *types.Part) (ad var n int64 var err error cs.ProposalBlock = wire.ReadBinary(&types.Block{}, cs.ProposalBlockParts.GetReader(), &n, &err).(*types.Block) - log.Info("Received complete proposal", "hash", cs.ProposalBlock.Hash()) + log.Debug("Received complete proposal", "hash", cs.ProposalBlock.Hash()) if cs.Step == RoundStepPropose && cs.isProposalComplete() { // Move onto the next step go cs.EnterPrevote(height, cs.Round) @@ -1052,13 +1052,13 @@ func (cs *ConsensusState) AddVote(address []byte, vote *types.Vote, peerKey stri //----------------------------------------------------------------------------- func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey string) (added bool, index int, err error) { - log.Info("addVote", "voteHeight", vote.Height, "voteType", vote.Type, "csHeight", cs.Height) + log.Debug("addVote", "voteHeight", vote.Height, "voteType", vote.Type, "csHeight", cs.Height) // A precommit for the previous height? if vote.Height+1 == cs.Height && vote.Type == types.VoteTypePrecommit { added, index, err = cs.LastCommit.AddByAddress(address, vote) if added { - log.Info(Fmt("Added to lastPrecommits: %v", cs.LastCommit.StringShort())) + log.Debug(Fmt("Added to lastPrecommits: %v", cs.LastCommit.StringShort())) } return } @@ -1071,7 +1071,7 @@ func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey stri switch vote.Type { case types.VoteTypePrevote: prevotes := cs.Votes.Prevotes(vote.Round) - log.Info(Fmt("Added to prevotes: %v", prevotes.StringShort())) + log.Debug(Fmt("Added to prevotes: %v", prevotes.StringShort())) // First, unlock if prevotes is a valid POL. // >> lockRound < POLRound <= unlockOrChangeLockRound (see spec) // NOTE: If (lockRound < POLRound) but !(POLRound <= unlockOrChangeLockRound), @@ -1107,7 +1107,7 @@ func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey stri } case types.VoteTypePrecommit: precommits := cs.Votes.Precommits(vote.Round) - log.Info(Fmt("Added to precommit: %v", precommits.StringShort())) + log.Debug(Fmt("Added to precommit: %v", precommits.StringShort())) if cs.Round <= vote.Round && precommits.HasTwoThirdsAny() { go func() { hash, _, ok := precommits.TwoThirdsMajority() @@ -1134,7 +1134,7 @@ func (cs *ConsensusState) addVote(address []byte, vote *types.Vote, peerKey stri } // Height mismatch, bad peer? - log.Info("Vote ignored and not added", "voteHeight", vote.Height, "csHeight", cs.Height) + log.Debug("Vote ignored and not added", "voteHeight", vote.Height, "csHeight", cs.Height) return } @@ -1181,7 +1181,7 @@ func (cs *ConsensusState) signAddVote(type_ byte, hash []byte, header types.Part err := cs.privValidator.SignVote(cs.state.ChainID, vote) if err == nil { _, _, err := cs.addVote(cs.privValidator.Address, vote, "") - log.Notice("Signed and added vote", "height", cs.Height, "round", cs.Round, "vote", vote, "error", err) + log.Debug("Signed and added vote", "height", cs.Height, "round", cs.Round, "vote", vote, "error", err) return vote } else { log.Warn("Error signing vote", "height", cs.Height, "round", cs.Round, "vote", vote, "error", err) diff --git a/Godeps/_workspace/src/github.com/tendermint/tendermint/p2p/switch.go b/Godeps/_workspace/src/github.com/tendermint/tendermint/p2p/switch.go index 7d9fcb521524a455465c2cad96be57761b3cba31..3491319a8275dcbb46c0f051ea9e047eb0f0166a 100644 --- a/Godeps/_workspace/src/github.com/tendermint/tendermint/p2p/switch.go +++ b/Godeps/_workspace/src/github.com/tendermint/tendermint/p2p/switch.go @@ -283,7 +283,7 @@ func (sw *Switch) IsDialing(addr *NetAddress) bool { // which receives success values for each attempted send (false if times out) func (sw *Switch) Broadcast(chId byte, msg interface{}) chan bool { successChan := make(chan bool, len(sw.peers.List())) - log.Info("Broadcast", "channel", chId, "msg", msg) + log.Debug("Broadcast", "channel", chId, "msg", msg) for _, peer := range sw.peers.List() { go func(peer *Peer) { success := peer.Send(chId, msg) diff --git a/Godeps/_workspace/src/github.com/tendermint/tendermint/vm/vm.go b/Godeps/_workspace/src/github.com/tendermint/tendermint/vm/vm.go index c0ea1b0ee75eb77f6c878e7930c3c334a574d5b9..9eb275701ff42abfc2aee24f07837d1e9a71e507 100644 --- a/Godeps/_workspace/src/github.com/tendermint/tendermint/vm/vm.go +++ b/Godeps/_workspace/src/github.com/tendermint/tendermint/vm/vm.go @@ -42,7 +42,7 @@ const ( dataStackCapacity = 1024 callStackCapacity = 100 // TODO ensure usage. memoryCapacity = 1024 * 1024 // 1 MB - dbg Debug = true + dbg Debug = false ) func (d Debug) Printf(s string, a ...interface{}) { @@ -703,7 +703,6 @@ func (vm *VM) call(caller, callee *Account, code, input []byte, value int64, gas vm.appState.AddLog(log) if vm.evc != nil { eventId := types.EventStringLogEvent(callee.Address.Postfix(20)) - fmt.Printf("eventId: %s\n", eventId) vm.evc.FireEvent(eventId, log) } // Using sol-log for this as well since 'log' will print garbage. diff --git a/README.md b/README.md index e3744866893af86d6e2bbb6917070090b6f34d80..d2bbd08c1487db2146b45766b578b91e5c552a02 100644 --- a/README.md +++ b/README.md @@ -144,8 +144,8 @@ json_rpc_endpoint="/rpc" [web_socket] websocket_endpoint="/socketrpc" max_websocket_sessions=50 -read_buffer_size = 2048 -write_buffer_size = 2048 +read_buffer_size = 4096 +write_buffer_size = 4096 [logging] console_log_level="info" file_log_level="warn" diff --git a/erisdb/json_service.go b/erisdb/json_service.go index d80255f97a1e4a751a019ad039d601ef31e952ba..c08eec29eaa8a848daa828c335c5ba922b5324dc 100644 --- a/erisdb/json_service.go +++ b/erisdb/json_service.go @@ -2,7 +2,6 @@ package erisdb import ( "encoding/json" - "fmt" "github.com/eris-ltd/eris-db/Godeps/_workspace/src/github.com/gin-gonic/gin" ep "github.com/eris-ltd/eris-db/erisdb/pipe" rpc "github.com/eris-ltd/eris-db/rpc" @@ -117,10 +116,10 @@ func (this *ErisDbJsonService) writeError(msg, id string, code int, w http.Respo // Helper for writing responses. func (this *ErisDbJsonService) writeResponse(id string, result interface{}, w http.ResponseWriter) { - fmt.Printf("Result: %v\n", result) + log.Debug("Result: %v\n", result) response := rpc.NewRPCResponse(id, result) err := this.codec.Encode(response, w) - fmt.Printf("Response: %v\n", response) + log.Debug("Response: %v\n", response) if err != nil { this.writeError("Internal error: "+err.Error(), id, rpc.INTERNAL_ERROR, w) return diff --git a/erisdb/methods.go b/erisdb/methods.go index 13fe8744eebd5fd84e6239d506b747de4df3a3e9..7a27628da3939ec2b4edb1ae0102017fa8c006b4 100644 --- a/erisdb/methods.go +++ b/erisdb/methods.go @@ -3,7 +3,6 @@ package erisdb import ( "crypto/rand" "encoding/hex" - "fmt" "github.com/eris-ltd/eris-db/Godeps/_workspace/src/github.com/tendermint/tendermint/types" ep "github.com/eris-ltd/eris-db/erisdb/pipe" rpc "github.com/eris-ltd/eris-db/rpc" @@ -151,12 +150,10 @@ func (this *ErisDbMethods) Account(request *rpc.RPCRequest, requester interface{ func (this *ErisDbMethods) Accounts(request *rpc.RPCRequest, requester interface{}) (interface{}, int, error) { param := &AccountsParam{} - fmt.Printf("ACCOUNT LIST REQUEST: %v\n", request) err := this.codec.DecodeBytes(param, request.Params) if err != nil { return nil, rpc.INVALID_PARAMS, err } - fmt.Printf("PARAMS: %v\n", param) list, errC := this.pipe.Accounts().Accounts(param.Filters) if errC != nil { return nil, rpc.INTERNAL_ERROR, errC @@ -473,12 +470,10 @@ func (this *ErisDbMethods) NameRegEntry(request *rpc.RPCRequest, requester inter func (this *ErisDbMethods) NameRegEntries(request *rpc.RPCRequest, requester interface{}) (interface{}, int, error) { param := &FilterListParam{} - fmt.Printf("ACCOUNT LIST REQUEST: %v\n", request) err := this.codec.DecodeBytes(param, request.Params) if err != nil { return nil, rpc.INVALID_PARAMS, err } - fmt.Printf("PARAMS: %v\n", param) list, errC := this.pipe.NameReg().Entries(param.Filters) if errC != nil { return nil, rpc.INTERNAL_ERROR, errC diff --git a/erisdb/pipe/transactor.go b/erisdb/pipe/transactor.go index 19b9c7b4fb49f847fe2fd9331bb0b6644f4d6d20..a0cfb8b4eba83b59605f7779ef4b1ad6ff3665bf 100644 --- a/erisdb/pipe/transactor.go +++ b/erisdb/pipe/transactor.go @@ -12,6 +12,7 @@ import ( "github.com/eris-ltd/eris-db/Godeps/_workspace/src/github.com/tendermint/tendermint/state" "github.com/eris-ltd/eris-db/Godeps/_workspace/src/github.com/tendermint/tendermint/types" "github.com/eris-ltd/eris-db/Godeps/_workspace/src/github.com/tendermint/tendermint/vm" + "sync" "time" ) @@ -20,6 +21,7 @@ type transactor struct { consensusState *cs.ConsensusState mempoolReactor *mempl.MempoolReactor eventEmitter EventEmitter + txMtx *sync.Mutex } func newTransactor(eventSwitch tEvents.Fireable, consensusState *cs.ConsensusState, mempoolReactor *mempl.MempoolReactor, eventEmitter EventEmitter) *transactor { @@ -28,6 +30,7 @@ func newTransactor(eventSwitch tEvents.Fireable, consensusState *cs.ConsensusSta consensusState, mempoolReactor, eventEmitter, + &sync.Mutex{}, } return txs } @@ -132,7 +135,8 @@ func (this *transactor) Transact(privKey, address, data []byte, gasLimit, fee in } pk := &[64]byte{} copy(pk[:], privKey) - fmt.Printf("PK BYTES FROM TRANSACT: %x\n", pk) + this.txMtx.Lock() + defer this.txMtx.Unlock() pa := account.GenPrivAccountFromPrivKeyBytes(pk) cache := this.mempoolReactor.Mempool.GetCache() acc := cache.GetAccount(pa.Address) @@ -142,6 +146,7 @@ func (this *transactor) Transact(privKey, address, data []byte, gasLimit, fee in } else { sequence = acc.Sequence + 1 } + // fmt.Printf("Sequence %d\n", sequence) txInput := &types.TxInput{ Address: pa.Address, Amount: 1, @@ -155,6 +160,7 @@ func (this *transactor) Transact(privKey, address, data []byte, gasLimit, fee in Fee: fee, Data: data, } + // Got ourselves a tx. txS, errS := this.SignTx(tx, []*account.PrivAccount{pa}) if errS != nil { @@ -182,13 +188,13 @@ func (this *transactor) TransactAndHold(privKey, address, data []byte, gasLimit, wc <- &event } }) - - timer := time.NewTimer(10 * time.Second) + + timer := time.NewTimer(300 * time.Second) toChan := timer.C - + var ret *types.EventMsgCall var rErr error - + select { case <-toChan: rErr = fmt.Errorf("Transaction timed out. Hash: " + subId) @@ -211,7 +217,8 @@ func (this *transactor) TransactNameReg(privKey []byte, name, data string, amoun } pk := &[64]byte{} copy(pk[:], privKey) - fmt.Printf("PK BYTES FROM TRANSACT NAMEREG: %x\n", pk) + this.txMtx.Lock() + defer this.txMtx.Unlock() pa := account.GenPrivAccountFromPrivKeyBytes(pk) cache := this.mempoolReactor.Mempool.GetCache() acc := cache.GetAccount(pa.Address) diff --git a/erisdb/serve.go b/erisdb/serve.go index 7fdd1eb64fa37ff1493f734521048e5400cfcd6a..2f9bcd608b93b0f33f758fed36d7357ffdf7d632 100644 --- a/erisdb/serve.go +++ b/erisdb/serve.go @@ -14,7 +14,7 @@ import ( "path" ) -const ERISDB_VERSION = "0.11.2" +const ERISDB_VERSION = "0.11.5" const TENDERMINT_VERSION = "0.5.0" var log = log15.New("module", "eris/erisdb_server") diff --git a/erisdb/wsService.go b/erisdb/wsService.go index 258cccea795696acba82149b0b616528286a62f6..cd19e36ba47b98fa74c3a367599cd9c05c5538c8 100644 --- a/erisdb/wsService.go +++ b/erisdb/wsService.go @@ -30,7 +30,7 @@ func NewErisDbWsService(codec rpc.Codec, pipe ep.Pipe) server.WebSocketService { // Process a request. func (this *ErisDbWsService) Process(msg []byte, session *server.WSSession) { - fmt.Printf("REQUEST: %s\n", string(msg)) + log.Debug("REQUEST: %s\n", string(msg)) // Create new request object and unmarshal. req := &rpc.RPCRequest{} errU := json.Unmarshal(msg, req) @@ -76,7 +76,7 @@ func (this *ErisDbWsService) writeError(msg, id string, code int, session *serve func (this *ErisDbWsService) writeResponse(id string, result interface{}, session *server.WSSession) { response := rpc.NewRPCResponse(id, result) bts, err := this.codec.EncodeBytes(response) - fmt.Printf("Response: %v\n", response) + log.Debug("RESPONSE: %v\n", response) if err != nil { this.writeError("Internal error: "+err.Error(), id, rpc.INTERNAL_ERROR, session) return diff --git a/server/config.go b/server/config.go index 0faa65726b1412a4b780459f4684ab3cd10bd4e3..bd84d4766feb99d6ce55051fcf17a90a788d945a 100644 --- a/server/config.go +++ b/server/config.go @@ -73,8 +73,8 @@ func DefaultServerConfig() *ServerConfig { WebSocket: WebSocket{ WebSocketEndpoint: "/socketrpc", MaxWebSocketSessions: 50, - ReadBufferSize: 2048, - WriteBufferSize: 2048, + ReadBufferSize: 4096, + WriteBufferSize: 4096, }, Logging: Logging{ ConsoleLogLevel: "info", diff --git a/server/websocket.go b/server/websocket.go index 78563f6ca05751deb5ad4b7f4283db316e380154..377de80ebe01471373abe35263580c1521f0eb1a 100644 --- a/server/websocket.go +++ b/server/websocket.go @@ -13,18 +13,14 @@ import ( // to net in connections/session management. At some point... const ( - // Size of read channel. - readChanBufferSize = 10 - // Size of write channel. - writeChanBufferSize = 10 // Time allowed to write a message to the peer. - writeWait = 10 * time.Second + writeWait = 0 * time.Second // Time allowed to read the next pong message from the peer. - pongWait = 10 * time.Second + pongWait = 0 * time.Second // Send pings to peer with this period. Must be less than pongWait. - pingPeriod = (pongWait * 9) / 10 + pingPeriod = 0 * time.Second // Maximum message size allowed from a peer. - maxMessageSize = 2048 + maxMessageSize = 1000000 ) // Services requests. Message bytes are passed along with the session @@ -175,7 +171,7 @@ func (this *WSSession) Close() { this.closed = true this.wsConn.Close() this.sessionManager.removeSession(this.id) - log.Debug("Closing websocket connection.", "sessionId", this.id, "remaining", len(this.sessionManager.activeSessions)) + log.Info("Closing websocket connection.", "sessionId", this.id, "remaining", len(this.sessionManager.activeSessions)) this.sessionManager.notifyClosed(this) } } @@ -213,8 +209,8 @@ func (this *WSSession) readPump() { }() */ this.wsConn.SetReadLimit(maxMessageSize) - this.wsConn.SetReadDeadline(time.Now().Add(pongWait)) - this.wsConn.SetPongHandler(func(string) error { this.wsConn.SetReadDeadline(time.Now().Add(pongWait)); return nil }) + // this.wsConn.SetReadDeadline(time.Now().Add(pongWait)) + // this.wsConn.SetPongHandler(func(string) error { this.wsConn.SetReadDeadline(time.Now().Add(pongWait)); return nil }) for { // Read @@ -223,33 +219,21 @@ func (this *WSSession) readPump() { // Read error. if err != nil { // Socket could have been gracefully closed, so not really an error. - log.Debug("Socket closed. Removing.", "error", err.Error()) + log.Info("Socket closed. Removing.", "error", err.Error()) this.writeCloseChan <- struct{}{} return } - // Wrong message type. + if msgType != websocket.TextMessage { - var typeStr string - if msgType == websocket.BinaryMessage { - typeStr = "Binary" - } else if msgType == websocket.CloseMessage { - typeStr = "Close" - } else if msgType == websocket.PingMessage { - typeStr = "Ping" - } else if msgType == websocket.PingMessage { - typeStr = "Pong" - } else { - // This should not be possible. - typeStr = "Unknown ID: " + fmt.Sprintf("%d", msgType) - } - - log.Info("Receiving non text-message from client, closing.", "type", typeStr) + log.Info("Receiving non text-message from client, closing.") this.writeCloseChan <- struct{}{} return } - - // Process the request. - this.service.Process(msg, this) + + go func(){ + // Process the request. + this.service.Process(msg, this) + }() } } @@ -268,10 +252,10 @@ func (this *WSSession) writePump() { wpm.Unlock() }() */ - ticker := time.NewTicker(pingPeriod) + // ticker := time.NewTicker(pingPeriod) defer func() { - ticker.Stop() + // ticker.Stop() this.Close() }() @@ -291,12 +275,15 @@ func (this *WSSession) writePump() { case <-this.writeCloseChan: return // Ticker run out. Time for another ping message. + /* case <-ticker.C: if err := this.write(websocket.PingMessage, []byte{}); err != nil { log.Debug("Failed to write ping message to socket. Closing.") return } + */ } + } } @@ -402,7 +389,7 @@ func (this *SessionManager) createSession(wsConn *websocket.Conn) (*WSSession, e sessionManager: this, id: newId, wsConn: wsConn, - writeChan: make(chan []byte, writeChanBufferSize), + writeChan: make(chan []byte, maxMessageSize), writeCloseChan: make(chan struct{}), service: this.service, } diff --git a/test/server/ws_burst_test.go b/test/server/ws_burst_test.go index 75d13683a485161a10113e9759b1505922a68cac..129ddb7d1f908a44021aa8caa4a2e001b111a791 100644 --- a/test/server/ws_burst_test.go +++ b/test/server/ws_burst_test.go @@ -101,8 +101,8 @@ func wsClient(doneChan chan bool, errChan chan error) { <-readChan i++ } - client.Close() - time.Sleep(time.Millisecond * 100) + time.Sleep(100*time.Millisecond) + doneChan <- true } diff --git a/test/transacting/transacting_tes.go b/test/transacting/transacting_tes.go index a1f0da1a8625a6d016c2ba6f322fe7ca92e83d37..4d5717fc0e1f4bb6d8ed7072b2ffb8884990b5db 100644 --- a/test/transacting/transacting_tes.go +++ b/test/transacting/transacting_tes.go @@ -136,4 +136,4 @@ func (this *TxSuite) postJson(endpoint string, v interface{}) *http.Response { func TestQuerySuite(t *testing.T) { suite.Run(t, &TxSuite{}) -} +} \ No newline at end of file