Merge pull request #135 from Darkren/fix/improve-route-group-logging

Improve route group logging, fix route group closing procedure

go.mod

@@ -13,16 +13,19 @@ require (
 	github.com/gorilla/handlers v1.4.2
 	github.com/gorilla/securecookie v1.1.1
 	github.com/hashicorp/yamux v0.0.0-20190923154419-df201c70410d
+	github.com/konsorten/go-windows-terminal-sequences v1.0.2 // indirect
 	github.com/kr/pretty v0.2.0 // indirect
+	github.com/mattn/go-isatty v0.0.12 // indirect
 	github.com/pkg/profile v1.3.0
 	github.com/prometheus/client_golang v1.3.0
 	github.com/prometheus/common v0.7.0
 	github.com/sirupsen/logrus v1.4.2
 	github.com/spf13/cobra v0.0.5
 	github.com/stretchr/testify v1.4.0
 	go.etcd.io/bbolt v1.3.3
-	golang.org/x/crypto v0.0.0-20200117160349-530e935923ad
+	golang.org/x/crypto v0.0.0-20200128174031-69ecbb4d6d5d
 	golang.org/x/net v0.0.0-20191204025024-5ee1b9f4859a
+	golang.org/x/sys v0.0.0-20200124204421-9fbb57f87de9 // indirect
 )
 
 //replace github.com/SkycoinProject/dmsg => ../dmsg

go.sum

@@ -1,4 +1,14 @@
 github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU=
+github.com/SkycoinProject/dmsg v0.0.0-20191106075825-cabc26522b11 h1:OpkHFoRtTKkcaNy/iCdBOyuFqLyy0geXtLz3vOD1FfE=
+github.com/SkycoinProject/dmsg v0.0.0-20191106075825-cabc26522b11/go.mod h1:aJrtm4X13hJDh+EX4amx51EBaLvSKjhFH8tf0E8Xxx4=
+github.com/SkycoinProject/dmsg v0.0.0-20191107094546-85c27858fca6 h1:qL8+QqCaEzNO4vesE50kZyX1o7BOiwxUMYi1OX/J6KM=
+github.com/SkycoinProject/dmsg v0.0.0-20191107094546-85c27858fca6/go.mod h1:Omi1J0gOWWriHkHn/9aGw8JXHtsEfnYwithZY6fIEQY=
+github.com/SkycoinProject/dmsg v0.0.0-20200116114634-91be578a1895 h1:lnTxeHdSdju5bdFknXD5CsxYe+MVAuBwFeHcG6DgYGA=
+github.com/SkycoinProject/dmsg v0.0.0-20200116114634-91be578a1895/go.mod h1:ND2IgJU0IdbkF1FS0We0EoI/2Gqx6MWJe12zC/KsTzI=
+github.com/SkycoinProject/dmsg v0.0.0-20200128120244-669ad29a4e6b h1:t0tIsfWPDDd/vsw/mOW4hA0xwQ3rFxdOQA+sjc9YSoo=
+github.com/SkycoinProject/dmsg v0.0.0-20200128120244-669ad29a4e6b/go.mod h1:/nTdcMBrMHE39N6fxm300DtMly3UvZXPfwxBa9U8oGs=
+github.com/SkycoinProject/dmsg v0.0.0-20200128130016-bdcb95cea9ac h1:9O98qvwAyRf8vWmTic3bIWu7Ulg89V9TnXtabS8ise0=
+github.com/SkycoinProject/dmsg v0.0.0-20200128130016-bdcb95cea9ac/go.mod h1:/nTdcMBrMHE39N6fxm300DtMly3UvZXPfwxBa9U8oGs=
 github.com/SkycoinProject/dmsg v0.0.0-20200129011427-cd48108c339f h1:hAb4pyFTJ5hJttXGQ/6PzsMqpiOBfBj/BN3jJoeD5Vo=
 github.com/SkycoinProject/dmsg v0.0.0-20200129011427-cd48108c339f/go.mod h1:/nTdcMBrMHE39N6fxm300DtMly3UvZXPfwxBa9U8oGs=
 github.com/SkycoinProject/skycoin v0.26.0 h1:8/ZRZb2VM2DM4YTIitRJMZ3Yo/3H1FFmbCMx5o6ekmA=
@@ -66,6 +76,8 @@ github.com/json-iterator/go v1.1.8/go.mod h1:KdQUCv79m/52Kvf8AW2vK1V8akMuk1QjK/u
 github.com/julienschmidt/httprouter v1.2.0/go.mod h1:SYymIcj16QtmaHHD7aYtjjsJG7VTCxuUUipMqKk8s4w=
 github.com/konsorten/go-windows-terminal-sequences v1.0.1 h1:mweAR1A6xJ3oS2pRaGiHgQ4OO8tzTaLawm8vnODuwDk=
 github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ=
+github.com/konsorten/go-windows-terminal-sequences v1.0.2 h1:DB17ag19krx9CFsz4o3enTrPXyIXCl+2iCXH/aMAp9s=
+github.com/konsorten/go-windows-terminal-sequences v1.0.2/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ=
 github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515/go.mod h1:+0opPa2QZZtGFBFZlji/RkVcI2GknAs/DXo4wKdlNEc=
 github.com/kr/pretty v0.2.0 h1:s5hAObm+yFO5uHYt5dYjxi2rXrsnmRpJx4OYvIWUaQs=
 github.com/kr/pretty v0.2.0/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI=
