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

lcb_respexists_is_found returns true for documents which have been removed

    XMLWordPrintable

Details

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

    Description

      If you upsert a doc, and then remove it at some point later, you will get LCB_ERR_DOCUMENT_NOT_FOUND. But, if you see if it exists after that, the lcb_respexists_is_found actually still returns true. Looking at the exists.cc, things look reasonable. Perhaps a document that has been removed recently still exists (marked as deleted) and we end up with LCB_SUCCESS in the rc for those?

      This is really on latest master (though I marked it as 3.0.0, it is later than that)

      Attachments

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

        Activity

          david.kelly David Kelly added a comment -

          This does happen on 6.5 and earlier (5.5.6 for instance).  If the key was never in the server, things are correct.  But if it was we fail.  My test upserts, makes sure it is there with a get, then removes and makes sure a get returns a LCB_ERR_DOCUMENT_NOT_FOUND, then tries exists and it gets true from lcb_respexists_is_found.

          david.kelly David Kelly added a comment - This does happen on 6.5 and earlier (5.5.6 for instance).  If the key was never in the server, things are correct.  But if it was we fail.  My test upserts, makes sure it is there with a get, then removes and makes sure a get returns a LCB_ERR_DOCUMENT_NOT_FOUND, then tries exists and it gets true from lcb_respexists_is_found.
          david.kelly David Kelly added a comment -

          As a side note, we are seeing intermittent segfaults with exists as well.  The problem appears to be in the tracing that happens at the end of the lcb_wait call.  If I call exists in a loop I can reproduce easily.  A typical stack trace:

          * thread #2, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x1)
              frame #0: 0x000000010388eba7 libcouchbase.2.dylib`::lcbtrace_span_add_tag_uint64(lcbtrace_SPAN *, const char *, uint64_t) [inlined] sllist_append(list=0x0000000101c28988, item=0x0000000101c29270) at sllist-inl.h:148:26
              frame #1: 0x000000010388eb9e libcouchbase.2.dylib`::lcbtrace_span_add_tag_uint64(lcbtrace_SPAN *, const char *, uint64_t) [inlined] lcb::trace::Span::add_tag(this=0x0000000101c28940, name="couchbase.context_info", copy=1, value=4324494992) at span.cc:409
            * frame #2: 0x000000010388eb6e libcouchbase.2.dylib`::lcbtrace_span_add_tag_uint64(span=0x0000000101c28940, name="couchbase.context_info", value=4324494992) at span.cc:99
              frame #3: 0x0000000101f10da4 _libcouchbase.cpython-37m-darwin.so`pycbc_propagate_context_info(span=0x0000000101c001a0, dest=0x0000000101c28940) at ext.c:2581:5 [opt]
              frame #4: 0x0000000101f110e3 _libcouchbase.cpython-37m-darwin.so`pycbc_span_report(tracer=<unavailable>, span=0x0000000101c001a0) at ext.c:2761:5 [opt]
              frame #5: 0x000000010388e826 libcouchbase.2.dylib`::lcbtrace_span_finish(lcbtrace_SPAN *, uint64_t) [inlined] lcb::trace::Span::finish(this=0x0000000101c001a0, now=<unavailable>) at span.cc:366:9
              frame #6: 0x000000010388e801 libcouchbase.2.dylib`::lcbtrace_span_finish(span=0x0000000101c001a0, now=<unavailable>) at span.cc:71
              frame #7: 0x00000001038482be libcouchbase.2.dylib`::mcreq_dispatch_response(mc_PIPELINE *, mc_PACKET *, lcb::MemcachedResponse *, lcb_STATUS) at handler.cc:481:5
              frame #8: 0x0000000103848118 libcouchbase.2.dylib`::mcreq_dispatch_response(pipeline=0x0000000101e24490, req=<unavailable>, res=0x00007ffeefbfe120, immerr=LCB_SUCCESS) at handler.cc:1201
              frame #9: 0x000000010387faf9 libcouchbase.2.dylib`lcb::Server::try_read(this=0x0000000101e24490, ctx=<unavailable>, ior=0x0000000101e25be8) at mcserver.cc:0
              frame #10: 0x00000001038812ae libcouchbase.2.dylib`on_read(ctx=0x0000000101e25ba0, (null)=<unavailable>) at mcserver.cc:579:26
              frame #11: 0x0000000103819d09 libcouchbase.2.dylib`E_handler [inlined] invoke_read_cb(ctx=<unavailable>, nb=47) at ctx.c:255:5
              frame #12: 0x0000000103819cee libcouchbase.2.dylib`E_handler(sock=<unavailable>, which=2, arg=0x0000000101e25ba0) at ctx.c:282
              frame #13: 0x0000000103803132 libcouchbase.2.dylib`run_loop(io=0x0000000101c1ce00, is_tick=0) at plugin-select.c:309:17
              frame #14: 0x000000010388e6dd libcouchbase.2.dylib`::lcb_wait(instance=0x0000000101c27840, flags=<unavailable>) at wait.cc:109:5
              frame #15: 0x0000000101f1b172 _libcouchbase.cpython-37m-darwin.so`pycbc_common_vars_wait [inlined] pycbc_oputil_wait_common(self=<unavailable>, context=<unavailable>) at oputil.c:702:5 [opt]
              frame #16: 0x0000000101f1b132 _libcouchbase.cpython-37m-darwin.so`pycbc_common_vars_wait(cv=0x00007ffeefbfe6b0, self=0x000000010545ed70, context=<unavailable>) at oputil.c:205 [opt]
              frame #17: 0x0000000101f145cb _libcouchbase.cpython-37m-darwin.so`get_common(self=0x000000010545ed70, args=<unavailable>, kwargs=0x00000001054

          It appears that the list somehow has gotten corrupted.  Not sure how/why.  

          However this isn't the real topic of this bug report – it is the fact that the lcb_respexists_is_found returns true when the document has been recently deleted.  This happens hitting 5.5.6 and 6.5 (didn't try others).  I doubt it it related to the segfault above, so maybe worth a second bug report just for it. 

          david.kelly David Kelly added a comment - As a side note, we are seeing intermittent segfaults with exists as well.  The problem appears to be in the tracing that happens at the end of the lcb_wait call.  If I call exists in a loop I can reproduce easily.  A typical stack trace: * thread #2, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x1) frame #0: 0x000000010388eba7 libcouchbase.2.dylib`::lcbtrace_span_add_tag_uint64(lcbtrace_SPAN *, const char *, uint64_t) [inlined] sllist_append(list=0x0000000101c28988, item=0x0000000101c29270) at sllist-inl.h:148:26 frame #1: 0x000000010388eb9e libcouchbase.2.dylib`::lcbtrace_span_add_tag_uint64(lcbtrace_SPAN *, const char *, uint64_t) [inlined] lcb::trace::Span::add_tag(this=0x0000000101c28940, name="couchbase.context_info", copy=1, value=4324494992) at span.cc:409 * frame #2: 0x000000010388eb6e libcouchbase.2.dylib`::lcbtrace_span_add_tag_uint64(span=0x0000000101c28940, name="couchbase.context_info", value=4324494992) at span.cc:99 frame #3: 0x0000000101f10da4 _libcouchbase.cpython-37m-darwin.so`pycbc_propagate_context_info(span=0x0000000101c001a0, dest=0x0000000101c28940) at ext.c:2581:5 [opt] frame #4: 0x0000000101f110e3 _libcouchbase.cpython-37m-darwin.so`pycbc_span_report(tracer=<unavailable>, span=0x0000000101c001a0) at ext.c:2761:5 [opt] frame #5: 0x000000010388e826 libcouchbase.2.dylib`::lcbtrace_span_finish(lcbtrace_SPAN *, uint64_t) [inlined] lcb::trace::Span::finish(this=0x0000000101c001a0, now=<unavailable>) at span.cc:366:9 frame #6: 0x000000010388e801 libcouchbase.2.dylib`::lcbtrace_span_finish(span=0x0000000101c001a0, now=<unavailable>) at span.cc:71 frame #7: 0x00000001038482be libcouchbase.2.dylib`::mcreq_dispatch_response(mc_PIPELINE *, mc_PACKET *, lcb::MemcachedResponse *, lcb_STATUS) at handler.cc:481:5 frame #8: 0x0000000103848118 libcouchbase.2.dylib`::mcreq_dispatch_response(pipeline=0x0000000101e24490, req=<unavailable>, res=0x00007ffeefbfe120, immerr=LCB_SUCCESS) at handler.cc:1201 frame #9: 0x000000010387faf9 libcouchbase.2.dylib`lcb::Server::try_read(this=0x0000000101e24490, ctx=<unavailable>, ior=0x0000000101e25be8) at mcserver.cc:0 frame #10: 0x00000001038812ae libcouchbase.2.dylib`on_read(ctx=0x0000000101e25ba0, (null)=<unavailable>) at mcserver.cc:579:26 frame #11: 0x0000000103819d09 libcouchbase.2.dylib`E_handler [inlined] invoke_read_cb(ctx=<unavailable>, nb=47) at ctx.c:255:5 frame #12: 0x0000000103819cee libcouchbase.2.dylib`E_handler(sock=<unavailable>, which=2, arg=0x0000000101e25ba0) at ctx.c:282 frame #13: 0x0000000103803132 libcouchbase.2.dylib`run_loop(io=0x0000000101c1ce00, is_tick=0) at plugin-select.c:309:17 frame #14: 0x000000010388e6dd libcouchbase.2.dylib`::lcb_wait(instance=0x0000000101c27840, flags=<unavailable>) at wait.cc:109:5 frame #15: 0x0000000101f1b172 _libcouchbase.cpython-37m-darwin.so`pycbc_common_vars_wait [inlined] pycbc_oputil_wait_common(self=<unavailable>, context=<unavailable>) at oputil.c:702:5 [opt] frame #16: 0x0000000101f1b132 _libcouchbase.cpython-37m-darwin.so`pycbc_common_vars_wait(cv=0x00007ffeefbfe6b0, self=0x000000010545ed70, context=<unavailable>) at oputil.c:205 [opt] frame #17: 0x0000000101f145cb _libcouchbase.cpython-37m-darwin.so`get_common(self=0x000000010545ed70, args=<unavailable>, kwargs=0x00000001054 It appears that the list somehow has gotten corrupted.  Not sure how/why.   However this isn't the real topic of this bug report – it is the fact that the lcb_respexists_is_found returns true when the document has been recently deleted.  This happens hitting 5.5.6 and 6.5 (didn't try others).  I doubt it it related to the segfault above, so maybe worth a second bug report just for it. 
          david.kelly David Kelly added a comment - - edited

          The segfault mentioned above is CCBC-1215 - and there is a changelist for it.  This ticket is just for is_found returning true for deleted docs.

          Since we know whether or not the document has been deleted, we can either let is_found continue to return true for this case and add a new api for is_deleted, or just change the logic to return false if the doc has been deleted.

           

          To me, the latter is more logical, so I'll do that, and we can discuss...

          david.kelly David Kelly added a comment - - edited The segfault mentioned above is CCBC-1215 - and there is a changelist for it.  This ticket is just for is_found returning true for deleted docs. Since we know whether or not the document has been deleted, we can either let is_found continue to return true for this case and add a new api for is_deleted, or just change the logic to return false if the doc has been deleted.   To me, the latter is more logical, so I'll do that, and we can discuss...
          david.kelly David Kelly added a comment -

          CCBC-1215 and CCBC-1218 both merged.  Will enable tests, that should do it.

          david.kelly David Kelly added a comment - CCBC-1215 and CCBC-1218 both merged.  Will enable tests, that should do it.
          david.kelly David Kelly added a comment -

          forgot to close this.  

          david.kelly David Kelly added a comment - forgot to close this.  

          Build couchbase-server-7.0.0-3115 contains libcouchbase commit 207d15d with commit message:
          CCBC-1187: lcb_respexists_is_found returns true for deleted documents.

          build-team Couchbase Build Team added a comment - Build couchbase-server-7.0.0-3115 contains libcouchbase commit 207d15d with commit message: CCBC-1187 : lcb_respexists_is_found returns true for deleted documents.

          People

            david.kelly David Kelly
            david.kelly David Kelly
            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