peer-level integration test for crypto handshake

- add const length params for handshake messages
- add length check to fail early
- add debug logs to help interop testing (!ABSOLUTELY SHOULD BE DELETED LATER)
- wrap connection read/writes in error check
- add cryptoReady channel in peer to signal when secure session setup is finished
- wait for cryptoReady or timeout in TestPeersHandshake

3 files changed, 71 insertions, 15 deletions

diff --git a/p2p/crypto.go b/p2p/crypto.go
index 91d60aa7e..e8f4d551b 100644
--- a/p2p/crypto.go
+++ b/p2p/crypto.go
@@ -21,6 +21,8 @@ var (
 	keyLen int = 32  // ECDSA
 	msgLen int = 194 // sigLen + keyLen + pubLen + keyLen + 1 = 194
 	resLen int = 97  // pubLen + keyLen + 1
+	iHSLen int = 307 // size of the final ECIES payload sent as initiator's handshake
+	rHSLen int = 210 // size of the final ECIES payload sent as receiver's handshake
 )
 
 // secretRW implements a message read writer with encryption and authentication
@@ -66,7 +68,8 @@ func newCryptoId(id ClientIdentity) (self *cryptoId, err error) {
 		// for reuse, call wth ReadAt, no reset seek needed
 	}
 	self.pubKeyS = id.Pubkey()[1:]
-	clogger.Debugf("crytoid starting for %v", hexkey(self.pubKeyS))
+	clogger.Debugf("initialise crypto for NodeId %v", hexkey(self.pubKeyS))
+	clogger.Debugf("private-key %v\npublic key %v", hexkey(prvKeyS), hexkey(self.pubKeyS))
 	return
 }
 
@@ -92,22 +95,51 @@ Run(connection, remotePublicKey, sessionToken) is called when the peer connectio
 
 func (self *cryptoId) Run(conn io.ReadWriter, remotePubKeyS []byte, sessionToken []byte, initiator bool) (token []byte, rw *secretRW, err error) {
 	var auth, initNonce, recNonce []byte
+	var read int
 	var randomPrivKey *ecdsa.PrivateKey
 	var remoteRandomPubKey *ecdsa.PublicKey
+	clogger.Debugf("attempting session with %v", hexkey(remotePubKeyS))
 	if initiator {
 		if auth, initNonce, randomPrivKey, _, err = self.startHandshake(remotePubKeyS, sessionToken); err != nil {
 			return
 		}
-		conn.Write(auth)
-		var response []byte
-		conn.Read(response)
+		clogger.Debugf("initiator-nonce: %v", hexkey(initNonce))
+		clogger.Debugf("initiator-random-private-key: %v", hexkey(crypto.FromECDSA(randomPrivKey)))
+		randomPublicKeyS, _ := ExportPublicKey(&randomPrivKey.PublicKey)
+		clogger.Debugf("initiator-random-public-key: %v", hexkey(randomPublicKeyS))
+
+		if _, err = conn.Write(auth); err != nil {
+			return
+		}
+		clogger.Debugf("initiator handshake (sent to %v):\n%v", hexkey(remotePubKeyS), hexkey(auth))
+		var response []byte = make([]byte, rHSLen)
+		if read, err = conn.Read(response); err != nil || read == 0 {
+			return
+		}
+		if read != rHSLen {
+			err = fmt.Errorf("remote receiver's handshake has invalid length. expect %v, got %v", rHSLen, read)
+			return
+		}
 		// write out auth message
 		// wait for response, then call complete
 		if recNonce, remoteRandomPubKey, _, err = self.completeHandshake(response); err != nil {
 			return
 		}
+		clogger.Debugf("receiver-nonce: %v", hexkey(recNonce))
+		remoteRandomPubKeyS, _ := ExportPublicKey(remoteRandomPubKey)
+		clogger.Debugf("receiver-random-public-key: %v", hexkey(remoteRandomPubKeyS))
+
 	} else {
-		conn.Read(auth)
+		auth = make([]byte, iHSLen)
+		clogger.Debugf("waiting for initiator handshake (from %v)", hexkey(remotePubKeyS))
+		if read, err = conn.Read(auth); err != nil {
+			return
+		}
+		if read != iHSLen {
+			err = fmt.Errorf("remote initiator's handshake has invalid length. expect %v, got %v", iHSLen, read)
+			return
+		}
+		clogger.Debugf("received initiator handshake (from %v):\n%v", hexkey(remotePubKeyS), hexkey(auth))
 		// we are listening connection. we are responders in the handshake.
 		// Extract info from the authentication. The initiator starts by sending us a handshake that we need to respond to.
 		// so we read auth message first, then respond
@@ -115,7 +147,12 @@ func (self *cryptoId) Run(conn io.ReadWriter, remotePubKeyS []byte, sessionToken
 		if response, recNonce, initNonce, randomPrivKey, remoteRandomPubKey, err = self.respondToHandshake(auth, remotePubKeyS, sessionToken); err != nil {
 			return
 		}
-		conn.Write(response)
+		clogger.Debugf("receiver-nonce: %v", hexkey(recNonce))
+		clogger.Debugf("receiver-random-priv-key: %v", hexkey(crypto.FromECDSA(randomPrivKey)))
+		if _, err = conn.Write(response); err != nil {
+			return
+		}
+		clogger.Debugf("receiver handshake (sent to %v):\n%v", hexkey(remotePubKeyS), hexkey(response))
 	}
 	return self.newSession(initNonce, recNonce, auth, randomPrivKey, remoteRandomPubKey)
 }
@@ -354,6 +391,10 @@ func (self *cryptoId) newSession(initNonce, respNonce, auth []byte, privKey *ecd
 		egressMac:  egressMac,
 		ingressMac: ingressMac,
 	}
+	clogger.Debugf("aes-secret: %v", hexkey(aesSecret))
+	clogger.Debugf("mac-secret: %v", hexkey(macSecret))
+	clogger.Debugf("egress-mac: %v", hexkey(egressMac))
+	clogger.Debugf("ingress-mac: %v", hexkey(ingressMac))
 	return
 }
 
