rpc: fix deadlock when unref is inside conn->lock

In ping-timer implementation, the timer event takes a ref on the rpc
object. This ref needs to be removed after every timeout event.
ping-timer mechanism could be holding the last ref. For e.g, when a peer
is detached and its rpc object was unref'd. In this case, ping-timer
mechanism would try to acquire conn->mutex to perform the 'last' unref
while being inside the critical section already. This will result in a
deadlock.

Change-Id: I74f80dd08c9348bd320a1c6d12fc8cd544fa4aea
BUG: 1206134
Signed-off-by: Krishnan Parthasarathi <kparthas@redhat.com>
Reviewed-on: http://review.gluster.org/9613
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Vijay Bellur <vbellur@redhat.com>

1 files changed, 91 insertions, 70 deletions

diff --git a/rpc/rpc-lib/src/rpc-clnt-ping.c b/rpc/rpc-lib/src/rpc-clnt-ping.c
index b263f68868e..0b32990e31e 100644
--- a/rpc/rpc-lib/src/rpc-clnt-ping.c
+++ b/rpc/rpc-lib/src/rpc-clnt-ping.c
@@ -35,6 +35,67 @@ struct rpc_clnt_program clnt_ping_prog = {
         .procnames = clnt_ping_procs,
 };
 
+/* Must be called under conn->lock */
+static int
+__rpc_clnt_rearm_ping_timer (struct rpc_clnt *rpc, gf_timer_cbk_t cbk)
+{
+        rpc_clnt_connection_t *conn    = &rpc->conn;
+        rpc_transport_t       *trans   = conn->trans;
+        struct timespec        timeout = {0, };
+        gf_timer_t            *timer   = NULL;
+
+        if (conn->ping_timer) {
+                gf_log_callingfn ("", GF_LOG_CRITICAL,
+                                  "%s: ping timer event already scheduled",
+                                  conn->trans->peerinfo.identifier);
+                return -1;
+        }
+
+        timeout.tv_sec = conn->ping_timeout;
+        timeout.tv_nsec = 0;
+
+        rpc_clnt_ref (rpc);
+        timer = gf_timer_call_after (rpc->ctx, timeout,
+                                     cbk,
+                                     (void *) rpc);
+        if (timer == NULL) {
+                gf_log (trans->name, GF_LOG_WARNING,
+                        "unable to setup ping timer");
+
+                /* This unref can't be the last. We just took a ref few lines
+                 * above. So this can be performed under conn->lock. */
+                rpc_clnt_unref (rpc);
+                conn->ping_started = 0;
+                return -1;
+        }
+
+        conn->ping_timer = timer;
+        conn->ping_started = 1;
+        return 0;
+}
+
+/* Must be called under conn->lock */
+static int
+__rpc_clnt_remove_ping_timer (struct rpc_clnt *rpc)
+{
+        rpc_clnt_connection_t *conn  = &rpc->conn;
+        gf_timer_t            *timer = NULL;
+
+        if (conn->ping_timer) {
+                timer = conn->ping_timer;
+                conn->ping_timer = NULL;
+                gf_timer_call_cancel (rpc->ctx, timer);
+                conn->ping_started = 0;
+                return 1;
+
+        }
+        gf_log_callingfn ("", GF_LOG_DEBUG, "%s: ping timer event "
+                          "already removed",
+                           conn->trans->peerinfo.identifier);
+
+        return 0;
+}
+
 static void
 rpc_clnt_start_ping (void *rpc_ptr);
 
@@ -46,8 +107,8 @@ rpc_clnt_ping_timer_expired (void *rpc_ptr)
         rpc_clnt_connection_t   *conn               = NULL;
         int                      disconnect         = 0;
         int                      transport_activity = 0;
-        struct timespec          timeout            = {0, };
         struct timeval           current            = {0, };
+        int                      unref              = 0;
 
         rpc = (struct rpc_clnt*) rpc_ptr;
         conn = &rpc->conn;
