From 0ec7909ec30d946190689584bc5b4a0566b97fc1 Mon Sep 17 00:00:00 2001 From: Ethan Buchman Date: Fri, 15 Dec 2017 23:08:05 -0500 Subject: [PATCH] more logging in p2p and consensus --- consensus/reactor.go | 5 ++++- p2p/connection.go | 19 +++++++++++++++++-- p2p/peer.go | 20 ++++---------------- p2p/peer_set_test.go | 1 - p2p/pex_reactor.go | 4 ++-- p2p/pex_reactor_test.go | 1 - 6 files changed, 27 insertions(+), 23 deletions(-) diff --git a/consensus/reactor.go b/consensus/reactor.go index 90dfa3b1c..053d1e7b2 100644 --- a/consensus/reactor.go +++ b/consensus/reactor.go @@ -916,7 +916,10 @@ func (ps *PeerState) SetHasProposalBlockPart(height int64, round int, index int) func (ps *PeerState) PickSendVote(votes types.VoteSetReader) bool { if vote, ok := ps.PickVoteToSend(votes); ok { msg := &VoteMessage{vote} + ps.logger.Debug("Sending vote message", "ps", ps, "vote", vote) return ps.Peer.Send(VoteChannel, struct{ ConsensusMessage }{msg}) + } else { + ps.logger.Debug("No vote message to send", "ps", ps) } return false } @@ -1344,7 +1347,7 @@ type HasVoteMessage struct { // String returns a string representation. func (m *HasVoteMessage) String() string { - return fmt.Sprintf("[HasVote VI:%v V:{%v/%02d/%v} VI:%v]", m.Index, m.Height, m.Round, m.Type, m.Index) + return fmt.Sprintf("[HasVote VI:%v V:{%v/%02d/%v}]", m.Index, m.Height, m.Round, m.Type) } //------------------------------------- diff --git a/p2p/connection.go b/p2p/connection.go index 51f6dd3bb..279de7d9f 100644 --- a/p2p/connection.go +++ b/p2p/connection.go @@ -14,6 +14,7 @@ import ( tmlegacy "github.com/tendermint/go-wire/nowriter/tmlegacy" cmn "github.com/tendermint/tmlibs/common" flow "github.com/tendermint/tmlibs/flowrate" + "github.com/tendermint/tmlibs/log" ) var legacy = tmlegacy.TMEncoderLegacy{} @@ -161,6 +162,13 @@ func NewMConnectionWithConfig(conn net.Conn, chDescs []*ChannelDescriptor, onRec return mconn } +func (c *MConnection) SetLogger(l log.Logger) { + c.BaseService.SetLogger(l) + for _, ch := range c.channels { + ch.SetLogger(l) + } +} + // OnStart implements BaseService func (c *MConnection) OnStart() error { if err := c.BaseService.OnStart(); err != nil { @@ -385,6 +393,7 @@ func (c *MConnection) sendMsgPacket() bool { // Nothing to send? if leastChannel == nil { + c.Logger.Debug("Least channel == nil") return true } else { // c.Logger.Info("Found a msgPacket to send") @@ -566,6 +575,8 @@ type Channel struct { recentlySent int64 // exponential moving average maxMsgPacketPayloadSize int + + logger log.Logger } func newChannel(conn *MConnection, desc ChannelDescriptor) *Channel { @@ -582,6 +593,10 @@ func newChannel(conn *MConnection, desc ChannelDescriptor) *Channel { } } +func (ch *Channel) SetLogger(l log.Logger) { + ch.logger = l +} + // Queues message to send to this channel. // Goroutine-safe // Times out (and returns false) after defaultSendTimeout @@ -654,7 +669,7 @@ func (ch *Channel) nextMsgPacket() msgPacket { // Not goroutine-safe func (ch *Channel) writeMsgPacketTo(w io.Writer) (n int, err error) { packet := ch.nextMsgPacket() - // log.Debug("Write Msg Packet", "conn", ch.conn, "packet", packet) + ch.logger.Debug("Write Msg Packet", "conn", ch.conn, "packet", packet) writeMsgPacketTo(packet, w, &n, &err) if err == nil { ch.recentlySent += int64(n) @@ -670,7 +685,7 @@ func writeMsgPacketTo(packet msgPacket, w io.Writer, n *int, err *error) { // Handles incoming msgPackets. Returns a msg bytes if msg is complete. // Not goroutine-safe func (ch *Channel) recvMsgPacket(packet msgPacket) ([]byte, error) { - // log.Debug("Read Msg Packet", "conn", ch.conn, "packet", packet) + ch.logger.Debug("Read Msg Packet", "conn", ch.conn, "packet", packet) if ch.desc.RecvMessageCapacity < len(ch.recving)+len(packet.Bytes) { return nil, wire.ErrBinaryReadOverflow } diff --git a/p2p/peer.go b/p2p/peer.go index cc9c14c37..cc7f4927a 100644 --- a/p2p/peer.go +++ b/p2p/peer.go @@ -2,7 +2,6 @@ package p2p import ( "fmt" - "io" "net" "time" @@ -48,7 +47,6 @@ type peer struct { config *PeerConfig nodeInfo *NodeInfo - key string Data *cmn.CMap // User data. } @@ -209,8 +207,6 @@ func (p *peer) HandshakeTimeout(ourNodeInfo *NodeInfo, timeout time.Duration) er peerNodeInfo.RemoteAddr = p.Addr().String() p.nodeInfo = peerNodeInfo - p.key = peerNodeInfo.PubKey.KeyString() - return nil } @@ -283,26 +279,18 @@ func (p *peer) CanSend(chID byte) bool { return p.mconn.CanSend(chID) } -// WriteTo writes the peer's public key to w. -func (p *peer) WriteTo(w io.Writer) (int64, error) { - var n int - var err error - wire.WriteString(p.key, w, &n, &err) - return int64(n), err -} - // String representation. func (p *peer) String() string { if p.outbound { - return fmt.Sprintf("Peer{%v %v out}", p.mconn, p.key[:12]) + return fmt.Sprintf("Peer{%v %v out}", p.mconn, p.Key()) } - return fmt.Sprintf("Peer{%v %v in}", p.mconn, p.key[:12]) + return fmt.Sprintf("Peer{%v %v in}", p.mconn, p.Key()) } // Equals reports whenever 2 peers are actually represent the same node. func (p *peer) Equals(other Peer) bool { - return p.key == other.Key() + return p.Key() == other.Key() } // Get the data for a given key. @@ -317,7 +305,7 @@ func (p *peer) Set(key string, data interface{}) { // Key returns the peer's id key. func (p *peer) Key() string { - return p.key + return p.nodeInfo.ListenAddr // XXX: should probably be PubKey.KeyString() } // NodeInfo returns a copy of the peer's NodeInfo. diff --git a/p2p/peer_set_test.go b/p2p/peer_set_test.go index 694300523..a7f29315a 100644 --- a/p2p/peer_set_test.go +++ b/p2p/peer_set_test.go @@ -13,7 +13,6 @@ import ( // Returns an empty dummy peer func randPeer() *peer { return &peer{ - key: cmn.RandStr(12), nodeInfo: &NodeInfo{ RemoteAddr: cmn.Fmt("%v.%v.%v.%v:46656", rand.Int()%256, rand.Int()%256, rand.Int()%256, rand.Int()%256), ListenAddr: cmn.Fmt("%v.%v.%v.%v:46656", rand.Int()%256, rand.Int()%256, rand.Int()%256, rand.Int()%256), diff --git a/p2p/pex_reactor.go b/p2p/pex_reactor.go index 29c35548e..2bfe7dcab 100644 --- a/p2p/pex_reactor.go +++ b/p2p/pex_reactor.go @@ -264,8 +264,8 @@ func (r *PEXReactor) ensurePeers() { if dialling := r.Switch.IsDialing(try); dialling { continue } - // XXX: does this work ?! - if connected := r.Switch.Peers().Has(try.IP.String()); connected { + // XXX: Should probably use pubkey as peer key ... + if connected := r.Switch.Peers().Has(try.String()); connected { continue } r.Logger.Info("Will dial address", "addr", try) diff --git a/p2p/pex_reactor_test.go b/p2p/pex_reactor_test.go index e80840b17..a14f0eb2a 100644 --- a/p2p/pex_reactor_test.go +++ b/p2p/pex_reactor_test.go @@ -194,7 +194,6 @@ func createRoutableAddr() (addr string, netAddr *NetAddress) { func createRandomPeer(outbound bool) *peer { addr, netAddr := createRoutableAddr() p := &peer{ - key: cmn.RandStr(12), nodeInfo: &NodeInfo{ ListenAddr: addr, RemoteAddr: netAddr.String(),