optionally log errors (used in testing hook to catch non-fatal errors)

Author: philhofer

client.go

@@ -4,6 +4,7 @@ import (
 	"crypto/tls"
 	"errors"
 	"fmt"
+	"log"
 	"net"
 	"sync"
 	"sync/atomic"
@@ -40,6 +41,27 @@ var (
 	ErrTooLarge = errors.New("synapse: message body too large")
 )
 
+// ErrorLogger is the logger used
+// by the package to log protocol
+// errors. (In general, protocol-level
+// errors are not returned directly
+// to the client.) It can be set during
+// initialization. If it is left
+// as nil, nothing will be logged.
+var ErrorLogger *log.Logger
+
+func errorln(s string) {
+	if ErrorLogger != nil {
+		ErrorLogger.Println(s)
+	}
+}
+
+func errorf(s string, args ...interface{}) {
+	if ErrorLogger != nil {
+		ErrorLogger.Printf(s, args...)
+	}
+}
+
 // Dial creates a new client by dialing
 // the provided network and remote address.
 // The provided timeout is used as the timeout
@@ -199,6 +221,7 @@ func (c *Client) readLoop() {
 		// they are routed to waiters
 		// precisely the same way
 		if frame != fCMD && frame != fRES {
+			errorf("server at addr %s sent a bad frame", c.conn.RemoteAddr())
 			// ignore
 			if !c.do(bwr.Skip(sz)) {
 				return
@@ -458,5 +481,8 @@ func (c *Client) ping() error {
 
 // sync known service addresses
 func (c *Client) syncLinks() {
-	c.sendCommand(cmdListLinks, svclistbytes())
+	err := c.sendCommand(cmdListLinks, svclistbytes())
+	if err != nil {
+		errorf("error synchronizing links: %s", err)
+	}
 }

client_test.go

@@ -16,6 +16,7 @@ func isCode(err error, c Status) bool {
 }
 
 func TestClientServiceName(t *testing.T) {
+	setTestLog(t)
 	if tcpClient.Service() != "test-endpoint" {
 		t.Errorf("expected service endpoint to be %q, but got %q", "test-endpoint", tcpClient.Service())
 	}
@@ -25,6 +26,7 @@ func TestClientServiceName(t *testing.T) {
 }
 
 func TestNearest(t *testing.T) {
+	setTestLog(t)
 	svc := Nearest("test-endpoint")
 	if svc == nil {
 		t.Error("expected Nearest(test-endpoint) to return something")
@@ -51,6 +53,7 @@ func TestNearest(t *testing.T) {
 // open up a client and server; make
 // some concurrent requests
 func TestClient(t *testing.T) {
+	setTestLog(t)
 
 	const concurrent = 5
 	wg := new(sync.WaitGroup)
@@ -83,6 +86,7 @@ func TestClient(t *testing.T) {
 // the output of the debug handler
 // is only visible if '-v' is set
 func TestDebugClient(t *testing.T) {
+	setTestLog(t)
 	attachDebug("debug_echo", t)
 
 	instr := String("here's a message body!")
@@ -99,6 +103,7 @@ func TestDebugClient(t *testing.T) {
 // test that 'nil' is a safe
 // argument to requests and responses
 func TestNop(t *testing.T) {
+	setTestLog(t)
 	err := tcpClient.Call("nop", nil, nil)
 	if err != nil {
 		t.Fatal(err)

command.go

@@ -88,12 +88,13 @@ const (
 
 // client-side ping finalizer
 func recvping(cl *Client, res []byte) {
+	r := cl.conn.RemoteAddr()
 	var s Service
 	_, err := s.UnmarshalMsg(res)
 	if err != nil {
+		errorf("server at addr %s sent a malformed ping response", r)
 		return
 	}
-	r := cl.conn.RemoteAddr()
 	s.net = r.Network()
 	s.addr = r.String()
 	cache(&s)
@@ -113,6 +114,7 @@ func recvlinks(cl *Client, res []byte) {
 	sl := serviceTable{}
 	_, err := sl.UnmarshalMsg(res)
 	if err != nil {
+		errorf("server at addr %s sent malformed links: %s", cl.conn.RemoteAddr(), err)
 		return
 	}
 	svcCache.Lock()

server.go

@@ -94,7 +94,7 @@ func ServeConn(c net.Conn, service string, h Handler) {
 		h:       h,
 		remote:  c.RemoteAddr(),
 		writing: make(chan *connWrapper, 32),
-		route:   getRoute(c),
+		route:   getRoute(c.RemoteAddr()),
 	}
 	go ch.writeLoop()
 	ch.connLoop()     // returns on connection close
@@ -140,18 +140,17 @@ const (
 	routeOSLocal                // same machine (unix socket / loopback)
 )
 
-func getRoute(c net.Conn) route {
-	raddr := c.RemoteAddr()
+func getRoute(raddr net.Addr) route {
 	nwk := raddr.Network()
 	switch nwk {
 	case "unix":
 		return routeOSLocal
 	case "tcp", "tcp4", "tcp6":
-		a, err := net.ResolveIPAddr(nwk, raddr.String())
+		a, err := net.ResolveTCPAddr(nwk, raddr.String())
 		if err != nil {
 			return routeUnknown
 		}
-		if a.IP.IsLoopback() {
+		if a.IP.IsLoopback() || a.IP.IsLinkLocalUnicast() {
 			return routeOSLocal
 		} else if a.IP.IsLinkLocalUnicast() {
 			return routeLinkLocal

service.go

@@ -150,9 +150,12 @@ func isRoutable(s *Service) bool {
 	switch s.net {
 	case "tcp", "tcp6", "tcp4":
 		a, err := net.ResolveTCPAddr(s.net, s.addr)
-
+		if err != nil {
+			errorf("couldn't resolve tcp addr %s: %s", s.addr, err)
+			return false
+		}
 		// TODO: link-local addresses
-		return err == nil && a.IP.IsGlobalUnicast()
+		return a.IP.IsGlobalUnicast()
 	default:
 		return false
 	}

setup_test.go

@@ -3,8 +3,10 @@ package synapse
 import (
 	"fmt"
 	"io"
+	"log"
 	"net"
 	"os"
+	"sync"
 	"testing"
 	"time"
 
@@ -29,8 +31,32 @@ var (
 	rt *Router
 
 	ct testing.T
+
+	loglock sync.Mutex
 )
 
+type faillog struct {
+	t *testing.T
+}
+
+func (f *faillog) Write(b []byte) (int, error) {
+	loglock.Lock()
+	f.t.Error("error logged")
+	i, err := os.Stderr.Write(b)
+	loglock.Unlock()
+	return i, err
+}
+
+func fail(t *testing.T) io.Writer {
+	return &faillog{t}
+}
+
+func setTestLog(t *testing.T) {
+	loglock.Lock()
+	ErrorLogger = log.New(fail(t), "synapse-error-log: ", log.LstdFlags)
+	loglock.Unlock()
+}
+
 // attaches a debug(echo handler) at the named
 // route w/ the provided *testing.T
 func attachDebug(name string, t *testing.T) {

svc_test/sstc/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"flag"
 	"fmt"
+	"log"
 	"os"
 	"time"
 
@@ -36,6 +37,10 @@ func dumpservices(srv string) {
 	}
 }
 
+func init() {
+	synapse.ErrorLogger = log.New(os.Stderr, "syn-client-log: ", log.LstdFlags)
+}
+
 func main() {
 	cl, err := synapse.Dial("tcp", *port, 25*time.Millisecond)
 	if err != nil {
@@ -70,6 +75,10 @@ func main() {
 	if err != nil {
 		perror("client: couldn't dial socket:", err)
 	}
+	// give the second client time
+	// to complete another round of
+	// list synchronization.
+	time.Sleep(50 * time.Millisecond)
 	err = cl2.Close()
 	if err != nil {
 		perror("client: close error:", err)

svc_test/ssts/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"flag"
 	"fmt"
+	"log"
 	"net"
 	"os"
 	"os/signal"
@@ -44,6 +45,10 @@ func (e echoHandler) ServeCall(req synapse.Request, res synapse.ResponseWriter)
 	}
 }
 
+func init() {
+	synapse.ErrorLogger = log.New(os.Stderr, "syn-server-log: ", log.LstdFlags)
+}
+
 func main() {
 	go func() {
 		err := synapse.ListenAndServe("tcp", *port, "service-test", echoHandler{})