@@ -61,12 +122,7 @@ rpc_clnt_ping_timer_expired (void *rpc_ptr)
 
         pthread_mutex_lock (&conn->lock);
         {
-                if (conn->ping_timer) {
-                        gf_timer_call_cancel (rpc->ctx,
-                                              conn->ping_timer);
-                        conn->ping_timer = NULL;
-                        rpc_clnt_unref (rpc);
-                }
+                unref = __rpc_clnt_remove_ping_timer (rpc);
 
                 gettimeofday (&current, NULL);
                 if (((current.tv_sec - conn->last_received.tv_sec) <
@@ -80,20 +136,13 @@ rpc_clnt_ping_timer_expired (void *rpc_ptr)
                         gf_log (trans->name, GF_LOG_TRACE,
                                 "ping timer expired but transport activity "
                                 "detected - not bailing transport");
-                        timeout.tv_sec = conn->ping_timeout;
-                        timeout.tv_nsec = 0;
-
-                        rpc_clnt_ref (rpc);
-                        conn->ping_timer =
-                                gf_timer_call_after (rpc->ctx, timeout,
-                                                     rpc_clnt_ping_timer_expired,
-                                                     (void *) rpc);
-                        if (conn->ping_timer == NULL) {
+
+                        if (__rpc_clnt_rearm_ping_timer (rpc,
+                                         rpc_clnt_ping_timer_expired) == -1) {
                                 gf_log (trans->name, GF_LOG_WARNING,
                                         "unable to setup ping timer");
-                                conn->ping_started = 0;
-                                rpc_clnt_unref (rpc);
                         }
+
                 } else {
                         conn->ping_started = 0;
                         disconnect = 1;
@@ -101,6 +150,9 @@ rpc_clnt_ping_timer_expired (void *rpc_ptr)
         }
         pthread_mutex_unlock (&conn->lock);
 
+        if (unref)
+                rpc_clnt_unref (rpc);
+
         if (disconnect) {
                 gf_log (trans->name, GF_LOG_CRITICAL,
                         "server %s has not responded in the last %d "
@@ -124,6 +176,7 @@ rpc_clnt_ping_cbk (struct rpc_req *req, struct iovec *iov, int count,
         rpc_clnt_connection_t *conn    = NULL;
         call_frame_t          *frame   = NULL;
         struct timespec       timeout  = {0, };
+        int                   unref    = 0;
 
         if (!myframe) {
                 gf_log (THIS->name, GF_LOG_WARNING,
@@ -140,13 +193,10 @@ rpc_clnt_ping_cbk (struct rpc_req *req, struct iovec *iov, int count,
         pthread_mutex_lock (&conn->lock);
         {
                 if (req->rpc_status == -1) {
-                        if (conn->ping_timer != NULL) {
+                        unref = __rpc_clnt_remove_ping_timer (rpc);
+                        if (unref) {
                                 gf_log (this->name, GF_LOG_WARNING,
                                         "socket or ib related error");
-                                gf_timer_call_cancel (rpc->ctx,
-                                                      conn->ping_timer);
-                                conn->ping_timer = NULL;
-                                rpc_clnt_unref (rpc);
 
                         } else {
                                 /* timer expired and transport bailed out */
@@ -158,42 +208,20 @@ rpc_clnt_ping_cbk (struct rpc_req *req, struct iovec *iov, int count,
                         goto unlock;
                 }
 
-                /* We need to unref rpc_clnt after every call cancel. This is
-                 * because we take a ref every time a ping timer event is
-                 * scheduled.  But we are accounting for this by doing away
-                 * with the ref we should have taken otherwise. This possible
-                 * since ref and unref have the following property.
-                 *
-                 * rpc_clnt_unref (rpc); rpc_clnt_ref (rpc);
-                 * is the same as,
-                 * (;)
-                 * where, rpc->refcnt > 0.
-                 *
-                 * Here rpc->refcnt > 0, since the ping_timer is not NULL,
-                 * which implies the ping timer event hasn't executed, and
-                 * therefore the ref taken when it was scheduled is still
-                 * present.  */
-
-                gf_timer_call_cancel (this->ctx,
-                                      conn->ping_timer);
-
-                timeout.tv_sec = conn->ping_timeout;
-                timeout.tv_nsec = 0;
-                conn->ping_timer = gf_timer_call_after (this->ctx, timeout,
-                                                        rpc_clnt_start_ping,
-                                                        (void *)rpc);
-
-                if (conn->ping_timer == NULL) {
+                unref = __rpc_clnt_remove_ping_timer (rpc);
+                if (__rpc_clnt_rearm_ping_timer (rpc,
+                                                 rpc_clnt_start_ping) == -1) {
                         gf_log (this->name, GF_LOG_WARNING,
                                 "failed to set the ping timer");
-                        conn->ping_started = 0;
-                        rpc_clnt_unref (rpc);
                 }
 
         }
 unlock:
         pthread_mutex_unlock (&conn->lock);
 out:
+        if (unref)
+                rpc_clnt_unref (rpc);
+
         if (frame)
                 STACK_DESTROY (frame->root);
         return 0;
@@ -246,6 +274,7 @@ rpc_clnt_start_ping (void *rpc_ptr)
         rpc_clnt_connection_t   *conn        = NULL;
         struct timespec          timeout     = {0, };
         int                      frame_count = 0;
+        int                      unref       = 0;
 
         rpc = (struct rpc_clnt*) rpc_ptr;
         conn = &rpc->conn;
@@ -258,12 +287,7 @@ rpc_clnt_start_ping (void *rpc_ptr)
 
         pthread_mutex_lock (&conn->lock);
         {
-                if (conn->ping_timer) {
-                        gf_timer_call_cancel (rpc->ctx, conn->ping_timer);
-                        conn->ping_timer = NULL;
-                        conn->ping_started = 0;
-                        rpc_clnt_unref (rpc);
-                }
+                unref = __rpc_clnt_remove_ping_timer (rpc);
 
                 if (conn->saved_frames) {
                         GF_ASSERT (conn->saved_frames->count >= 0);
@@ -279,29 +303,26 @@ rpc_clnt_start_ping (void *rpc_ptr)
                                 !conn->connected, frame_count);
 
                         pthread_mutex_unlock (&conn->lock);
+                        if (unref)
+                                rpc_clnt_unref (rpc);
                         return;
                 }
 
-                timeout.tv_sec = conn->ping_timeout;
-                timeout.tv_nsec = 0;
-
-                rpc_clnt_ref (rpc);
-                conn->ping_timer =
-                        gf_timer_call_after (rpc->ctx, timeout,
-                                             rpc_clnt_ping_timer_expired,
-                                             (void *) rpc);
-
-                if (conn->ping_timer == NULL) {
+                if (__rpc_clnt_rearm_ping_timer (rpc,
+                                         rpc_clnt_ping_timer_expired) == -1) {
                         gf_log (THIS->name, GF_LOG_WARNING,
                                 "unable to setup ping timer");
-                        rpc_clnt_unref (rpc);
                         pthread_mutex_unlock (&conn->lock);
+                        if (unref)
+                                rpc_clnt_unref (rpc);
                         return;
-                } else {
-                        conn->ping_started = 1;
+
                 }
+
         }
         pthread_mutex_unlock (&conn->lock);
+        if (unref)
+                rpc_clnt_unref (rpc);
 
         rpc_clnt_ping(rpc);
 }