peer check messages

eth/handler.go

@@ -346,6 +346,7 @@ func (pm *ProtocolManager) Stop() {
 }
 
 func (pm *ProtocolManager) newPeer(pv int, p *p2p.Peer, rw p2p.MsgReadWriter) *peer {
+	log.Info("PEERCHECK [newPeer]", "peer", p)
 	return newPeer(pv, p, newMeteredMsgWriter(rw))
 }
 

p2p/dial.go

@@ -160,13 +160,16 @@ func (s *dialstate) removeStatic(n *discover.Node) {
 }
 
 func (s *dialstate) newTasks(nRunning int, peers map[discover.NodeID]*Peer, now time.Time) []task {
+	log.Info("PEERCHECK [newTasks]", "peers", peers)
 	if s.start.IsZero() {
 		s.start = now
 	}
 
 	var newtasks []task
 	addDial := func(flag connFlag, n *discover.Node) bool {
+		log.Info("PEERCHECK [newTasks] addDial", "id", n.ID, "addr", &net.TCPAddr{IP: n.IP, Port: int(n.TCP)})
 		if err := s.checkDial(n, peers); err != nil {
+			log.Info("PEERCHECK [newTasks] checkdial", "err", err, "id", n.ID, "addr", &net.TCPAddr{IP: n.IP, Port: int(n.TCP)})
 			log.Trace("Skipping dial candidate", "id", n.ID, "addr", &net.TCPAddr{IP: n.IP, Port: int(n.TCP)}, "err", err)
 			return false
 		}
@@ -292,6 +295,7 @@ func (s *dialstate) taskDone(t task, now time.Time) {
 }
 
 func (t *dialTask) Do(srv *Server) {
+	log.Info("PEERCHECK [Do]", "t.dest", t.dest, "t", t)
 	if t.dest.Incomplete() {
 		if !t.resolve(srv) {
 			return
@@ -365,8 +369,10 @@ type dialError struct {
 
 // dial performs the actual connection attempt.
 func (t *dialTask) dial(srv *Server, dest *discover.Node) error {
+	log.Info("PEERCHECK dial", "dest", dest)
 	fd, err := srv.Dialer.Dial(dest)
 	if err != nil {
+		log.Info("PEERCHECK dial error", "err", err)
 		return &dialError{err}
 	}
 	mfd := newMeteredConn(fd, false)

p2p/discover/table.go

@@ -556,10 +556,13 @@ func (tab *Table) len() (n int) {
 // bondall bonds with all given nodes concurrently and returns
 // those nodes for which bonding has probably succeeded.
 func (tab *Table) bondall(nodes []*Node) (result []*Node) {
+	log.Info("PEERCHECK [bondall]", "nodes", nodes)
 	rc := make(chan *Node, len(nodes))
 	for i := range nodes {
 		go func(n *Node) {
-			nn, _ := tab.bond(false, n.ID, n.addr(), n.TCP)
+			nn, err := tab.bond(false, n.ID, n.addr(), n.TCP)
+			log.Info("PEERCHECK [bondall]", "nn", nn, "err", err)
+
 			rc <- nn
 		}(nodes[i])
 	}
@@ -568,6 +571,8 @@ func (tab *Table) bondall(nodes []*Node) (result []*Node) {
 			result = append(result, n)
 		}
 	}
+	log.Info("PEERCHECK [bondall]", "result", result)
+
 	return result
 }
 
@@ -588,6 +593,7 @@ func (tab *Table) bondall(nodes []*Node) (result []*Node) {
 // If pinged is true, the remote node has just pinged us and one half
 // of the process can be skipped.
 func (tab *Table) bond(pinged bool, id NodeID, addr *net.UDPAddr, tcpPort uint16) (*Node, error) {
+	log.Info("PEERCHECK [bond]", "pinged", pinged, "id", id, "addr", addr, "tcpPort", tcpPort)
 	if id == tab.self.ID {
 		return nil, errors.New("is self")
 	}
@@ -600,6 +606,7 @@ func (tab *Table) bond(pinged bool, id NodeID, addr *net.UDPAddr, tcpPort uint16
 	var result error
 	if fails > 0 || age > nodeDBNodeExpiration {
 		log.Trace("Starting bonding ping/pong", "id", id, "known", node != nil, "failcount", fails, "age", age)
+		log.Info("PEERCHECK [bond] Starting bonding ping/pong", "id", id, "known", node != nil, "failcount", fails, "age", age)
 
 		tab.bondmu.Lock()
 		w := tab.bonding[id]

p2p/discover/udp.go

@@ -274,6 +274,7 @@ func (t *udp) close() {
 
 // ping sends a ping message to the given node and waits for a reply.
 func (t *udp) ping(toid NodeID, toaddr *net.UDPAddr) error {
+	log.Info("PEERCHECK [ping]", "toid", toid, "toaddr", toaddr)
 	req := &ping{
 		Version:    Version,
 		From:       t.ourEndpoint,
@@ -306,7 +307,7 @@ func (t *udp) findnode(toid NodeID, toaddr *net.UDPAddr, target NodeID) ([]*Node
 			nreceived++
 			n, err := t.nodeFromRPC(toaddr, rn)
 			if err != nil {
-				log.Trace("Invalid neighbor node received", "ip", rn.IP, "addr", toaddr, "err", err)
+				log.Debug("PEERCHECK [findnode] Invalid neighbor node received", "ip", rn.IP, "addr", toaddr, "err", err)
 				continue
 			}
 			nodes = append(nodes, n)
@@ -318,6 +319,7 @@ func (t *udp) findnode(toid NodeID, toaddr *net.UDPAddr, target NodeID) ([]*Node
 		Expiration: uint64(time.Now().Add(expiration).Unix()),
 	})
 	err := <-errc
+	log.Info("PEERCHECK [findnode]", "nodes", nodes)
 	return nodes, err
 }
 
@@ -481,6 +483,8 @@ func (t *udp) send(toaddr *net.UDPAddr, ptype byte, req packet) ([]byte, error)
 
 func (t *udp) write(toaddr *net.UDPAddr, what string, packet []byte) error {
 	_, err := t.conn.WriteToUDP(packet, toaddr)
+
+	log.Info("PEERCHECK >> "+what, "addr", toaddr, "err", err)
 	log.Trace(">> "+what, "addr", toaddr, "err", err)
 	return err
 }
@@ -546,6 +550,7 @@ func (t *udp) handlePacket(from *net.UDPAddr, buf []byte) error {
 	}
 	err = packet.handle(t, from, fromID, hash)
 	log.Trace("<< "+packet.name(), "addr", from, "err", err)
+	log.Info("PEERCHECK << "+packet.name(), "addr", from, "err", err, "t.ourendpoint.IP",t.ourEndpoint.IP, "t.ourendpoint.TCP", t.ourEndpoint.TCP, "t.ourendpoint.UDP", t.ourEndpoint.UDP, "t.nat", t.nat)
 	return err
 }
 
@@ -563,6 +568,7 @@ func decodePacket(buf []byte) (packet, NodeID, []byte, error) {
 		return nil, NodeID{}, hash, err
 	}
 	var req packet
+	isNeighbor := false
 	switch ptype := sigdata[0]; ptype {
 	case pingXDC:
 		req = new(ping)
@@ -572,11 +578,15 @@ func decodePacket(buf []byte) (packet, NodeID, []byte, error) {
 		req = new(findnode)
 	case neighborsPacket:
 		req = new(neighbors)
+		isNeighbor = true
 	default:
 		return nil, fromID, hash, fmt.Errorf("unknown type: %d", ptype)
 	}
 	s := rlp.NewStream(bytes.NewReader(sigdata[1:]), 0)
 	err = s.Decode(req)
+	if isNeighbor {
+		log.Info("PEERCHECK neiborsPacket recv", "req", req, "fromID", fromID, "err", err)
+	}
 	return req, fromID, hash, err
 }
 

p2p/discover/udp_test.go

@@ -482,6 +482,8 @@ func TestForwardCompatibility(t *testing.T) {
 			t.Fatalf("invalid hex: %s", test.input)
 		}
 		packet, nodeid, _, err := decodePacket(input)
+		fmt.Println(packet)
+		fmt.Println(nodeid)
 		if err != nil {
 			t.Errorf("did not accept packet %s\n%v", test.input, err)
 			continue

p2p/nat/nat.go

@@ -65,6 +65,9 @@ func Parse(spec string) (Interface, error) {
 		mech  = strings.ToLower(parts[0])
 		ip    net.IP
 	)
+
+	log.Error("PEERCHECK [Parse]", "spec", spec)
+
 	if len(parts) > 1 {
 		ip = net.ParseIP(parts[1])
 		if ip == nil {
@@ -80,6 +83,7 @@ func Parse(spec string) (Interface, error) {
 		if ip == nil {
 			return nil, errors.New("missing IP address")
 		}
+		log.Error("[Parse]", "returning extip", ExtIP(ip) )
 		return ExtIP(ip), nil
 	case "upnp":
 		return UPnP(), nil

p2p/server.go

@@ -585,6 +585,7 @@ func (srv *Server) run(dialstate dialer) {
 
 running:
 	for {
+		log.Info("PEERCHECK server loop")
 		scheduleTasks()
 
 		select {
@@ -809,8 +810,10 @@ func (srv *Server) SetupConn(fd net.Conn, flags connFlag, dialDest *discover.Nod
 		return errors.New("shutdown")
 	}
 	c := &conn{fd: fd, transport: srv.newTransport(fd), flags: flags, cont: make(chan error)}
+	log.Info("PEERCHECK [SetupConn]", "dialDest", dialDest, "flags", flags, "c",c)
 	err := srv.setupConn(c, flags, dialDest)
 	if err != nil {
+		log.Info("PEERCHECK [SetupConn] error", "dialDest", dialDest, "err", err, "c",c)
 		c.close(err)
 		srv.log.Trace("Setting up connection failed", "id", c.id, "err", err)
 	}