Merge pull request #552 from bboreham/status-conn-errors

Allow ConnectionMaker to report the reason the connection broke

router/connection.go

@@ -284,7 +284,8 @@ func (conn *LocalConnection) sendAction(action ConnectionAction) {
 // ACTOR server
 
 func (conn *LocalConnection) run(actionChan <-chan ConnectionAction, finished chan<- struct{}, acceptNewPeer bool) {
-	defer conn.shutdown()
+	var err error // important to use this var and not create another one with 'err :='
+	defer func() { conn.shutdown(err) }()
 	defer close(finished)
 
 	tcpConn := conn.TCPConn
@@ -292,14 +293,12 @@ func (conn *LocalConnection) run(actionChan <-chan ConnectionAction, finished ch
 	enc := gob.NewEncoder(tcpConn)
 	dec := gob.NewDecoder(tcpConn)
 
-	if err := conn.handshake(enc, dec, acceptNewPeer); err != nil {
-		log.Printf("->[%s] connection shutting down due to error during handshake: %v\n", conn.remoteTCPAddr, err)
+	if err = conn.handshake(enc, dec, acceptNewPeer); err != nil {
 		return
 	}
 	log.Printf("->[%s] completed handshake with %s\n", conn.remoteTCPAddr, conn.remote.FullName())
 
-	if err := conn.initHeartbeats(); err != nil { // [1]
-		conn.Log("connection shutting down due to error:", err)
+	if err = conn.initHeartbeats(); err != nil { // [1]
 		return
 	}
 
@@ -307,11 +306,7 @@ func (conn *LocalConnection) run(actionChan <-chan ConnectionAction, finished ch
 
 	go conn.receiveTCP(dec) // [1]
 
-	if err := conn.actorLoop(actionChan); err != nil { // [1]
-		conn.Log("connection shutting down due to error:", err)
-		return
-	}
-	conn.Log("connection shutting down")
+	err = conn.actorLoop(actionChan) // [1]
 }
 
 // [1] Ordering constraints:
@@ -376,7 +371,16 @@ func (conn *LocalConnection) actorLoop(actionChan <-chan ConnectionAction) (err
 	return
 }
 
-func (conn *LocalConnection) shutdown() {
+func (conn *LocalConnection) shutdown(err error) {
+	switch {
+	case err != nil && conn.remote == nil:
+		log.Printf("->[%s] connection shutting down due to error during handshake: %v\n", conn.remoteTCPAddr, err)
+	case err != nil:
+		conn.Log("connection shutting down due to error:", err)
+	default:
+		conn.Log("connection shutting down")
+	}
+
 	if conn.TCPConn != nil {
 		checkWarn(conn.TCPConn.Close())
 	}
@@ -398,7 +402,7 @@ func (conn *LocalConnection) shutdown() {
 	// try to send any more
 	conn.stopForwarders()
 
-	conn.Router.ConnectionMaker.ConnectionTerminated(conn.remoteTCPAddr)
+	conn.Router.ConnectionMaker.ConnectionTerminated(conn.remoteTCPAddr, err)
 }
 
 // Helpers

router/connection_maker.go

@@ -26,6 +26,7 @@ type ConnectionMaker struct {
 // Information about an address where we may find a peer
 type Target struct {
 	attempting  bool          // are we currently attempting to connect there?
+	lastError   error         // reason for disconnection last time
 	tryAfter    time.Time     // next time to try this address
 	tryInterval time.Duration // backoff time on next failure
 }
@@ -72,10 +73,11 @@ func (cm *ConnectionMaker) ForgetConnection(peer string) {
 	}
 }
 
-func (cm *ConnectionMaker) ConnectionTerminated(address string) {
+func (cm *ConnectionMaker) ConnectionTerminated(address string, err error) {
 	cm.actionChan <- func() bool {
 		if target, found := cm.targets[address]; found {
 			target.attempting = false
+			target.lastError = err
 			target.tryAfter, target.tryInterval = tryAfter(target.tryInterval)
 		}
 		return true
@@ -97,13 +99,15 @@ func (cm *ConnectionMaker) String() string {
 	cm.actionChan <- func() bool {
 		var buf bytes.Buffer
 		for address, target := range cm.targets {
-			var fmtStr string
+			fmt.Fprint(&buf, address)
+			if target.lastError != nil {
+				fmt.Fprintf(&buf, " (%s)", target.lastError)
+			}
 			if target.attempting {
-				fmtStr = "%s (trying since %v)\n"
+				fmt.Fprintf(&buf, " (trying since %v)\n", target.tryAfter)
 			} else {
-				fmtStr = "%s (next try at %v)\n"
+				fmt.Fprintf(&buf, " (next try at %v)\n", target.tryAfter)
 			}
-			fmt.Fprintf(&buf, fmtStr, address, target.tryAfter)
 		}
 		resultChan <- buf.String()
 		return false
@@ -213,7 +217,7 @@ func (cm *ConnectionMaker) attemptConnection(address string, acceptNewPeer bool)
 	log.Printf("->[%s] attempting connection\n", address)
 	if err := cm.ourself.CreateConnection(address, acceptNewPeer); err != nil {
 		log.Printf("->[%s] error during connection attempt: %v\n", address, err)
-		cm.ConnectionTerminated(address)
+		cm.ConnectionTerminated(address, err)
 	}
 }
 

site/troubleshooting.md

@@ -79,7 +79,7 @@ broadcast:
 7a:f4:56:87:76:3b -> [7a:16:dd:5b:83:de]
 7a:16:dd:5b:83:de -> []
 Reconnects:
-192.168.32.1:6783 (next try at 2014-10-23 16:39:50.585932102 +0000 UTC)
+192.168.32.1:6783 (dial tcp4 192.168.32.1:6783: connection timed out) (next try at 2014-10-23 16:39:50.585932102 +0000 UTC)
 
 weavedns container is not present; have you launched it?
 ````
@@ -121,8 +121,8 @@ for a full explanation.
 
 The 'Reconnects' section lists peers that this router is aware of, but is
 not currently connected to.  Each line contains some information about
-whether it is attempting to connect or is waiting for a while before
-connecting again.
+what went wrong the last time; whether it is attempting to connect or
+is waiting for a while before connecting again.
 
 Finally, status information from weave DNS is included. In this example,
 the DNS container has not been launched so no status information is