ZOOKEEPER-2253: C asserts ordering of ping requests, while Java client does not

(Chris Chen via rgs)

git-svn-id: https://svn.apache.org/repos/asf/zookeeper/trunk@1705482 13f79535-47bb-0310-9956-ffa450edef68

CHANGES.txt

@@ -176,6 +176,9 @@ BUGFIXES:
   ZOOKEEPER-1803: Add description for pzxid in programmer's guide
   (Arshad Mohammad via rakeshr)
 
+  ZOOKEEPER-2253: C asserts ordering of ping requests, while Java client does not
+  (Chris Chen via rgs)
+
 IMPROVEMENTS:
   ZOOKEEPER-1660 Documentation for Dynamic Reconfiguration (Reed Wanderman-Milne via shralex)  
 

src/c/src/zookeeper.c

@@ -1617,25 +1617,20 @@ void free_completions(zhandle_t *zh,int callCompletion,int reason)
             zh->outstanding_sync--;
             destroy_completion_entry(cptr);
         } else if (callCompletion) {
-            if(cptr->xid == PING_XID){
-                // Nothing to do with a ping response
-                destroy_completion_entry(cptr);
-            } else {
-                // Fake the response
-                buffer_list_t *bptr;
-                h.xid = cptr->xid;
-                h.zxid = -1;
-                h.err = reason;
-                oa = create_buffer_oarchive();
-                serialize_ReplyHeader(oa, "header", &h);
-                bptr = calloc(sizeof(*bptr), 1);
-                assert(bptr);
-                bptr->len = get_buffer_len(oa);
-                bptr->buffer = get_buffer(oa);
-                close_buffer_oarchive(&oa, 0);
-                cptr->buffer = bptr;
-                queue_completion(&zh->completions_to_process, cptr, 0);
-            }
+            // Fake the response
+            buffer_list_t *bptr;
+            h.xid = cptr->xid;
+            h.zxid = -1;
+            h.err = reason;
+            oa = create_buffer_oarchive();
+            serialize_ReplyHeader(oa, "header", &h);
+            bptr = calloc(sizeof(*bptr), 1);
+            assert(bptr);
+            bptr->len = get_buffer_len(oa);
+            bptr->buffer = get_buffer(oa);
+            close_buffer_oarchive(&oa, 0);
+            cptr->buffer = bptr;
+            queue_completion(&zh->completions_to_process, cptr, 0);
         }
     }
     a_list.completion = NULL;
@@ -2007,7 +2002,6 @@ static struct timeval get_timeval(int interval)
     rc = serialize_RequestHeader(oa, "header", &h);
     enter_critical(zh);
     get_system_time(&zh->last_ping);
-    rc = rc < 0 ? rc : add_void_completion(zh, h.xid, 0, 0);
     rc = rc < 0 ? rc : queue_buffer_bytes(&zh->to_send, get_buffer(oa),
             get_buffer_len(oa));
     leave_critical(zh);
