Uploaded image for project: 'Couchbase Server'
  1. Couchbase Server
  2. MB-40126

Subdoc CreateAsDeleted without any value path can result in non-empty value

    XMLWordPrintable

Details

    • Untriaged
    • Centos 64-bit
    • 1
    • No
    • KV Sprint 2020-June

    Description

      Build: 6.6.0-7834

      Test case:

      ./testrunner -i node.ini threads_to_use=8,rerun=False,skip_cleanup=True,get-cbcollect-info=False,skip_collections_cleanup=True -t Atomicity.doc_isolation.IsolationDocTest.test_staged_doc_read,nodes_init=2,num_items=1,replicas=1,transaction_timeout=30,transaction_commit=True,doc_op=create,operation=beforeAtrPending,GROUP=P0

      Cbcollect logs:
      https://cb-jira.s3.us-east-2.amazonaws.com/logs/transaction_crash/collectinfo-2020-06-24T195940-ns_1%4010.112.191.105.zip
      https://cb-jira.s3.us-east-2.amazonaws.com/logs/transaction_crash/collectinfo-2020-06-24T195940-ns_1%4010.112.191.106.zip
      Scenario:

      • Two node cluster, Couchbase bucket with replica=1
      • Start transaction with expiry of 30 seconds. Forcefully fail the transaction during "beforeAtrPending" and retry

      Expected behavior:

      Failed transaction should succeed without any issues

      Service 'memcached' exited with status 134. Restarting. Messages:
      2020-06-24T12:53:01.819552-07:00 CRITICAL /opt/couchbase/bin/../lib/libstdc++.so.6() [0x7f0c401a8000+0x8f213]
      2020-06-24T12:53:01.819559-07:00 CRITICAL /opt/couchbase/bin/../lib/../lib/ep.so() [0x7f0c3aca6000+0xcccd0]
      2020-06-24T12:53:01.819564-07:00 CRITICAL /opt/couchbase/bin/../lib/../lib/ep.so() [0x7f0c3aca6000+0xc811a]
      2020-06-24T12:53:01.819570-07:00 CRITICAL /opt/couchbase/bin/../lib/../lib/ep.so() [0x7f0c3aca6000+0xca523]
      2020-06-24T12:53:01.819576-07:00 CRITICAL /opt/couchbase/bin/../lib/../lib/ep.so() [0x7f0c3aca6000+0x18f490]
      2020-06-24T12:53:01.819581-07:00 CRITICAL /opt/couchbase/bin/../lib/../lib/ep.so() [0x7f0c3aca6000+0xcfa4d]
      2020-06-24T12:53:01.819586-07:00 CRITICAL /opt/couchbase/bin/../lib/../lib/ep.so() [0x7f0c3aca6000+0x12b764]
      2020-06-24T12:53:01.819590-07:00 CRITICAL /opt/couchbase/bin/../lib/libplatform_so.so.0.1.0() [0x7f0c42257000+0x8f17]
      2020-06-24T12:53:01.819594-07:00 CRITICAL /lib64/libpthread.so.0() [0x7f0c3fa73000+0x7df3]
      2020-06-24T12:53:01.819621-07:00 CRITICAL /lib64/libc.so.6(clone+0x6d) [0x7f0c3f6b2000+0xf61ad]

      Attaching test.log and  trans_expired_with_d_ambiguous.pcapng for further debugging.

      Attachments

        1. _7845_client-op.png
          _7845_client-op.png
          390 kB
        2. _7845_invalid-prepare.png
          _7845_invalid-prepare.png
          381 kB
        3. _dcp-prepare-png.png
          _dcp-prepare-png.png
          346 kB
        4. _no non-subdoc fronend op.png
          _no non-subdoc fronend op.png
          33 kB
        5. _subdoc ops only against 105.png
          _subdoc ops only against 105.png
          212 kB
        6. 6.6.0-7845_client_run_1.pcapng
          1.74 MB
        7. 6.6.0-7845_node_run_1.pcap
          4.17 MB
        8. test.log
          33 kB
        9. test.pcap
          20.11 MB
        10. trans_expired_with_d_ambiguous_new.pcapng
          2.06 MB
        11. trans_expired_with_d_ambiguous.pcapng
          2.09 MB

        Issue Links

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

          Activity

            drigby Dave Rigby added a comment - - edited

            Updated Wireshark to correctly decode XATTRs within a DCP_PREPARE opcode. That gives the following decode of the DCP_PREPARE which was rejected by the DCP Consumer :

            Couchbase Protocol, DCP Prepare Request, Opcode: 0x60, VBucket: 0x3cb
                Magic: Request (0x80)
                Opcode: DCP Prepare (0x60)
                Key Length: 16
                Extras Length: 31
                Data Type: 0x05, JSON, XATTR
                VBucket: 971 (0x03cb)
                [Value Length: 161]
                Total Body Length: 208
                Opaque: 0x000001ce
                CAS: 0x161bc2fe46ec0000
                Extras
                Key: _txn:atr-971-#4b
                XATTR Length: 155
                XATTRs
                    XATTR Pair Length: 151
                        Key: attempts
                        Value: {"82534e38-fb98-475f-a831-a6b9f62d52f1":{"tid":"3135008a-ff17-43fc-a9a8-70ac2363983a","st":"PENDING","tst":"0x0000ec46fec21b16","exp":30000}}
                Value: {}
            

            I suspect the problem here is the "empty but not empty" value - i.e. the value "{}" represents an empty JSON document, but the value from a mcbp pov is not empty.

            drigby Dave Rigby added a comment - - edited Updated Wireshark to correctly decode XATTRs within a DCP_PREPARE opcode. That gives the following decode of the DCP_PREPARE which was rejected by the DCP Consumer : Couchbase Protocol, DCP Prepare Request, Opcode: 0x60, VBucket: 0x3cb Magic: Request (0x80) Opcode: DCP Prepare (0x60) Key Length: 16 Extras Length: 31 Data Type: 0x05, JSON, XATTR VBucket: 971 (0x03cb) [Value Length: 161] Total Body Length: 208 Opaque: 0x000001ce CAS: 0x161bc2fe46ec0000 Extras Key: _txn:atr-971-#4b XATTR Length: 155 XATTRs XATTR Pair Length: 151 Key: attempts Value: {"82534e38-fb98-475f-a831-a6b9f62d52f1":{"tid":"3135008a-ff17-43fc-a9a8-70ac2363983a","st":"PENDING","tst":"0x0000ec46fec21b16","exp":30000}} Value: {} I suspect the problem here is the "empty but not empty" value - i.e. the value "{}" represents an empty JSON document, but the value from a mcbp pov is not empty.

            Build couchbase-server-6.6.0-7856 contains kv_engine commit c55541f with commit message:
            MB-40126: subdoc CreateAsDeleted: User value shouldn't be '{}'

            build-team Couchbase Build Team added a comment - Build couchbase-server-6.6.0-7856 contains kv_engine commit c55541f with commit message: MB-40126 : subdoc CreateAsDeleted: User value shouldn't be '{}'

            We used to hit this error before on 7846 but we are not hitting this anymore on 7856 using our FIT performer for transaction testing.

            praneeth.bokka Praneeth Bokka added a comment - We used to hit this error before on 7846 but we are not hitting this anymore on 7856 using our FIT performer for transaction testing.

            We are not hitting this issue anymore for TAF tests as well:

            09:11:10.197 1/MainThread/7f825/f7f08 overall commit completed

            09:11:10.197 1/MainThread/7f825/f7f08 added attempt TransactionAttempt{id=f7f08,state=COMPLETED,atrColl=com.couchbase.client.java.ReactiveCollection@47fb595c/_txn:atr-971-#4b} after success

            09:11:10.197 1/MainThread/7f825/f7f08 Adding cleanup request for _default/_txn:atr-971-#4b to run in 30000 msecs

            09:11:10.197 1/MainThread/7f825 finished txn in 134ms

            2020-07-02 09:11:10,436 | test  | INFO    | MainThread | [basetestcase:check_coredump_exist:543] Initializing core dump check on all the nodes

            2020-07-02 09:11:29,283 | test  | INFO    | MainThread | [rest_client:monitorRebalance:1423] Rebalance done. Taken 10.1079998016 seconds to complete

            2020-07-02 09:11:29,285 | test  | INFO    | MainThread | [rest_client:monitorRebalance:1425] Sleep for 5 seconds after rebalance

            ok

             

            ----------------------------------------------------------------------

            Ran 1 test in 197.275s

             

            OK

            During the test, Remote Connections: 27, Disconnections: 27

            SDK Connections: 2, Disconnections: 2

            summary so far suite Atomicity.doc_isolation.IsolationDocTest , pass 1 , fail 0

            testrunner logs, diags and results are available under /Users/praneethbokka/Frameworks/services/TAF/logs/testrunner-20-Jul-02_09-08-54/test_1

             

            Deprecated Gradle features were used in this build, making it incompatible with Gradle 7.0.

            Use '--warning-mode all' to show the individual deprecation warnings.

            See https://docs.gradle.org/6.0/userguide/command_line_interface.html#sec:command_line_warnings

             

             

            However we are running into other issue:

            https://issues.couchbase.com/browse/MB-40262

            praneeth.bokka Praneeth Bokka added a comment - We are not hitting this issue anymore for TAF tests as well: 09:11:10.197 1/MainThread/7f825/f7f08 overall commit completed 09:11:10.197 1/MainThread/7f825/f7f08 added attempt TransactionAttempt{id=f7f08,state=COMPLETED,atrColl=com.couchbase.client.java.ReactiveCollection@47fb595c/_txn:atr-971-#4b} after success 09:11:10.197 1/MainThread/7f825/f7f08 Adding cleanup request for _default/_txn:atr-971-#4b to run in 30000 msecs 09:11:10.197 1/MainThread/7f825 finished txn in 134ms 2020-07-02 09:11:10,436 | test  | INFO    | MainThread | [basetestcase:check_coredump_exist:543] Initializing core dump check on all the nodes 2020-07-02 09:11:29,283 | test  | INFO    | MainThread | [rest_client:monitorRebalance:1423] Rebalance done. Taken 10.1079998016 seconds to complete 2020-07-02 09:11:29,285 | test  | INFO    | MainThread | [rest_client:monitorRebalance:1425] Sleep for 5 seconds after rebalance ok   ---------------------------------------------------------------------- Ran 1 test in 197.275s   OK During the test, Remote Connections: 27, Disconnections: 27 SDK Connections: 2, Disconnections: 2 summary so far suite Atomicity.doc_isolation.IsolationDocTest , pass 1 , fail 0 testrunner logs, diags and results are available under /Users/praneethbokka/Frameworks/services/TAF/logs/testrunner-20-Jul-02_09-08-54/test_1   Deprecated Gradle features were used in this build, making it incompatible with Gradle 7.0. Use '--warning-mode all' to show the individual deprecation warnings. See https://docs.gradle.org/6.0/userguide/command_line_interface.html#sec:command_line_warnings     However we are running into other issue: https://issues.couchbase.com/browse/MB-40262

            Build couchbase-server-7.0.0-2526 contains kv_engine commit c55541f with commit message:
            MB-40126: subdoc CreateAsDeleted: User value shouldn't be '{}'

            build-team Couchbase Build Team added a comment - Build couchbase-server-7.0.0-2526 contains kv_engine commit c55541f with commit message: MB-40126 : subdoc CreateAsDeleted: User value shouldn't be '{}'

            People

              ashwin.govindarajulu Ashwin Govindarajulu
              ashwin.govindarajulu Ashwin Govindarajulu
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty