Uploaded image for project: 'Couchbase Go SDK'
  1. Couchbase Go SDK
  2. GOCBC-832

DCP showing unacked_bytes

    XMLWordPrintable

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • None
    • 2.1.0
    • None
    • 1

    Description

      gocbcore SHA used for build: c6e079e95daae3c480d0ba3644c28eeef6a43fef

      * c6e079e Charles Dixon | GOCBC-807: Change BestEffortRetry to Exponential Backoff
      * 61e6302 James Lee | GOCBC-815: Honor the 'DisableDecompression' option in 'AgentConfig'
      * d3c5896 Charles Dixon | GOCBC-812: Add missing properties to KeyValueError
      * 12c8dc0 Charles Dixon | GOCBC-813: Remove cancel time func/lock from memdrequest
      * b5b8897 Charles Dixon | GOCBC-814: Update search to look for hits not results in payload
      * b61b18e Charles Dixon | GOCBC-662: Reorder subdoc opts if xattrs are present
      ...

      DCP connections made via gocbcore are showing a large number of unacked bytes ..

      • Here's cbstats for an index that streamed from _default scope, _default collection ..

      [11:15:01] AD: ~/Documents/couchbase/ns_server $ ../install/bin/cbstats localhost:12000 -u Administrator -p asdasd -b travel-sample dcp | grep acked_bytes
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_6ddbfb54-571d29af:total_acked_bytes:                         4194693
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_6ddbfb54-571d29af:unacked_bytes:                             2148919
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_13aa53f3-7be001a:total_acked_bytes:                          4195413
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_13aa53f3-7be001a:unacked_bytes:                              2201528
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_18572d87-3e45bec0:total_acked_bytes:                         4204050
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_18572d87-3e45bec0:unacked_bytes:                             2299584
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_54820232-640db58e:total_acked_bytes:                         4195128
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_54820232-640db58e:unacked_bytes:                             2187371
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_aa574717-5827c537:total_acked_bytes:                         4194938
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_aa574717-5827c537:unacked_bytes:                             2201847
       eq_dcpq:fts:travel_6f0c1ee73e8ea454_f4e0a48a-7f8c7a44:total_acked_bytes:                         4194699

      • Here's stats for an index that streamed from a non-default collection within a non-default scope ..

      [11:15:13] AD: ~/Documents/couchbase/ns_server $ ../install/bin/cbstats localhost:12000 -u Administrator -p asdasd -b default dcp | grep acked_bytes
       eq_dcpq:fts:default_1533b6bddfa26825_6ddbfb54-6162c043:total_acked_bytes:                         0
       eq_dcpq:fts:default_1533b6bddfa26825_6ddbfb54-6162c043:unacked_bytes:                             376695
       eq_dcpq:fts:default_1533b6bddfa26825_13aa53f3-4802b2b:total_acked_bytes:                          0
       eq_dcpq:fts:default_1533b6bddfa26825_13aa53f3-4802b2b:unacked_bytes:                              379860
       eq_dcpq:fts:default_1533b6bddfa26825_18572d87-5b99c09:total_acked_bytes:                          0
       eq_dcpq:fts:default_1533b6bddfa26825_18572d87-5b99c09:unacked_bytes:                              379459
       eq_dcpq:fts:default_1533b6bddfa26825_54820232-3f9eb03b:total_acked_bytes:                         0
       eq_dcpq:fts:default_1533b6bddfa26825_54820232-3f9eb03b:unacked_bytes:                             381036
       eq_dcpq:fts:default_1533b6bddfa26825_aa574717-780ba3d5:total_acked_bytes:                         0
       eq_dcpq:fts:default_1533b6bddfa26825_aa574717-780ba3d5:unacked_bytes:                             377886
       eq_dcpq:fts:default_1533b6bddfa26825_f4e0a48a-481b2061:total_acked_bytes:                         0
       eq_dcpq:fts:default_1533b6bddfa26825_f4e0a48a-481b2061:unacked_bytes:                             375898 

      Note that the index still receives all the documents, and there're no pending backfills on KV side - as we were looking at this being related to: MB-38121.

      Also, the fix from GOCBC-774 is already included in the builds.

      I've attached a cbcollect_info from the node if you think it'd be useful.

      Attachments

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

        Activity

          brett19 Brett Lawson added a comment -

          I believe this is a result of our internal DCP ack system not being aware of some of the new collections-specific DCP messages (system event, et.al.). Abhi Dangeti can you confirm that this occured on a cluster with developer preview enabled (or on a Cheshire Cat build)?

          brett19 Brett Lawson added a comment - I believe this is a result of our internal DCP ack system not being aware of some of the new collections-specific DCP messages (system event, et.al.). Abhi Dangeti can you confirm that this occured on a cluster with developer preview enabled (or on a Cheshire Cat build)?
          abhinav Abhi Dangeti added a comment -

          Hey Brett Lawson, this was with cluster_run on the couchbase repo with the latest code. 

          abhinav Abhi Dangeti added a comment - Hey Brett Lawson , this was with cluster_run on the couchbase repo with the latest code. 

          Hi Abhi Dangeti  is this still an issue? I've just tested against a slightly old build of cheshire cat using a non-default scope and collection and I see that the acked_bytes looks as expected:

          [vagrant@node1-cheshire-cat-testing-centos7 bin]$ ./cbstats localhost:11210 -u Administrator -p password -b beer-sample dcp | grep acked_bytes
          eq_dcpq:simple-stream:total_acked_bytes: 37755108
          eq_dcpq:simple-stream:unacked_bytes: 611774

          charles.dixon Charles Dixon added a comment - Hi Abhi Dangeti   is this still an issue? I've just tested against a slightly old build of cheshire cat using a non-default scope and collection and I see that the acked_bytes looks as expected: [vagrant@node1-cheshire-cat-testing-centos7 bin] $ ./cbstats localhost:11210 -u Administrator -p password -b beer-sample dcp | grep acked_bytes eq_dcpq:simple-stream:total_acked_bytes: 37755108 eq_dcpq:simple-stream:unacked_bytes: 611774
          abhinav Abhi Dangeti added a comment -

          Hey Charles Dixon , acked_bytes looks fine, what about unacked_bytes above?

          abhinav Abhi Dangeti added a comment - Hey Charles Dixon  , acked_bytes looks fine, what about unacked_bytes above?

          The unacked_bytes is equal to the number of bytes that are still within the gocbcore ack "buffer". In this function https://github.com/couchbase/gocbcore/blob/ac4efa47c224acc20dcbb708b001981b36bdebc5/memdclient.go#L79-L100 you can see that we only ack once we have received enough data (https://github.com/couchbase/gocbcore/blob/master/agent.go#L184). I checked with the debugger and the number of unacked_bytes seen above == `client.dcpFlowRecv` as it's waiting for more data to be received.

          charles.dixon Charles Dixon added a comment - The unacked_bytes is equal to the number of bytes that are still within the gocbcore ack "buffer". In this function https://github.com/couchbase/gocbcore/blob/ac4efa47c224acc20dcbb708b001981b36bdebc5/memdclient.go#L79-L100 you can see that we only ack once we have received enough data ( https://github.com/couchbase/gocbcore/blob/master/agent.go#L184 ). I checked with the debugger and the number of unacked_bytes seen above == `client.dcpFlowRecv` as it's waiting for more data to be received.
          abhinav Abhi Dangeti added a comment -

          I see, I raised this ticket when I saw these unacked_bytes after all the expected data was streamed into the index.

          abhinav Abhi Dangeti added a comment - I see, I raised this ticket when I saw these unacked_bytes after all the expected data was streamed into the index.

          I think that once all data has been streamed then there being outstanding unacked_bytes is probably ok as it won't cause the server to stop sending data/send the backfill error. Please do correct me if I'm wrong though or if you think differently.

          charles.dixon Charles Dixon added a comment - I think that once all data has been streamed then there being outstanding unacked_bytes is probably ok as it won't cause the server to stop sending data/send the backfill error. Please do correct me if I'm wrong though or if you think differently.

          Yea, I mean this isn't causing any trouble between the DCP producer/consumer. The stat just threw me off that maybe the SDK wasn't ACKing everything it was receiving.

          abhinav Abhi Dangeti added a comment - Yea, I mean this isn't causing any trouble between the DCP producer/consumer. The stat just threw me off that maybe the SDK wasn't ACKing everything it was receiving.

          People

            charles.dixon Charles Dixon
            abhinav Abhi Dangeti
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty