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

    • Triage:
      Untriaged
    • Operating System:
      Centos 64-bit
    • Story Points:
      1
    • Is this a Regression?:
      No
    • Sprint:
      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

            Hide
            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.

            Show
            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.
            Hide
            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 '{}'

            Show
            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 '{}'
            Hide
            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.

            Show
            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.
            Hide
            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

            Show
            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
            Hide
            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 '{}'

            Show
            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

              Assignee:
              ashwin.govindarajulu Ashwin Govindarajulu
              Reporter:
              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