more logging in p2p and consensus

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)
 }
 
 //-------------------------------------

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
 	}

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.

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),

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)

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(),