@@ -2745,12 +2739,8 @@ static void deserialize_response(zhandle_t *zh, int type, int xid, int failed, i
     case COMPLETION_VOID:
         LOG_DEBUG(LOGCALLBACK(zh), "Calling COMPLETION_VOID for xid=%#x failed=%d rc=%d",
                     cptr->xid, failed, rc);
-        if (xid == PING_XID) {
-            // We want to skip the ping
-        } else {
-            assert(cptr->c.void_result);
-            cptr->c.void_result(rc, cptr->data);
-        }
+        assert(cptr->c.void_result);
+        cptr->c.void_result(rc, cptr->data);
         break;
     case COMPLETION_MULTI:
         LOG_DEBUG(LOGCALLBACK(zh), "Calling COMPLETION_MULTI for xid=%#x failed=%d rc=%d",
@@ -2861,7 +2851,15 @@ int zookeeper_process(zhandle_t *zh, int events)
                                     bptr->buffer, bptr->curr_offset);
         deserialize_ReplyHeader(ia, "hdr", &hdr);
 
-        if (hdr.xid == WATCHER_EVENT_XID) {
+        if (hdr.xid == PING_XID) {
+            // Ping replies can arrive out-of-order
+            int elapsed = 0;
+            struct timeval now;
+            gettimeofday(&now, 0);
+            elapsed = calculate_interval(&zh->last_ping, &now);
+            LOG_DEBUG(LOGCALLBACK(zh), "Got ping response in %d ms", elapsed);
+            free_buffer(bptr);
+        } else if (hdr.xid == WATCHER_EVENT_XID) {
             struct WatcherEvent evt;
             int type = 0;
             char *path = NULL;
@@ -2925,7 +2923,7 @@ int zookeeper_process(zhandle_t *zh, int events)
                         hdr.xid,cptr->xid);
             }
 
-            if (hdr.xid != PING_XID && hdr.zxid > 0) {
+            if (hdr.zxid > 0) {
                 // Update last_zxid only when it is a request response
                 zh->last_zxid = hdr.zxid;
             }
@@ -2933,22 +2931,9 @@ int zookeeper_process(zhandle_t *zh, int events)
             deactivateWatcher(zh, cptr->watcher_deregistration, rc);
 
             if (cptr->c.void_result != SYNCHRONOUS_MARKER) {
-                if(hdr.xid == PING_XID){
-                    int elapsed = 0;
-                    struct timeval now;
-                    get_system_time(&now);
-                    elapsed = calculate_interval(&zh->last_ping, &now);
-                    LOG_DEBUG(LOGCALLBACK(zh), "Got ping response in %d ms", elapsed);
-
-                    // Nothing to do with a ping response
-                    free_buffer(bptr);
-                    destroy_completion_entry(cptr);
-                } else {
-                    LOG_DEBUG(LOGCALLBACK(zh), "Queueing asynchronous response");
-
-                    cptr->buffer = bptr;
-                    queue_completion(&zh->completions_to_process, cptr, 0);
-                }
+                LOG_DEBUG(LOGCALLBACK(zh), "Queueing asynchronous response");
+                cptr->buffer = bptr;
+                queue_completion(&zh->completions_to_process, cptr, 0);
             } else {
                 struct sync_completion
                         *sc = (struct sync_completion*)cptr->data;

src/c/tests/TestOperations.cc

@@ -29,6 +29,7 @@ class Zookeeper_operations : public CPPUNIT_NS::TestFixture
     CPPUNIT_TEST_SUITE(Zookeeper_operations);
 #ifndef THREADED
     CPPUNIT_TEST(testPing);
+    CPPUNIT_TEST(testUnsolicitedPing);
     CPPUNIT_TEST(testTimeoutCausedByWatches1);
     CPPUNIT_TEST(testTimeoutCausedByWatches2);
 #else    
@@ -305,6 +306,40 @@ public:
         CPPUNIT_ASSERT_EQUAL(1,zkServer.pingCount_);
     }
 
+    // ZOOKEEPER-2253: Permit unsolicited pings
+    void testUnsolicitedPing()
+    {
+        const int TIMEOUT=9; // timeout in secs
+        Mock_gettimeofday timeMock;
+        PingCountingServer zkServer;
+        // must call zookeeper_close() while all the mocks are in scope
+        CloseFinally guard(&zh);
+
+        // receive timeout is in milliseconds
+        zh=zookeeper_init("localhost:1234",watcher,TIMEOUT*1000,TEST_CLIENT_ID,0,0);
+        CPPUNIT_ASSERT(zh!=0);
+        // simulate connected state
+        forceConnected(zh);
+
+        int fd=0;
+        int interest=0;
+        timeval tv;
+
+        int rc=zookeeper_interest(zh,&fd,&interest,&tv);
+        CPPUNIT_ASSERT_EQUAL((int)ZOK,rc);
+
+        // verify no ping sent
+        CPPUNIT_ASSERT(zkServer.pingCount_==0);
+
+        // we're going to receive a unsolicited PING response; ensure
+        // that the client has updated its last_recv timestamp
+        timeMock.tick(tv);
+        zkServer.addRecvResponse(new PingResponse);
+        rc=zookeeper_process(zh,interest);
+        CPPUNIT_ASSERT_EQUAL((int)ZOK,rc);
+        CPPUNIT_ASSERT(timeMock==zh->last_recv);
+    }
+
     // simulate a watch arriving right before a ping is due
     // assert the ping is sent nevertheless
     void testTimeoutCausedByWatches1()