expose latency timer on WSClient

glide.lock

@@ -1,5 +1,5 @@
-hash: 2c988aae9517b386ee911e4da5deb9f5034359b7e2ccf448952a3ddb9771222d
-updated: 2017-06-28T13:04:20.907047164+02:00
+hash: 41581813ff97225a7feb86b5accb0fe4acb3e198b64592d7452240e9473c479f
+updated: 2017-08-03T19:17:16.410522485Z
 imports:
 - name: github.com/btcsuite/btcd
   version: b8df516b4b267acf2de46be593a9d948d1d2c420
@@ -61,6 +61,8 @@ imports:
   version: 5ccdfb18c776b740aecaf085c4d9a2779199c279
 - name: github.com/pkg/errors
   version: 645ef00459ed84a119197bfb8d8205042c6df63d
+- name: github.com/rcrowley/go-metrics
+  version: 1f30fe9094a513ce4c700b9a54458bbb0c96996c
 - name: github.com/spf13/afero
   version: 9be650865eab0c12963d8753212f4f9c66cdcf12
   subpackages:
@@ -126,7 +128,6 @@ imports:
   - clist
   - common
   - db
-  - events
   - flowrate
   - log
   - merkle

glide.yaml

@@ -7,11 +7,10 @@ import:
 - package: github.com/golang/protobuf
   subpackages:
   - proto
-- package: github.com/pelletier/go-toml
-  version: ^1.0.0
 - package: github.com/gorilla/websocket
 - package: github.com/pkg/errors
   version: ~0.8.0
+- package: github.com/rcrowley/go-metrics
 - package: github.com/spf13/cobra
 - package: github.com/spf13/viper
 - package: github.com/tendermint/abci
@@ -26,21 +25,15 @@ import:
   version: ~0.6.2
   subpackages:
   - data
-- package: github.com/tendermint/merkleeyes
-  version: ~0.2.4
-  subpackages:
-  - app
-  - iavl
-  - testutil
 - package: github.com/tendermint/tmlibs
   version: ~0.2.2
   subpackages:
   - autofile
   - cli
+  - cli/flags
   - clist
   - common
   - db
-  - events
   - flowrate
   - log
   - merkle
@@ -53,7 +46,16 @@ import:
   subpackages:
   - context
 - package: google.golang.org/grpc
+- package: github.com/tendermint/merkleeyes
+  version: ~0.2.4
+  subpackages:
+  - app
+  - iavl
+  - testutil
 testImport:
+- package: github.com/go-kit/kit
+  subpackages:
+  - log/term
 - package: github.com/stretchr/testify
   subpackages:
   - assert

rpc/lib/client/ws_client.go

@@ -12,6 +12,8 @@ import (
 
 	"github.com/gorilla/websocket"
 	"github.com/pkg/errors"
+	metrics "github.com/rcrowley/go-metrics"
+
 	types "github.com/tendermint/tendermint/rpc/lib/types"
 	cmn "github.com/tendermint/tmlibs/common"
 )
@@ -39,6 +41,9 @@ type WSClient struct {
 	Endpoint string // /websocket/url/endpoint
 	Dialer   func(string, string) (net.Conn, error)
 
+	PingPongLatencyTimer metrics.Timer
+	sentLastPingAt       time.Time
+
 	// user facing channels, closed only when the client is being stopped.
 	ResultsCh chan json.RawMessage
 	ErrorsCh  chan error
@@ -49,16 +54,18 @@ type WSClient struct {
 	reconnectAfter     chan error            // reconnect requests
 	receiveRoutineQuit chan struct{}         // a way for receiveRoutine to close writeRoutine
 
-	wg sync.WaitGroup
+	wg  sync.WaitGroup
+	mtx sync.RWMutex
 }
 
 // NewWSClient returns a new client.
 func NewWSClient(remoteAddr, endpoint string) *WSClient {
 	addr, dialer := makeHTTPDialer(remoteAddr)
 	wsClient := &WSClient{
-		Address:  addr,
-		Dialer:   dialer,
-		Endpoint: endpoint,
+		Address:              addr,
+		Dialer:               dialer,
+		Endpoint:             endpoint,
+		PingPongLatencyTimer: metrics.NewTimer(),
 	}
 	wsClient.BaseService = *cmn.NewBaseService(nil, "WSClient", wsClient)
 	return wsClient
@@ -263,6 +270,9 @@ func (c *WSClient) writeRoutine() {
 				c.reconnectAfter <- err
 				return
 			}
+			c.mtx.Lock()
+			c.sentLastPingAt = time.Now()
+			c.mtx.Unlock()
 			c.Logger.Debug("sent ping")
 		case <-c.receiveRoutineQuit:
 			return
@@ -284,6 +294,9 @@ func (c *WSClient) receiveRoutine() {
 	c.conn.SetReadDeadline(time.Now().Add(pongWait))
 	c.conn.SetPongHandler(func(string) error {
 		c.conn.SetReadDeadline(time.Now().Add(pongWait))
+		c.mtx.RLock()
+		c.PingPongLatencyTimer.UpdateSince(c.sentLastPingAt)
+		c.mtx.RUnlock()
 		c.Logger.Debug("got pong")
 		return nil
 	})

rpc/lib/rpc_test.go

@@ -276,9 +276,9 @@ func TestServersAndClientsBasic(t *testing.T) {
 		testWithHTTPClient(t, cl2)
 
 		cl3 := client.NewWSClient(addr, websocketEndpoint)
+    cl3.SetLogger(log.TestingLogger())
 		_, err := cl3.Start()
 		require.Nil(t, err)
-		cl3.SetLogger(log.TestingLogger())
 		fmt.Printf("=== testing server on %s using %v client", addr, cl3)
 		testWithWSClient(t, cl3)
 		cl3.Stop()
@@ -305,9 +305,9 @@ func TestQuotedStringArg(t *testing.T) {
 
 func TestWSNewWSRPCFunc(t *testing.T) {
 	cl := client.NewWSClient(tcpAddr, websocketEndpoint)
+  cl.SetLogger(log.TestingLogger())
 	_, err := cl.Start()
 	require.Nil(t, err)
-	cl.SetLogger(log.TestingLogger())
 	defer cl.Stop()
 
 	val := "acbd"
@@ -331,9 +331,9 @@ func TestWSNewWSRPCFunc(t *testing.T) {
 
 func TestWSHandlesArrayParams(t *testing.T) {
 	cl := client.NewWSClient(tcpAddr, websocketEndpoint)
+  cl.SetLogger(log.TestingLogger())
 	_, err := cl.Start()
 	require.Nil(t, err)
-	cl.SetLogger(log.TestingLogger())
 	defer cl.Stop()
 
 	val := "acbd"
@@ -361,9 +361,9 @@ func TestWSClientPingPong(t *testing.T) {
 	}
 
 	cl := client.NewWSClient(tcpAddr, websocketEndpoint)
+  cl.SetLogger(log.TestingLogger())
 	_, err := cl.Start()
 	require.Nil(t, err)
-	cl.SetLogger(log.TestingLogger())
 	defer cl.Stop()
 
 	time.Sleep(35 * time.Second)