diff --git a/discovery/bootstrapper.go b/discovery/bootstrapper.go index 6aced5987..5bcfbdb6f 100644 --- a/discovery/bootstrapper.go +++ b/discovery/bootstrapper.go @@ -158,6 +158,7 @@ func (c *ChannelGraphBootstrapper) SampleNodeAddrs(numAddrs uint32, // We'll merge the ignore map with our currently selected map in order // to ensure we don't return any duplicate nodes. for n := range ignore { + log.Tracef("Ignored node %x for bootstrapping", n) c.tried[n] = struct{}{} } diff --git a/lnwallet/channel.go b/lnwallet/channel.go index 917f06b1d..ac72852d5 100644 --- a/lnwallet/channel.go +++ b/lnwallet/channel.go @@ -1744,7 +1744,7 @@ func (lc *LightningChannel) restoreCommitState( } lc.localCommitChain.addCommitment(localCommit) - lc.log.Debugf("starting local commitment: %v", + lc.log.Tracef("starting local commitment: %v", newLogClosure(func() string { return spew.Sdump(lc.localCommitChain.tail()) }), @@ -1760,7 +1760,7 @@ func (lc *LightningChannel) restoreCommitState( } lc.remoteCommitChain.addCommitment(remoteCommit) - lc.log.Debugf("starting remote commitment: %v", + lc.log.Tracef("starting remote commitment: %v", newLogClosure(func() string { return spew.Sdump(lc.remoteCommitChain.tail()) }), diff --git a/lnwallet/wallet.go b/lnwallet/wallet.go index 412487cb9..0624c236c 100644 --- a/lnwallet/wallet.go +++ b/lnwallet/wallet.go @@ -1442,7 +1442,7 @@ func (l *LightningWallet) handleContributionMsg(req *addContributionMsg) { ) } - walletLog.Debugf("Funding tx for ChannelPoint(%v) "+ + walletLog.Tracef("Funding tx for ChannelPoint(%v) "+ "generated: %v", chanPoint, spew.Sdump(fundingTx)) } @@ -1589,9 +1589,9 @@ func (l *LightningWallet) handleChanPointReady(req *continueContributionMsg) { txsort.InPlaceSort(ourCommitTx) txsort.InPlaceSort(theirCommitTx) - walletLog.Debugf("Local commit tx for ChannelPoint(%v): %v", + walletLog.Tracef("Local commit tx for ChannelPoint(%v): %v", chanPoint, spew.Sdump(ourCommitTx)) - walletLog.Debugf("Remote commit tx for ChannelPoint(%v): %v", + walletLog.Tracef("Remote commit tx for ChannelPoint(%v): %v", chanPoint, spew.Sdump(theirCommitTx)) // Record newly available information within the open channel state. diff --git a/peer/brontide.go b/peer/brontide.go index b0450de19..257dcdac0 100644 --- a/peer/brontide.go +++ b/peer/brontide.go @@ -479,7 +479,8 @@ func (p *Brontide) Start() error { return nil } - peerLog.Tracef("Peer %v starting", p) + peerLog.Tracef("Peer %v starting with conn[%v->%v]", p, + p.cfg.Conn.LocalAddr(), p.cfg.Conn.RemoteAddr()) // Fetch and then load all the active channels we have with this remote // peer from the database. diff --git a/peer/test_utils.go b/peer/test_utils.go index a29cb7e53..0c044091c 100644 --- a/peer/test_utils.go +++ b/peer/test_utils.go @@ -521,3 +521,11 @@ func (m *mockMessageConn) ReadNextHeader() (uint32, error) { func (m *mockMessageConn) ReadNextBody(buf []byte) ([]byte, error) { return m.curReadMessage, nil } + +func (m *mockMessageConn) RemoteAddr() net.Addr { + return nil +} + +func (m *mockMessageConn) LocalAddr() net.Addr { + return nil +} diff --git a/routing/notifications.go b/routing/notifications.go index 02956c84c..a04f3be51 100644 --- a/routing/notifications.go +++ b/routing/notifications.go @@ -125,9 +125,8 @@ func (r *ChannelRouter) notifyTopologyChange(topologyDiff *TopologyChange) { return } - log.Debugf("Sending topology notification to %v clients %v", - numClients, - newLogClosure(func() string { + log.Tracef("Sending topology notification to %v clients %v", + numClients, newLogClosure(func() string { return spew.Sdump(topologyDiff) }), ) diff --git a/server.go b/server.go index 9947f34b7..7035be5e2 100644 --- a/server.go +++ b/server.go @@ -2450,7 +2450,11 @@ const bootstrapBackOffCeiling = time.Minute * 5 // until the target number of peers has been reached. This ensures that nodes // receive an up to date network view as soon as possible. func (s *server) initialPeerBootstrap(ignore map[autopilot.NodeID]struct{}, - numTargetPeers uint32, bootstrappers []discovery.NetworkPeerBootstrapper) { + numTargetPeers uint32, + bootstrappers []discovery.NetworkPeerBootstrapper) { + + srvrLog.Debugf("Init bootstrap with targetPeers=%v, bootstrappers=%v, "+ + "ignore=%v", numTargetPeers, len(bootstrappers), len(ignore)) // We'll start off by waiting 2 seconds between failed attempts, then // double each time we fail until we hit the bootstrapBackOffCeiling. @@ -2775,6 +2779,9 @@ func (s *server) establishPersistentConnections() error { return err } + srvrLog.Debugf("Establishing %v persistent connections on start", + len(nodeAddrsMap)) + // Acquire and hold server lock until all persistent connection requests // have been recorded and sent to the connection manager. s.mu.Lock() @@ -3093,10 +3100,10 @@ func (s *server) InboundPeerConnected(conn net.Conn) { // If we already have an outbound connection to this peer, then ignore // this new connection. - if _, ok := s.outboundPeers[pubStr]; ok { - srvrLog.Debugf("Already have outbound connection for %x, "+ - "ignoring inbound connection", - nodePub.SerializeCompressed()) + if p, ok := s.outboundPeers[pubStr]; ok { + srvrLog.Debugf("Already have outbound connection for %v, "+ + "ignoring inbound connection from local=%v, remote=%v", + p, conn.LocalAddr(), conn.RemoteAddr()) conn.Close() return @@ -3105,8 +3112,9 @@ func (s *server) InboundPeerConnected(conn net.Conn) { // If we already have a valid connection that is scheduled to take // precedence once the prior peer has finished disconnecting, we'll // ignore this connection. - if _, ok := s.scheduledPeerConnection[pubStr]; ok { - srvrLog.Debugf("Ignoring connection, peer already scheduled") + if p, ok := s.scheduledPeerConnection[pubStr]; ok { + srvrLog.Debugf("Ignoring connection from %v, peer %v already "+ + "scheduled", conn.RemoteAddr(), p) conn.Close() return } @@ -3179,10 +3187,10 @@ func (s *server) OutboundPeerConnected(connReq *connmgr.ConnReq, conn net.Conn) // If we already have an inbound connection to this peer, then ignore // this new connection. - if _, ok := s.inboundPeers[pubStr]; ok { - srvrLog.Debugf("Already have inbound connection for %x, "+ - "ignoring outbound connection", - nodePub.SerializeCompressed()) + if p, ok := s.inboundPeers[pubStr]; ok { + srvrLog.Debugf("Already have inbound connection for %v, "+ + "ignoring outbound connection from local=%v, remote=%v", + p, conn.LocalAddr(), conn.RemoteAddr()) if connReq != nil { s.connMgr.Remove(connReq.ID()) @@ -3303,6 +3311,8 @@ func (s *server) cancelConnReqs(pubStr string, skip *uint64) { } for _, connReq := range connReqs { + srvrLog.Tracef("Canceling %s:", connReqs) + // Atomically capture the current request identifier. connID := connReq.ID() @@ -3998,6 +4008,9 @@ func (s *server) connectToPeer(addr *lnwire.NetAddress, close(errChan) + srvrLog.Tracef("Brontide dialer made local=%v, remote=%v", + conn.LocalAddr(), conn.RemoteAddr()) + s.OutboundPeerConnected(nil, conn) }