@@ -77,6 +89,8 @@ github.com/mattn/go-colorable v0.1.4 h1:snbPLB8fVfU9iwbbo30TPtbLRzwWu6aJS6Xh4eaa
 github.com/mattn/go-colorable v0.1.4/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE=
 github.com/mattn/go-isatty v0.0.8 h1:HLtExJ+uU2HOZ+wI0Tt5DtUDrx8yhUqDcp7fYERX4CE=
 github.com/mattn/go-isatty v0.0.8/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s=
+github.com/mattn/go-isatty v0.0.12 h1:wuysRhFDzyxgEmMf5xjvJ2M9dZoWAXNNr5LSBS7uHXY=
+github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU=
 github.com/matttproud/golang_protobuf_extensions v1.0.1 h1:4hp9jkHxhMHkqkrB3Ix0jegS5sx/RkqARlsWZ6pIwiU=
 github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0=
 github.com/mgutz/ansi v0.0.0-20170206155736-9520e82c474b h1:j7+1HpAFS1zy5+Q4qx1fWh90gTKwiN4QCGoY9TWyyO4=
@@ -144,6 +158,8 @@ golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACk
 golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
 golang.org/x/crypto v0.0.0-20200117160349-530e935923ad h1:Jh8cai0fqIK+f6nG0UgPW5wFk8wmiMhM3AyciDBdtQg=
 golang.org/x/crypto v0.0.0-20200117160349-530e935923ad/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto=
+golang.org/x/crypto v0.0.0-20200128174031-69ecbb4d6d5d h1:9FCpayM9Egr1baVnV1SX0H87m+XB0B8S0hAMi99X/3U=
+golang.org/x/crypto v0.0.0-20200128174031-69ecbb4d6d5d/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto=
 golang.org/x/mod v0.1.1-0.20191105210325-c90efee705ee/go.mod h1:QqPTAvyqsEbceGzBzNggFXnrqF1CaUcvgkdR5Ot7KZg=
 golang.org/x/net v0.0.0-20181114220301-adae6a3d119a/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4=
 golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
@@ -164,6 +180,9 @@ golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7w
 golang.org/x/sys v0.0.0-20190422165155-953cdadca894/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20191220142924-d4481acd189f h1:68K/z8GLUxV76xGSqwTWw2gyk/jwn79LUL43rES2g8o=
 golang.org/x/sys v0.0.0-20191220142924-d4481acd189f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20200116001909-b77594299b42/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20200124204421-9fbb57f87de9 h1:1/DFK4b7JH8DmkqhUk48onnSfrPzImPoVxuomtbT2nk=
+golang.org/x/sys v0.0.0-20200124204421-9fbb57f87de9/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/text v0.3.0 h1:g61tztE5qeGQ89tm6NTjjM9VPIm088od1l6aSorWRWg=
 golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
 golang.org/x/tools v0.0.0-20200124021010-5c352bb417e0 h1:G9K47VwP2wDdADV683EnkOYQHhb20LSa80C4AE+Gskw=

pkg/router/route_group.go

@@ -354,6 +354,7 @@ func (rg *RouteGroup) sendKeepAlive() error {
 
 	packet := routing.MakeKeepAlivePacket(rule.KeyRouteID())
 	if err := tp.WritePacket(context.Background(), packet); err != nil {
+		rg.logger.WithError(err).Error("Failed to send keep-alive packet")
 		return err
 	}
 
@@ -380,10 +381,7 @@ func (rg *RouteGroup) close(code routing.CloseCode) error {
 		rg.closeDone.Add(len(rg.tps))
 	}
 
-	if err := rg.broadcastClosePackets(code); err != nil {
-		// TODO: decide if we should return this error, or close route group anyway
-		return err
-	}
+	rg.broadcastClosePackets(code)
 
 	if closeInitiator {
 		// if this node initiated closing, we need to wait for close packets
@@ -430,16 +428,13 @@ func (rg *RouteGroup) handleClosePacket(code routing.CloseCode) error {
 	return rg.close(code)
 }
 
-func (rg *RouteGroup) broadcastClosePackets(code routing.CloseCode) error {
+func (rg *RouteGroup) broadcastClosePackets(code routing.CloseCode) {
 	for i := 0; i < len(rg.tps); i++ {
 		packet := routing.MakeClosePacket(rg.fwd[i].KeyRouteID(), code)
 		if err := rg.tps[i].WritePacket(context.Background(), packet); err != nil {
-			// TODO: decide if we should return this error, or close route group anyway
-			return err
+			rg.logger.WithError(err).Error("Failed to send close packet")
 		}
 	}
-
-	return nil
 }
 
 func (rg *RouteGroup) waitForCloseLoop(waitTimeout time.Duration) error {

pkg/transport/managed_transport.go

@@ -152,7 +152,7 @@ func (mt *ManagedTransport) Serve(readCh chan<- routing.Packet, done <-chan stru
 				mt.connMx.Lock()
 				if mt.conn == nil {
 					if ok, err := mt.redial(ctx); err != nil {
-						mt.log.Warnf("failed to redial underlying connection: %v", err)
+						mt.log.Warnf("failed to redial underlying connection (redial loop): %v", err)
 						if !ok {
 							mt.connMx.Unlock()
 							return