From f8ec56ea79042bc65770209c4cac4a636c5507af Mon Sep 17 00:00:00 2001 From: Bryan Boreham Date: Mon, 13 Apr 2015 14:21:11 +0100 Subject: [PATCH 1/2] Move connection shutdown logging into shutdown() --- router/connection.go | 26 +++++++++++++++----------- 1 file changed, 15 insertions(+), 11 deletions(-) diff --git a/router/connection.go b/router/connection.go index a17a6fea..d7cebcd0 100644 --- a/router/connection.go +++ b/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()) } From 8ad244e0f93d6ad0e9de967eeae1c6296d54b7a8 Mon Sep 17 00:00:00 2001 From: Bryan Boreham Date: Mon, 13 Apr 2015 14:21:59 +0100 Subject: [PATCH 2/2] Let ConnectionMaker report the reason the connection broke --- router/connection.go | 2 +- router/connection_maker.go | 16 ++++++++++------ site/troubleshooting.md | 6 +++--- 3 files changed, 14 insertions(+), 10 deletions(-) diff --git a/router/connection.go b/router/connection.go index d7cebcd0..2d10f692 100644 --- a/router/connection.go +++ b/router/connection.go @@ -402,7 +402,7 @@ func (conn *LocalConnection) shutdown(err error) { // try to send any more conn.stopForwarders() - conn.Router.ConnectionMaker.ConnectionTerminated(conn.remoteTCPAddr) + conn.Router.ConnectionMaker.ConnectionTerminated(conn.remoteTCPAddr, err) } // Helpers diff --git a/router/connection_maker.go b/router/connection_maker.go index c50b1944..f19d2aaf 100644 --- a/router/connection_maker.go +++ b/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 } @@ -64,10 +65,11 @@ func (cm *ConnectionMaker) ForgetConnection(address 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 @@ -89,13 +91,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 @@ -201,7 +205,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) } } diff --git a/site/troubleshooting.md b/site/troubleshooting.md index 490df9a0..172ed8a0 100644 --- a/site/troubleshooting.md +++ b/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