1 files changed, 76 insertions, 11 deletions

diff --git a/rpc/rpc-lib/src/rpc-clnt-ping.c b/rpc/rpc-lib/src/rpc-clnt-ping.c
index a7ff866ac99..7ce066dec5f 100644
--- a/rpc/rpc-lib/src/rpc-clnt-ping.c
+++ b/rpc/rpc-lib/src/rpc-clnt-ping.c
@@ -18,6 +18,7 @@
 #include "mem-pool.h"
 #include "xdr-rpc.h"
 #include "rpc-common-xdr.h"
+#include "timespec.h"
 
 
 char *clnt_ping_procs[GF_DUMP_MAXVALUE] = {
@@ -30,6 +31,11 @@ struct rpc_clnt_program clnt_ping_prog = {
         .procnames = clnt_ping_procs,
 };
 
+struct ping_local {
+    struct rpc_clnt *rpc;
+    struct timespec submit_time;
+};
+
 /* Must be called under conn->lock */
 static int
 __rpc_clnt_rearm_ping_timer (struct rpc_clnt *rpc, gf_timer_cbk_t cbk)
@@ -166,16 +172,48 @@ out:
         return;
 }
 
+void
+_update_client_latency (const rpc_clnt_connection_t *conn,
+                        call_frame_t *frame,
+                        uint64_t elapsed_usec)
+{
+        fop_latency_t *lat;
+
+        lat = &frame->this->client_latency;
+
+        if (elapsed_usec < lat->min) {
+                lat->min = elapsed_usec;
+        }
+
+        if (elapsed_usec > lat->max) {
+                lat->max = elapsed_usec;
+        }
+
+        lat->total += elapsed_usec;
+        lat->count++;
+        lat->mean = lat->mean + (elapsed_usec - lat->mean) / lat->count;
+        gf_log (THIS->name, GF_LOG_DEBUG, "%s - Ping latency is %0.6lf ms, "
+                "avg: %0.6lf ms, count:%ld",
+                conn->trans->peerinfo.identifier, elapsed_usec / 1000.0,
+                lat->mean / 1000.0, lat->count);
+}
+
 int
 rpc_clnt_ping_cbk (struct rpc_req *req, struct iovec *iov, int count,
                    void *myframe)
 {
-        struct rpc_clnt       *rpc     = NULL;
+        struct ping_local     *local   = NULL;
         xlator_t              *this    = NULL;
         rpc_clnt_connection_t *conn    = NULL;
+
         call_frame_t          *frame   = NULL;
         struct timespec       timeout  = {0, };
+        struct timespec       now;
+        struct timespec       delta;
+        int64_t               latency_usec = 0;
+        int                   ret = 0;
         int                   unref    = 0;
+        gf_boolean_t          call_notify = _gf_false;
 
         if (!myframe) {
                 gf_log (THIS->name, GF_LOG_WARNING,
@@ -185,14 +223,13 @@ rpc_clnt_ping_cbk (struct rpc_req *req, struct iovec *iov, int count,
 
         frame = myframe;
         this = frame->this;
-        rpc  = frame->local;
-        frame->local = NULL; /* Prevent STACK_DESTROY from segfaulting */
-        conn = &rpc->conn;
+        local = frame->local;
+        conn = &local->rpc->conn;
 
         pthread_mutex_lock (&conn->lock);
         {
                 if (req->rpc_status == -1) {
-                        unref = rpc_clnt_remove_ping_timer_locked (rpc);
+                        unref = rpc_clnt_remove_ping_timer_locked (local->rpc);
                         if (unref) {
                                 gf_log (this->name, GF_LOG_WARNING,
                                         "socket or ib related error");
@@ -207,8 +244,15 @@ rpc_clnt_ping_cbk (struct rpc_req *req, struct iovec *iov, int count,
                         goto unlock;
                 }
 
-                unref = rpc_clnt_remove_ping_timer_locked (rpc);
-                if (__rpc_clnt_rearm_ping_timer (rpc,
+                timespec_now (&now);
+                timespec_sub (&local->submit_time, &now, &delta);
+                latency_usec = delta.tv_sec * 1000000UL +
+                               delta.tv_nsec / 1000UL;
+
+                _update_client_latency (conn, frame, latency_usec);
+                call_notify = _gf_true;
+                unref = rpc_clnt_remove_ping_timer_locked (local->rpc);
+                if (__rpc_clnt_rearm_ping_timer (local->rpc,
                                                  rpc_clnt_start_ping) == -1) {
                         gf_log (this->name, GF_LOG_WARNING,
                                 "failed to set the ping timer");
@@ -217,12 +261,24 @@ rpc_clnt_ping_cbk (struct rpc_req *req, struct iovec *iov, int count,
         }
 unlock:
         pthread_mutex_unlock (&conn->lock);
+
+        if (call_notify) {
+                ret = local->rpc->notifyfn (local->rpc, this,
+                                            RPC_CLNT_PING, NULL);
+                if (ret) {
+                        gf_log (this->name, GF_LOG_WARNING,
+                                "RPC_CLNT_PING notify failed");
+                }
+        }
 out:
         if (unref)
-                rpc_clnt_unref (rpc);
+                rpc_clnt_unref (local->rpc);
 
-        if (frame)
+        if (frame) {
+                GF_FREE (frame->local);
+                frame->local = NULL;
                 STACK_DESTROY (frame->root);
+        }
         return 0;
 }
 
@@ -232,18 +288,27 @@ rpc_clnt_ping (struct rpc_clnt *rpc)
         call_frame_t *frame = NULL;
         int32_t       ret   = -1;
         rpc_clnt_connection_t *conn = NULL;
+        struct ping_local *local = NULL;
 
         conn = &rpc->conn;
+        local = GF_MALLOC (sizeof(struct ping_local), gf_common_ping_local_t);
+        if (!local)
+                return ret;
         frame = create_frame (THIS, THIS->ctx->pool);
-        if (!frame)
+        if (!frame) {
+                GF_FREE (local);
                 return ret;
+        }
 
-        frame->local = rpc;
+        local->rpc = rpc;
+        timespec_now (&local->submit_time);
+        frame->local = local;
 
         ret = rpc_clnt_submit (rpc, &clnt_ping_prog,
                                GF_DUMP_PING, rpc_clnt_ping_cbk, NULL, 0,
                                NULL, 0, NULL, frame, NULL, 0, NULL, 0, NULL);
         if (ret) {
+                /* FIXME: should we free the frame here? Methinks so! */
                 gf_log (THIS->name, GF_LOG_ERROR,
                         "failed to start ping timer");
         }