diff --git a/p2p/crypto_test.go b/p2p/crypto_test.go
index 5fbdc61e3..47b16040a 100644
--- a/p2p/crypto_test.go
+++ b/p2p/crypto_test.go
@@ -8,6 +8,7 @@ import (
 	"fmt"
 	"net"
 	"testing"
+	"time"
 
 	"github.com/ethereum/go-ethereum/crypto"
 	"github.com/obscuren/ecies"
@@ -184,7 +185,17 @@ func TestPeersHandshake(t *testing.T) {
 		_, err := receiver.loop()
 		errc1 <- err
 	}()
+	ready := make(chan bool)
+	go func() {
+		<-initiator.cryptoReady
+		<-receiver.cryptoReady
+		close(ready)
+	}()
+	timeout := time.After(1 * time.Second)
 	select {
+	case <-ready:
+	case <-timeout:
+		t.Errorf("crypto handshake hanging for too long")
 	case err = <-errc0:
 		t.Errorf("peer 0 quit with error: %v", err)
 	case err = <-errc1:
diff --git a/p2p/peer.go b/p2p/peer.go
index e44eaab34..818f80580 100644
--- a/p2p/peer.go
+++ b/p2p/peer.go
@@ -71,6 +71,7 @@ type Peer struct {
 	protocols       []Protocol
 	runBaseProtocol bool // for testing
 	cryptoHandshake bool // for testing
+	cryptoReady     chan struct{}
 
 	runlock sync.RWMutex // protects running
 	running map[string]*proto
@@ -120,15 +121,16 @@ func newServerPeer(server *Server, conn net.Conn, dialAddr *peerAddr) *Peer {
 
 func newPeer(conn net.Conn, protocols []Protocol, dialAddr *peerAddr) *Peer {
 	p := &Peer{
-		Logger:    logger.NewLogger("P2P " + conn.RemoteAddr().String()),
-		conn:      conn,
-		dialAddr:  dialAddr,
-		bufconn:   bufio.NewReadWriter(bufio.NewReader(conn), bufio.NewWriter(conn)),
-		protocols: protocols,
-		running:   make(map[string]*proto),
-		disc:      make(chan DiscReason),
-		protoErr:  make(chan error),
-		closed:    make(chan struct{}),
+		Logger:      logger.NewLogger("P2P " + conn.RemoteAddr().String()),
+		conn:        conn,
+		dialAddr:    dialAddr,
+		bufconn:     bufio.NewReadWriter(bufio.NewReader(conn), bufio.NewWriter(conn)),
+		protocols:   protocols,
+		running:     make(map[string]*proto),
+		disc:        make(chan DiscReason),
+		protoErr:    make(chan error),
+		closed:      make(chan struct{}),
+		cryptoReady: make(chan struct{}),
 	}
 	return p
 }
@@ -240,6 +242,7 @@ func (p *Peer) loop() (reason DiscReason, err error) {
 	go readLoop(readMsg, readErr, readNext)
 	readNext <- true
 
+	close(p.cryptoReady)
 	if p.runBaseProtocol {
 		p.startBaseProtocol()
 	}
@@ -353,6 +356,7 @@ func (p *Peer) handleCryptoHandshake() (loop readLoop, err error) {
 	// this bit handles the handshake and creates a secure communications channel with
 	// var rw *secretRW
 	if sessionToken, _, err = crypto.Run(p.conn, p.Pubkey(), sessionToken, initiator); err != nil {
+		p.Debugf("unable to setup secure session: %v", err)
 		return
 	}
 	loop = func(msg chan<- Msg, err chan<- error, next <-chan bool) {