Uploaded image for project: 'Couchbase C client library libcouchbase'
  1. Couchbase C client library libcouchbase
  2. CCBC-1634

lcb_ping emits duplicate when the pipeline is reconnecting

    XMLWordPrintable

Details

    • Bug
    • Resolution: Fixed
    • Major
    • 3.3.12
    • None
    • None
    • None
    • 1
    • SDK08: SDK3.5, 0xD, FtrNA, PS

    Description

      Start three node cluster, run `cbc-ping --table`, kill one node.

      Expected result: dead node will report timeout
      Actual result: in place of dead node the duplicate OK reported with higher latency

      132999ms [Ic269da0816a80544] {61132/103} [TRACE] (confmon - L:329) Refreshing current cluster map (bucket: "default"), next update in 0us
      132999ms [Ic269da0816a80544] {61132/103} [TRACE] (cccp - L:264) Re-Issuing CCCP Command on server struct 0x616000000c80 (192.168.107.129:11210)
      132999ms [Ic269da0816a80544] {61132/103} [TRACE] (getconfig - L:81) Attempting to retrieve cluster map via CCCP (timeout=2500000us, ext=0, epoch=1, revision=119)
      ----------------------------------------------------------------------------------------------
      | type | id             | status | latency, us | remote                | local               |
      ----------------------------------------------------------------------------------------------
      | kv   | 0x6080000003a0 | ok     |        1339 | 192.168.107.129:11210 | 192.168.107.1:51582 |
      | kv   | 0x608000000ca0 | ok     |        1248 | 192.168.107.128:11210 | 192.168.107.1:51583 |
      | kv   | 0x608000000e20 | ok     |        1296 | 192.168.107.130:11210 | 192.168.107.1:51584 |
      ----------------------------------------------------------------------------------------------
       
      133006ms [Ic269da0816a80544] {61132/103} [TRACE] (confmon - L:158) Not applying configuration received via CCCP (bucket="default", source=CCCP, address="192.168.107.129"). No changes detected. A.rev=1:119, B.rev=1:119. Changes: servers=no, map=no, replicas=no
      134012ms [Ic269da0816a80544] {61132/103} [WARN] (server - L:1245) <192.168.107.130:11210> (CTX=0x610000001840,memcached,SRV=0x616000000f80,IX=2) Got socket error LCB_ERR_SOCKET_SHUTDOWN (1025)
      134012ms [Ic269da0816a80544] {61132/103} [DEBUG] (retryq - L:428) Adding PKT=0x60c00001b1c0 to retry queue. retries=1, cid=0 (unset), opaque=445, now=86534012ms, spent=1404us, deadline_in=+2498595us, status=0xff, rc=LCB_ERR_SOCKET_SHUTDOWN (1025)
      134013ms [Ic269da0816a80544] {61132/103} [TRACE] (retryq - L:208) Next tick in 9 ms
      134013ms [Ic269da0816a80544] {61132/103} [TRACE] (confmon - L:329) Refreshing current cluster map (bucket: "default"), next update in 0us
      134013ms [Ic269da0816a80544] {61132/103} [TRACE] (cccp - L:264) Re-Issuing CCCP Command on server struct 0x616000000f80 (192.168.107.130:11210)
      134013ms [Ic269da0816a80544] {61132/103} [TRACE] (getconfig - L:81) Attempting to retrieve cluster map via CCCP (timeout=2500000us, ext=0, epoch=1, revision=119)
      134013ms [Ic269da0816a80544] {61132/103} [DEBUG] (server - L:1341) <192.168.107.130:11210> (CTX=0x610000001840,memcached,SRV=0x616000000f80,IX=2) Finalizing context
      134013ms [Ic269da0816a80544] {61132/103} [DEBUG] (ioctx - L:140) <192.168.107.130:11210> (CTX=0x610000001840,memcached) Destroying context for SOCK=adaa07b11a36f1d8. Pending Writes=0, Entered=false, Socket Refcount=1
      134014ms [Ic269da0816a80544] {61132/103} [DEBUG] (lcbio_mgr - L:501) <192.168.107.130:11210> (HE=0x60c000003dc0) Creating new connection because none are available in the pool
      134014ms [Ic269da0816a80544] {61132/103} [TRACE] (lcbio_mgr - L:413) <192.168.107.130:11210> (HE=0x60c000003dc0) New pool entry: I=0x60800000f920
      134014ms [Ic269da0816a80544] {61132/103} [INFO] (connection - L:500) <192.168.107.130:11210> (SOCK=bd63074e83c9e0de) Starting. Timeout=2500000us
      134015ms [Ic269da0816a80544] {61132/103} [DEBUG] (connection - L:265) <192.168.107.130:11210> (SOCK=bd63074e83c9e0de) Created new socket with FD=6
      134015ms [Ic269da0816a80544] {61132/103} [TRACE] (connection - L:365) <192.168.107.130:11210> (SOCK=bd63074e83c9e0de) Scheduling I/O watcher for asynchronous connection completion.
      134024ms [Ic269da0816a80544] {61132/103} [TRACE] (retryq - L:278) Flush PKT=0x60c00001b1c0 to network. retries=1, cid=0 (unset), opaque=445, IX=0, spent=13279us, deadline_in=2486720us
      ----------------------------------------------------------------------------------------------
      | type | id             | status | latency, us | remote                | local               |
      ----------------------------------------------------------------------------------------------
      | kv   | 0x6080000003a0 | ok     |        4097 | 192.168.107.129:11210 | 192.168.107.1:51582 |
      | kv   | 0x608000000ca0 | ok     |        4045 | 192.168.107.128:11210 | 192.168.107.1:51583 |
      | kv   | 0x608000000ca0 | ok     |       13824 | 192.168.107.128:11210 | 192.168.107.1:51583 |
      ----------------------------------------------------------------------------------------------
      

      Attachments

        No reviews matched the request. Check your Options in the drop-down menu of this sections header.

        Activity

          People

            avsej Sergey Avseyev
            avsej Sergey Avseyev
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty