p2p/discover, p2p/enode: rework endpoint proof handling, packet logging (#18963)

This change resolves multiple issues around handling of endpoint proofs.
The proof is now done separately for each IP and completing the proof
requires a matching ping hash.

Also remove waitping because it's equivalent to sleep. waitping was
slightly more efficient, but that may cause issues with findnode if
packets are reordered and the remote end sees findnode before pong.

Logging of received packets was hitherto done after handling the packet,
which meant that sent replies were logged before the packet that
generated them. This change splits up packet handling into 'preverify'
and 'handle'. The error from 'preverify' is logged, but 'handle' happens
after the message is logged. This fixes the order. Packet logs now
contain the node ID.

2 files changed, 285 insertions, 141 deletions

diff --git a/p2p/enode/nodedb.go b/p2p/enode/nodedb.go
index 7ee0c09a9..9353b155c 100644
--- a/p2p/enode/nodedb.go
+++ b/p2p/enode/nodedb.go
@@ -21,11 +21,11 @@ import (
 	"crypto/rand"
 	"encoding/binary"
 	"fmt"
+	"net"
 	"os"
 	"sync"
 	"time"
 
-	"github.com/ethereum/go-ethereum/log"
 	"github.com/ethereum/go-ethereum/rlp"
 	"github.com/syndtr/goleveldb/leveldb"
 	"github.com/syndtr/goleveldb/leveldb/errors"
@@ -37,24 +37,31 @@ import (
 
 // Keys in the node database.
 const (
-	dbVersionKey = "version" // Version of the database to flush if changes
-	dbItemPrefix = "n:"      // Identifier to prefix node entries with
-
-	dbDiscoverRoot      = ":discover"
-	dbDiscoverSeq       = dbDiscoverRoot + ":seq"
-	dbDiscoverPing      = dbDiscoverRoot + ":lastping"
-	dbDiscoverPong      = dbDiscoverRoot + ":lastpong"
-	dbDiscoverFindFails = dbDiscoverRoot + ":findfail"
-	dbLocalRoot         = ":local"
-	dbLocalSeq          = dbLocalRoot + ":seq"
+	dbVersionKey   = "version" // Version of the database to flush if changes
+	dbNodePrefix   = "n:"      // Identifier to prefix node entries with
+	dbLocalPrefix  = "local:"
+	dbDiscoverRoot = "v4"
+
+	// These fields are stored per ID and IP, the full key is "n:<ID>:v4:<IP>:findfail".
+	// Use nodeItemKey to create those keys.
+	dbNodeFindFails = "findfail"
+	dbNodePing      = "lastping"
+	dbNodePong      = "lastpong"
+	dbNodeSeq       = "seq"
+
+	// Local information is keyed by ID only, the full key is "local:<ID>:seq".
+	// Use localItemKey to create those keys.
+	dbLocalSeq = "seq"
 )
 
-var (
+const (
 	dbNodeExpiration = 24 * time.Hour // Time after which an unseen node should be dropped.
 	dbCleanupCycle   = time.Hour      // Time period for running the expiration task.
-	dbVersion        = 7
+	dbVersion        = 8
 )
 
+var zeroIP = make(net.IP, 16)
+
 // DB is the node database, storing previously seen nodes and any collected metadata about
 // them for QoS purposes.
 type DB struct {
@@ -119,27 +126,58 @@ func newPersistentDB(path string) (*DB, error) {
 	return &DB{lvl: db, quit: make(chan struct{})}, nil
 }
 
-// makeKey generates the leveldb key-blob from a node id and its particular
-// field of interest.
-func makeKey(id ID, field string) []byte {
-	if (id == ID{}) {
-		return []byte(field)
-	}
-	return append([]byte(dbItemPrefix), append(id[:], field...)...)
+// nodeKey returns the database key for a node record.
+func nodeKey(id ID) []byte {
+	key := append([]byte(dbNodePrefix), id[:]...)
+	key = append(key, ':')
+	key = append(key, dbDiscoverRoot...)
+	return key
 }
 
-// splitKey tries to split a database key into a node id and a field part.
-func splitKey(key []byte) (id ID, field string) {
-	// If the key is not of a node, return it plainly
-	if !bytes.HasPrefix(key, []byte(dbItemPrefix)) {
-		return ID{}, string(key)
+// splitNodeKey returns the node ID of a key created by nodeKey.
+func splitNodeKey(key []byte) (id ID, rest []byte) {
+	if !bytes.HasPrefix(key, []byte(dbNodePrefix)) {
+		return ID{}, nil
 	}
-	// Otherwise split the id and field
-	item := key[len(dbItemPrefix):]
+	item := key[len(dbNodePrefix):]
 	copy(id[:], item[:len(id)])
-	field = string(item[len(id):])
+	return id, item[len(id)+1:]
+}
 
-	return id, field
+// nodeItemKey returns the database key for a node metadata field.
+func nodeItemKey(id ID, ip net.IP, field string) []byte {
+	ip16 := ip.To16()
+	if ip16 == nil {
+		panic(fmt.Errorf("invalid IP (length %d)", len(ip)))
+	}
+	return bytes.Join([][]byte{nodeKey(id), ip16, []byte(field)}, []byte{':'})
+}
+
+// splitNodeItemKey returns the components of a key created by nodeItemKey.
+func splitNodeItemKey(key []byte) (id ID, ip net.IP, field string) {
+	id, key = splitNodeKey(key)
+	// Skip discover root.
+	if string(key) == dbDiscoverRoot {
+		return id, nil, ""
+	}
+	key = key[len(dbDiscoverRoot)+1:]
+	// Split out the IP.
+	ip = net.IP(key[:16])
+	if ip4 := ip.To4(); ip4 != nil {
+		ip = ip4
+	}
+	key = key[16+1:]
+	// Field is the remainder of key.
+	field = string(key)
+	return id, ip, field
+}
+
+// localItemKey returns the key of a local node item.
+func localItemKey(id ID, field string) []byte {
+	key := append([]byte(dbLocalPrefix), id[:]...)
+	key = append(key, ':')
+	key = append(key, field...)
+	return key
 }
 
 // fetchInt64 retrieves an integer associated with a particular key.
@@ -181,7 +219,7 @@ func (db *DB) storeUint64(key []byte, n uint64) error {
 
 // Node retrieves a node with a given id from the database.
 func (db *DB) Node(id ID) *Node {
-	blob, err := db.lvl.Get(makeKey(id, dbDiscoverRoot), nil)
+	blob, err := db.lvl.Get(nodeKey(id), nil)
 	if err != nil {
 		return nil
 	}
@@ -207,15 +245,15 @@ func (db *DB) UpdateNode(node *Node) error {
 	if err != nil {
 		return err
 	}
-	if err := db.lvl.Put(makeKey(node.ID(), dbDiscoverRoot), blob, nil); err != nil {
+	if err := db.lvl.Put(nodeKey(node.ID()), blob, nil); err != nil {
 		return err
 	}
-	return db.storeUint64(makeKey(node.ID(), dbDiscoverSeq), node.Seq())
+	return db.storeUint64(nodeItemKey(node.ID(), zeroIP, dbNodeSeq), node.Seq())
 }
 
 // NodeSeq returns the stored record sequence number of the given node.
 func (db *DB) NodeSeq(id ID) uint64 {
-	return db.fetchUint64(makeKey(id, dbDiscoverSeq))
+	return db.fetchUint64(nodeItemKey(id, zeroIP, dbNodeSeq))
 }
 
 // Resolve returns the stored record of the node if it has a larger sequence
@@ -227,15 +265,17 @@ func (db *DB) Resolve(n *Node) *Node {
 	return db.Node(n.ID())
 }
 
-// DeleteNode deletes all information/keys associated with a node.
-func (db *DB) DeleteNode(id ID) error {
-	deleter := db.lvl.NewIterator(util.BytesPrefix(makeKey(id, "")), nil)
-	for deleter.Next() {
-		if err := db.lvl.Delete(deleter.Key(), nil); err != nil {
-			return err
-		}
+// DeleteNode deletes all information associated with a node.
+func (db *DB) DeleteNode(id ID) {
+	deleteRange(db.lvl, nodeKey(id))
+}
+
+func deleteRange(db *leveldb.DB, prefix []byte) {
+	it := db.NewIterator(util.BytesPrefix(prefix), nil)
+	defer it.Release()
+	for it.Next() {
+		db.Delete(it.Key(), nil)
 	}
-	return nil
 }
 
 // ensureExpirer is a small helper method ensuring that the data expiration
@@ -259,9 +299,7 @@ func (db *DB) expirer() {
 	for {
 		select {
 		case <-tick.C:
-			if err := db.expireNodes(); err != nil {
-				log.Error("Failed to expire nodedb items", "err", err)
-			}
+			db.expireNodes()
 		case <-db.quit:
 			return
 		}
@@ -269,71 +307,85 @@ func (db *DB) expirer() {
 }
 
 // expireNodes iterates over the database and deletes all nodes that have not
-// been seen (i.e. received a pong from) for some allotted time.
-func (db *DB) expireNodes() error {
-	threshold := time.Now().Add(-dbNodeExpiration)
-
-	// Find discovered nodes that are older than the allowance
-	it := db.lvl.NewIterator(nil, nil)
+// been seen (i.e. received a pong from) for some time.
+func (db *DB) expireNodes() {
+	it := db.lvl.NewIterator(util.BytesPrefix([]byte(dbNodePrefix)), nil)
 	defer it.Release()
+	if !it.Next() {
+		return
+	}
 
-	for it.Next() {
-		// Skip the item if not a discovery node
-		id, field := splitKey(it.Key())
-		if field != dbDiscoverRoot {
-			continue
+	var (
+		threshold    = time.Now().Add(-dbNodeExpiration).Unix()
+		youngestPong int64
+		atEnd        = false
+	)
+	for !atEnd {
+		id, ip, field := splitNodeItemKey(it.Key())
+		if field == dbNodePong {
+			time, _ := binary.Varint(it.Value())
+			if time > youngestPong {
+				youngestPong = time
+			}
+			if time < threshold {
+				// Last pong from this IP older than threshold, remove fields belonging to it.
+				deleteRange(db.lvl, nodeItemKey(id, ip, ""))
+			}
 		}
-		// Skip the node if not expired yet (and not self)
-		if seen := db.LastPongReceived(id); seen.After(threshold) {
-			continue
+		atEnd = !it.Next()
+		nextID, _ := splitNodeKey(it.Key())
+		if atEnd || nextID != id {
+			// We've moved beyond the last entry of the current ID.
+			// Remove everything if there was no recent enough pong.
+			if youngestPong > 0 && youngestPong < threshold {
+				deleteRange(db.lvl, nodeKey(id))
+			}
+			youngestPong = 0
 		}
-		// Otherwise delete all associated information
-		db.DeleteNode(id)
 	}
-	return nil
 }
 
 // LastPingReceived retrieves the time of the last ping packet received from
 // a remote node.
-func (db *DB) LastPingReceived(id ID) time.Time {
-	return time.Unix(db.fetchInt64(makeKey(id, dbDiscoverPing)), 0)
+func (db *DB) LastPingReceived(id ID, ip net.IP) time.Time {
+	return time.Unix(db.fetchInt64(nodeItemKey(id, ip, dbNodePing)), 0)
 }
 
 // UpdateLastPingReceived updates the last time we tried contacting a remote node.
-func (db *DB) UpdateLastPingReceived(id ID, instance time.Time) error {
-	return db.storeInt64(makeKey(id, dbDiscoverPing), instance.Unix())
+func (db *DB) UpdateLastPingReceived(id ID, ip net.IP, instance time.Time) error {
+	return db.storeInt64(nodeItemKey(id, ip, dbNodePing), instance.Unix())
 }
 
 // LastPongReceived retrieves the time of the last successful pong from remote node.
-func (db *DB) LastPongReceived(id ID) time.Time {
+func (db *DB) LastPongReceived(id ID, ip net.IP) time.Time {
 	// Launch expirer
 	db.ensureExpirer()
-	return time.Unix(db.fetchInt64(makeKey(id, dbDiscoverPong)), 0)
+	return time.Unix(db.fetchInt64(nodeItemKey(id, ip, dbNodePong)), 0)
 }
 
 // UpdateLastPongReceived updates the last pong time of a node.
-func (db *DB) UpdateLastPongReceived(id ID, instance time.Time) error {
-	return db.storeInt64(makeKey(id, dbDiscoverPong), instance.Unix())
+func (db *DB) UpdateLastPongReceived(id ID, ip net.IP, instance time.Time) error {
+	return db.storeInt64(nodeItemKey(id, ip, dbNodePong), instance.Unix())
 }
 
 // FindFails retrieves the number of findnode failures since bonding.
-func (db *DB) FindFails(id ID) int {
-	return int(db.fetchInt64(makeKey(id, dbDiscoverFindFails)))
+func (db *DB) FindFails(id ID, ip net.IP) int {
+	return int(db.fetchInt64(nodeItemKey(id, ip, dbNodeFindFails)))
 }
 
 // UpdateFindFails updates the number of findnode failures since bonding.
-func (db *DB) UpdateFindFails(id ID, fails int) error {
-	return db.storeInt64(makeKey(id, dbDiscoverFindFails), int64(fails))
+func (db *DB) UpdateFindFails(id ID, ip net.IP, fails int) error {
+	return db.storeInt64(nodeItemKey(id, ip, dbNodeFindFails), int64(fails))
 }
 
 // LocalSeq retrieves the local record sequence counter.
 func (db *DB) localSeq(id ID) uint64 {
-	return db.fetchUint64(makeKey(id, dbLocalSeq))
+	return db.fetchUint64(nodeItemKey(id, zeroIP, dbLocalSeq))
 }
 
 // storeLocalSeq stores the local record sequence counter.
 func (db *DB) storeLocalSeq(id ID, n uint64) {
-	db.storeUint64(makeKey(id, dbLocalSeq), n)
+	db.storeUint64(nodeItemKey(id, zeroIP, dbLocalSeq), n)
 }
 
 // QuerySeeds retrieves random nodes to be used as potential seed nodes
@@ -355,14 +407,14 @@ seek:
 		ctr := id[0]
 		rand.Read(id[:])
 		id[0] = ctr + id[0]%16
-		it.Seek(makeKey(id, dbDiscoverRoot))
+		it.Seek(nodeKey(id))
 
 		n := nextNode(it)
 		if n == nil {
 			id[0] = 0
 			continue seek // iterator exhausted
 		}
-		if now.Sub(db.LastPongReceived(n.ID())) > maxAge {
+		if now.Sub(db.LastPongReceived(n.ID(), n.IP())) > maxAge {
 			continue seek
 		}
 		for i := range nodes {
@@ -379,8 +431,8 @@ seek:
 // database entries.
 func nextNode(it iterator.Iterator) *Node {
 	for end := false; !end; end = !it.Next() {
-		id, field := splitKey(it.Key())
-		if field != dbDiscoverRoot {
+		id, rest := splitNodeKey(it.Key())
+		if string(rest) != dbDiscoverRoot {
 			continue
 		}
 		return mustDecodeNode(id[:], it.Value())
diff --git a/p2p/enode/nodedb_test.go b/p2p/enode/nodedb_test.go
index 96794827c..341b61a28 100644
--- a/p2p/enode/nodedb_test.go
+++ b/p2p/enode/nodedb_test.go
@@ -28,42 +28,54 @@ import (
 	"time"
 )
 
-var nodeDBKeyTests = []struct {
-	id    ID
-	field string
-	key   []byte
-}{
-	{
-		id:    ID{},
-		field: "version",
-		key:   []byte{0x76, 0x65, 0x72, 0x73, 0x69, 0x6f, 0x6e}, // field
-	},
-	{
-		id:    HexID("51232b8d7821617d2b29b54b81cdefb9b3e9c37d7fd5f63270bcc9e1a6f6a439"),
-		field: ":discover",
-		key: []byte{
-			0x6e, 0x3a, // prefix
-			0x51, 0x23, 0x2b, 0x8d, 0x78, 0x21, 0x61, 0x7d, // node id
-			0x2b, 0x29, 0xb5, 0x4b, 0x81, 0xcd, 0xef, 0xb9, //
-			0xb3, 0xe9, 0xc3, 0x7d, 0x7f, 0xd5, 0xf6, 0x32, //
-			0x70, 0xbc, 0xc9, 0xe1, 0xa6, 0xf6, 0xa4, 0x39, //
-			0x3a, 0x64, 0x69, 0x73, 0x63, 0x6f, 0x76, 0x65, 0x72, // field
-		},
-	},
+var keytestID = HexID("51232b8d7821617d2b29b54b81cdefb9b3e9c37d7fd5f63270bcc9e1a6f6a439")
+
+func TestDBNodeKey(t *testing.T) {
+	enc := nodeKey(keytestID)
+	want := []byte{
+		'n', ':',
+		0x51, 0x23, 0x2b, 0x8d, 0x78, 0x21, 0x61, 0x7d, // node id
+		0x2b, 0x29, 0xb5, 0x4b, 0x81, 0xcd, 0xef, 0xb9, //
+		0xb3, 0xe9, 0xc3, 0x7d, 0x7f, 0xd5, 0xf6, 0x32, //
+		0x70, 0xbc, 0xc9, 0xe1, 0xa6, 0xf6, 0xa4, 0x39, //
+		':', 'v', '4',
+	}
+	if !bytes.Equal(enc, want) {
+		t.Errorf("wrong encoded key:\ngot  %q\nwant %q", enc, want)
+	}
+	id, _ := splitNodeKey(enc)
+	if id != keytestID {
+		t.Errorf("wrong ID from splitNodeKey")
+	}
 }
 
-func TestDBKeys(t *testing.T) {
-	for i, tt := range nodeDBKeyTests {
-		if key := makeKey(tt.id, tt.field); !bytes.Equal(key, tt.key) {
-			t.Errorf("make test %d: key mismatch: have 0x%x, want 0x%x", i, key, tt.key)
-		}
-		id, field := splitKey(tt.key)
-		if !bytes.Equal(id[:], tt.id[:]) {
-			t.Errorf("split test %d: id mismatch: have 0x%x, want 0x%x", i, id, tt.id)
-		}
-		if field != tt.field {
-			t.Errorf("split test %d: field mismatch: have 0x%x, want 0x%x", i, field, tt.field)
-		}
+func TestDBNodeItemKey(t *testing.T) {
+	wantIP := net.IP{127, 0, 0, 3}
+	wantField := "foobar"
+	enc := nodeItemKey(keytestID, wantIP, wantField)
+	want := []byte{
+		'n', ':',
+		0x51, 0x23, 0x2b, 0x8d, 0x78, 0x21, 0x61, 0x7d, // node id
+		0x2b, 0x29, 0xb5, 0x4b, 0x81, 0xcd, 0xef, 0xb9, //
+		0xb3, 0xe9, 0xc3, 0x7d, 0x7f, 0xd5, 0xf6, 0x32, //
+		0x70, 0xbc, 0xc9, 0xe1, 0xa6, 0xf6, 0xa4, 0x39, //
+		':', 'v', '4', ':',
+		0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, // IP
+		0x00, 0x00, 0xff, 0xff, 0x7f, 0x00, 0x00, 0x03, //
+		':', 'f', 'o', 'o', 'b', 'a', 'r',
+	}
+	if !bytes.Equal(enc, want) {
+		t.Errorf("wrong encoded key:\ngot  %q\nwant %q", enc, want)
+	}
+	id, ip, field := splitNodeItemKey(enc)
+	if id != keytestID {
+		t.Errorf("splitNodeItemKey returned wrong ID: %v", id)
+	}
+	if !bytes.Equal(ip, wantIP) {
+		t.Errorf("splitNodeItemKey returned wrong IP: %v", ip)
+	}
+	if field != wantField {
+		t.Errorf("splitNodeItemKey returned wrong field: %q", field)
 	}
 }
 
@@ -113,33 +125,33 @@ func TestDBFetchStore(t *testing.T) {
 	defer db.Close()
 
 	// Check fetch/store operations on a node ping object
-	if stored := db.LastPingReceived(node.ID()); stored.Unix() != 0 {
+	if stored := db.LastPingReceived(node.ID(), node.IP()); stored.Unix() != 0 {
 		t.Errorf("ping: non-existing object: %v", stored)
 	}
-	if err := db.UpdateLastPingReceived(node.ID(), inst); err != nil {
+	if err := db.UpdateLastPingReceived(node.ID(), node.IP(), inst); err != nil {
 		t.Errorf("ping: failed to update: %v", err)
 	}
-	if stored := db.LastPingReceived(node.ID()); stored.Unix() != inst.Unix() {
+	if stored := db.LastPingReceived(node.ID(), node.IP()); stored.Unix() != inst.Unix() {
 		t.Errorf("ping: value mismatch: have %v, want %v", stored, inst)
 	}
 	// Check fetch/store operations on a node pong object
-	if stored := db.LastPongReceived(node.ID()); stored.Unix() != 0 {
+	if stored := db.LastPongReceived(node.ID(), node.IP()); stored.Unix() != 0 {
 		t.Errorf("pong: non-existing object: %v", stored)
 	}
-	if err := db.UpdateLastPongReceived(node.ID(), inst); err != nil {
+	if err := db.UpdateLastPongReceived(node.ID(), node.IP(), inst); err != nil {
 		t.Errorf("pong: failed to update: %v", err)
 	}
-	if stored := db.LastPongReceived(node.ID()); stored.Unix() != inst.Unix() {
+	if stored := db.LastPongReceived(node.ID(), node.IP()); stored.Unix() != inst.Unix() {
 		t.Errorf("pong: value mismatch: have %v, want %v", stored, inst)
 	}
 	// Check fetch/store operations on a node findnode-failure object
-	if stored := db.FindFails(node.ID()); stored != 0 {
+	if stored := db.FindFails(node.ID(), node.IP()); stored != 0 {
 		t.Errorf("find-node fails: non-existing object: %v", stored)
 	}
-	if err := db.UpdateFindFails(node.ID(), num); err != nil {
+	if err := db.UpdateFindFails(node.ID(), node.IP(), num); err != nil {
 		t.Errorf("find-node fails: failed to update: %v", err)
 	}
-	if stored := db.FindFails(node.ID()); stored != num {
+	if stored := db.FindFails(node.ID(), node.IP()); stored != num {
 		t.Errorf("find-node fails: value mismatch: have %v, want %v", stored, num)
 	}
 	// Check fetch/store operations on an actual node object
@@ -256,7 +268,7 @@ func testSeedQuery() error {
 		if err := db.UpdateNode(seed.node); err != nil {
 			return fmt.Errorf("node %d: failed to insert: %v", i, err)
 		}
-		if err := db.UpdateLastPongReceived(seed.node.ID(), seed.pong); err != nil {
+		if err := db.UpdateLastPongReceived(seed.node.ID(), seed.node.IP(), seed.pong); err != nil {
 			return fmt.Errorf("node %d: failed to insert bondTime: %v", i, err)
 		}
 	}
@@ -321,10 +333,12 @@ func TestDBPersistency(t *testing.T) {
 }
 
 var nodeDBExpirationNodes = []struct {
-	node *Node
-	pong time.Time
-	exp  bool
+	node      *Node
+	pong      time.Time
+	storeNode bool
+	exp       bool
 }{
+	// Node has new enough pong time and isn't expired:
 	{
 		node: NewV4(
 			hexPubkey("8d110e2ed4b446d9b5fb50f117e5f37fb7597af455e1dab0e6f045a6eeaa786a6781141659020d38bdc5e698ed3d4d2bafa8b5061810dfa63e8ac038db2e9b67"),
@@ -332,17 +346,79 @@ var nodeDBExpirationNodes = []struct {
 			30303,
 			30303,
 		),
-		pong: time.Now().Add(-dbNodeExpiration + time.Minute),
-		exp:  false,
-	}, {
+		storeNode: true,
+		pong:      time.Now().Add(-dbNodeExpiration + time.Minute),
+		exp:       false,
+	},
+	// Node with pong time before expiration is removed:
+	{
 		node: NewV4(
 			hexPubkey("913a205579c32425b220dfba999d215066e5bdbf900226b11da1907eae5e93eb40616d47412cf819664e9eacbdfcca6b0c6e07e09847a38472d4be46ab0c3672"),
 			net.IP{127, 0, 0, 2},
 			30303,
 			30303,
 		),
-		pong: time.Now().Add(-dbNodeExpiration - time.Minute),
-		exp:  true,
+		storeNode: true,
+		pong:      time.Now().Add(-dbNodeExpiration - time.Minute),
+		exp:       true,
+	},
+	// Just pong time, no node stored:
+	{
+		node: NewV4(
+			hexPubkey("b56670e0b6bad2c5dab9f9fe6f061a16cf78d68b6ae2cfda3144262d08d97ce5f46fd8799b6d1f709b1abe718f2863e224488bd7518e5e3b43809ac9bd1138ca"),
+			net.IP{127, 0, 0, 3},
+			30303,
+			30303,
+		),
+		storeNode: false,
+		pong:      time.Now().Add(-dbNodeExpiration - time.Minute),
+		exp:       true,
+	},
+	// Node with multiple pong times, all older than expiration.
+	{
+		node: NewV4(
+			hexPubkey("29f619cebfd32c9eab34aec797ed5e3fe15b9b45be95b4df3f5fe6a9ae892f433eb08d7698b2ef3621568b0fb70d57b515ab30d4e72583b798298e0f0a66b9d1"),
+			net.IP{127, 0, 0, 4},
+			30303,
+			30303,
+		),
+		storeNode: true,
+		pong:      time.Now().Add(-dbNodeExpiration - time.Minute),
+		exp:       true,
+	},
+	{
+		node: NewV4(
+			hexPubkey("29f619cebfd32c9eab34aec797ed5e3fe15b9b45be95b4df3f5fe6a9ae892f433eb08d7698b2ef3621568b0fb70d57b515ab30d4e72583b798298e0f0a66b9d1"),
+			net.IP{127, 0, 0, 5},
+			30303,
+			30303,
+		),
+		storeNode: false,
+		pong:      time.Now().Add(-dbNodeExpiration - 2*time.Minute),
+		exp:       true,
+	},
+	// Node with multiple pong times, one newer, one older than expiration.
+	{
+		node: NewV4(
+			hexPubkey("3b73a9e5f4af6c4701c57c73cc8cfa0f4802840b24c11eba92aac3aef65644a3728b4b2aec8199f6d72bd66be2c65861c773129039bd47daa091ca90a6d4c857"),
+			net.IP{127, 0, 0, 6},
+			30303,
+			30303,
+		),
+		storeNode: true,
+		pong:      time.Now().Add(-dbNodeExpiration + time.Minute),
+		exp:       false,
+	},
+	{
+		node: NewV4(
+			hexPubkey("3b73a9e5f4af6c4701c57c73cc8cfa0f4802840b24c11eba92aac3aef65644a3728b4b2aec8199f6d72bd66be2c65861c773129039bd47daa091ca90a6d4c857"),
+			net.IP{127, 0, 0, 7},
+			30303,
+			30303,
+		),
+		storeNode: false,
+		pong:      time.Now().Add(-dbNodeExpiration - time.Minute),
+		exp:       true,
 	},
 }
 
@@ -350,23 +426,39 @@ func TestDBExpiration(t *testing.T) {
 	db, _ := OpenDB("")
 	defer db.Close()
 
-	// Add all the test nodes and set their last pong time
+	// Add all the test nodes and set their last pong time.
 	for i, seed := range nodeDBExpirationNodes {
-		if err := db.UpdateNode(seed.node); err != nil {
-			t.Fatalf("node %d: failed to insert: %v", i, err)
+		if seed.storeNode {
+			if err := db.UpdateNode(seed.node); err != nil {
+				t.Fatalf("node %d: failed to insert: %v", i, err)
+			}
 		}
-		if err := db.UpdateLastPongReceived(seed.node.ID(), seed.pong); err != nil {
+		if err := db.UpdateLastPongReceived(seed.node.ID(), seed.node.IP(), seed.pong); err != nil {
 			t.Fatalf("node %d: failed to update bondTime: %v", i, err)
 		}
 	}
-	// Expire some of them, and check the rest
-	if err := db.expireNodes(); err != nil {
-		t.Fatalf("failed to expire nodes: %v", err)
-	}
+
+	db.expireNodes()
+
+	// Check that expired entries have been removed.
+	unixZeroTime := time.Unix(0, 0)
 	for i, seed := range nodeDBExpirationNodes {
 		node := db.Node(seed.node.ID())
-		if (node == nil && !seed.exp) || (node != nil && seed.exp) {
-			t.Errorf("node %d: expiration mismatch: have %v, want %v", i, node, seed.exp)
+		pong := db.LastPongReceived(seed.node.ID(), seed.node.IP())
+		if seed.exp {
+			if seed.storeNode && node != nil {
+				t.Errorf("node %d (%s) shouldn't be present after expiration", i, seed.node.ID().TerminalString())
+			}
+			if !pong.Equal(unixZeroTime) {
+				t.Errorf("pong time %d (%s %v) shouldn't be present after expiration", i, seed.node.ID().TerminalString(), seed.node.IP())
+			}
+		} else {
+			if seed.storeNode && node == nil {
+				t.Errorf("node %d (%s) should be present after expiration", i, seed.node.ID().TerminalString())
+			}
+			if !pong.Equal(seed.pong.Truncate(1 * time.Second)) {
+				t.Errorf("pong time %d (%s) should be %v after expiration, but is %v", i, seed.node.ID().TerminalString(), seed.pong, pong)
+			}
 		}
 	}
 }