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

DurabilityImpossible exception after Rebalance complete

    XMLWordPrintable

Details

    • Untriaged
    • 1
    • Yes

    Description

      On build 7.1.0-2241.

      Steps: Durability level is Majority
      1. 4 node cluster and replica as 0
      2. perform load – passed
      3. update replica as 1 and rebalance 4 node cluster
      4. perform load – passed
      5. update replica as 2 and rebalance
      6. now load fails with durabilityimpossiblexception

      even after rebalance complete, we see KV_NOT_MY_VBUCKET error in logs 

      2022-02-15 20:28:20,000 | test  | INFO    | pool-3-thread-15 | [task:transaction_load:5612] [20:14:34.979 60/pool-3-thread-15/d9f38 library version: 1.1.8 config: atrs=1024, metadataCollection=Optional.empty, expiry=750000msecs durability=MAJORITY per-txn config= durability=Optional.empty, supported=Supported {extensions=[EXT_TRANSACTION_ID, EXT_DEFERRED_COMMIT, EXT_TIME_OPT_UNSTAGING, EXT_BINARY_METADATA, EXT_CUSTOM_METADATA_COLLECTION, EXT_QUERY, EXT_STORE_DURABILITY, BF_CBD_3838, BF_CBD_3787, BF_CBD_3705, BF_CBD_3794, EXT_REMOVE_COMPLETED, EXT_ALL_KV_COMBINATIONS, EXT_UNKNOWN_ATR_STATES, BF_CBD_3791], protocol=2.0}, 20:14:34.979 190/elastic-25/d9f38 starting attempt 0/d9f38886-5223-4b06-823e-41be8bd60d92/71fb709a-5369-4825-b6ee-9ab7140fe61f, 20:14:34.979 179/elastic-15/d9f38/71fb7 First mutated doc in txn is 'default._default._default.test_docs-95180' on vbucket 146, so using atr _txn:atr-146-#29f, 20:14:34.979 179/elastic-15/d9f38/71fb7 about to set ATR default:_default._default._txn:atr-146-#29f to Pending, 20:14:34.986 119/cb-io-kv-5-7/d9f38/71fb7 set ATR default:_default._default._txn:atr-146-#29f to Pending in 6978us, got CAS (start time) cas=1644984874988208128,seqno=645,vbucket=146, 20:14:34.986 119/cb-io-kv-5-7/d9f38/71fb7 about to insert staged doc default._default._default.test_docs-95180 as shadow document, cas=Optional.empty, 20:14:34.993 119/cb-io-kv-5-7/d9f38/71fb7 inserted doc default._default._default.test_docs-95180 got cas=1644984874996531200,seqno=647,vbucket=146, in 6644us, 20:14:34.993 179/elastic-15/d9f38/71fb7 getting doc default._default._default.test_docs-95180, resolvingMissingATREntry=<empty>, 20:14:34.993 179/elastic-15/d9f38/71fb7 found own-write of mutated doc default._default._default.test_docs-95180, 20:14:34.993 179/elastic-15/d9f38/71fb7 about to insert staged doc default._default._default.test_docs-95181 as shadow document, cas=Optional.empty, 20:14:34.996 117/cb-io-kv-5-6/d9f38/71fb7 inserted doc default._default._default.test_docs-95181 got cas=1644984875002232832,seqno=629,vbucket=917, in 3482us, 20:14:34.996 179/elastic-15/d9f38/71fb7 getting doc default._default._default.test_docs-95181, resolvingMissingATREntry=<empty>, 20:14:34.996 179/elastic-15/d9f38/71fb7 found own-write of mutated doc default._default._default.test_docs-95181, 20:14:34.996 179/elastic-15/d9f38/71fb7 about to insert staged doc default._default._default.test_docs-95182 as shadow document, cas=Optional.empty, 20:14:35.002 117/cb-io-kv-5-6/d9f38/71fb7 inserted doc default._default._default.test_docs-95182 got cas=1644984875008327680,seqno=605,vbucket=668, in 5155us, 20:14:35.002 179/elastic-15/d9f38/71fb7 getting doc default._default._default.test_docs-95182, resolvingMissingATREntry=<empty>, 20:14:35.002 179/elastic-15/d9f38/71fb7 found own-write of mutated doc default._default._default.test_docs-95182, 20:14:35.002 179/elastic-15/d9f38/71fb7 about to insert staged doc default._default._default.test_docs-95183 as shadow document, cas=Optional.empty, 20:14:35.010 117/cb-io-kv-5-6/d9f38/71fb7 inserted doc default._default._default.test_docs-95183 got cas=1644984875010949120,seqno=641,vbucket=411, in 8027us, 20:14:35.010 179/elastic-15/d9f38/71fb7 getting doc default._default._default.test_docs-95183, resolvingMissingATREntry=<empty>, 20:14:35.010 179/elastic-15/d9f38/71fb7 found own-write of mutated doc default._default._default.test_docs-95183, 20:14:35.010 179/elastic-15/d9f38/71fb7 about to insert staged doc default._default._default.test_docs-95184 as shadow document, cas=Optional.empty, 20:14:35.014 111/cb-io-kv-5-3/d9f38/71fb7 got err while staging insert of default._default._default.test_docs-95184: com.couchbase.client.core.error.DurabilityImpossibleException: With the current cluster configuration, the requested durability guarantees are impossible {"clientContext":{"txn.op":"createStagedInsert"},"completed":true,"coreId":"0xd821b83500000069","idempotent":false,"lastChannelId":"D821B83500000069/0000000015D7C74B","lastDispatchedFrom":"172.23.107.120:50658","lastDispatchedTo":"172.23.106.10:11210","requestId":416108,"requestType":"SubdocMutateRequest","retried":1,"retryReasons":["KV_NOT_MY_VBUCKET"],"service":{"bucket":"default","collection":"_default","documentId":"test_docs-95184","opaque":"0x7ce64","rejectedWithNotMyVbucket":1,"scope":"_default","syncDurability":"MAJORITY","type":"kv"},"status":"DURABILITY_IMPOSSIBLE","timeoutMs":10000,"timings":{"dispatchMicros":904,"encodingMicros":9,"totalDispatchMicros":1465,"totalServerMicros":0,"totalMicros":4320,"serverMicros":0}}, 20:14:35.015 179/elastic-15/d9f38/71fb7 caught exception 'TransactionOperationFailed {ec:FAIL_OTHER, cause:com.couchbase.client.core.error.DurabilityImpossibleException, retry:false, autoRollback:true, raise:TRANSACTION_FAILED}' in runBlocking, rethrowing, 20:14:35.015 179/elastic-15/d9f38/71fb7           com.couchbase.transactions.error.internal.TransactionOperationFailedBuilder.build(TransactionOperationFailedBuilder.java:73), 20:14:35.015 179/elastic-15/d9f38/71fb7           com.couchbase.transactions.AttemptContextReactive.lambda$null$102(AttemptContextReactive.java:1852), 20:14:35.015 179/elastic-15/d9f38/<> finishing attempt off after error 'TransactionOperationFailed {ec:FAIL_OTHER, cause:com.couchbase.client.core.error.DurabilityImpossibleException, retry:false, autoRollback:true, raise:TRANSACTION_FAILED}', 20:14:35.015 179/elastic-15/d9f38/71fb7 auto-rolling-back on error, 20:14:35.015 179/elastic-15/d9f38/71fb7 rollback AttemptContextReactive{id=71fb7,state=ROLLED_BACK,atr=default:_default._default._txn:atr-146-#29f,staged=[INSERT default._default._default.test_docs-95180, INSERT default._default._default.test_docs-95181, INSERT default._default._default.test_docs-95182, INSERT default._default._default.test_docs-95183]} expiryOvertimeMode=false isAppRollback=false, 20:14:35.016 179/elastic-15/d9f38/71fb7 aborting ATR default:_default._default._txn:atr-146-#29f isAppRollback=false ambiguityResolutionMode=false, 20:14:35.021 119/cb-io-kv-5-7/d9f38/71fb7 aborted ATR default:_default._default._txn:atr-146-#29f, 20:14:35.021 119/cb-io-kv-5-7/d9f38/71fb7 rolling back staged insert default._default._default.test_docs-95180 with cas 1644984874996531200, 20:14:35.025 119/cb-io-kv-5-7/d9f38/71fb7 deleted inserted doc default._default._default.test_docs-95180, mt Optional[mt{vbID=146, vbUUID=243435992428039, seqno=651, bucket=default}], 20:14:35.025 119/cb-io-kv-5-7/d9f38/71fb7 rolling back staged insert default._default._default.test_docs-95181 with cas 1644984875002232832, 20:14:35.028 117/cb-io-kv-5-6/d9f38/71fb7 deleted inserted doc default._default._default.test_docs-95181, mt Optional[mt{vbID=917, vbUUID=190364536484220, seqno=631, bucket=default}], 20:14:35.028 117/cb-io-kv-5-6/d9f38/71fb7 rolling back staged insert default._default._default.test_docs-95182 with cas 1644984875008327680, 20:14:35.036 117/cb-io-kv-5-6/d9f38/71fb7 deleted inserted doc default._default._default.test_docs-95182, mt Optional[mt{vbID=668, vbUUID=95739851680385, seqno=607, bucket=default}], 20:14:35.036 117/cb-io-kv-5-6/d9f38/71fb7 rolling back staged insert default._default._default.test_docs-95183 with cas 1644984875010949120, 20:14:35.043 117/cb-io-kv-5-6/d9f38/71fb7 deleted inserted doc default._default._default.test_docs-95183, mt Optional[mt{vbID=411, vbUUID=110224610653843, seqno=643, bucket=default}], 20:14:35.043 117/cb-io-kv-5-6/d9f38/71fb7 marking ATR default:_default._default._txn:atr-146-#29f as rollback complete, 20:14:35.047 119/cb-io-kv-5-7/d9f38/71fb7 rollback - atr rolled back in 4284us, 20:14:35.047 119/cb-io-kv-5-7/d9f38/71fb7 Skipping addition of cleanup request in state ROLLED_BACK, 20:14:35.047 119/cb-io-kv-5-7/d9f38/71fb7 added attempt TransactionAttempt{id=71fb7,state=ROLLED_BACK,atr=default:_default._default._txn:atr-146-#29f} after error, 20:14:35.048 119/cb-io-kv-5-7/d9f38/<> reraising original exception TransactionOperationFailed {ec:FAIL_OTHER, cause:com.couchbase.client.core.error.DurabilityImpossibleException, retry:false, autoRollback:true, raise:TRANSACTION_FAILED}, 20:14:35.048 119/cb-io-kv-5-7/d9f38 TransactionOperationFailed retryTransaction=false, 20:14:35.048 119/cb-io-kv-5-7/d9f38/71fb7 converted TransactionOperationFailed TRANSACTION_FAILED to final error com.couchbase.transactions.error.TransactionFailed: Transaction has failed with cause 'com.couchbase.client.core.error.DurabilityImpossibleException: With the current cluster configuration, the requested durability guarantees are impossible {"clientContext":{"txn.op":"createStagedInsert"},"completed":true,"coreId":"0xd821b83500000069","idempotent":false,"lastChannelId":"D821B83500000069/0000000015D7C74B","lastDispatchedFrom":"172.23.107.120:50658","lastDispatchedTo":"172.23.106.10:11210","requestId":416108,"requestType":"SubdocMutateRequest","retried":1,"retryReasons":["KV_NOT_MY_VBUCKET"],"service":{"bucket":"default","collection":"_default","documentId":"test_docs-95184","opaque":"0x7ce64","rejectedWithNotMyVbucket":1,"scope":"_default","syncDurability":"MAJORITY","type":"kv"},"status":"DURABILITY_IMPOSSIBLE","timeoutMs":10000,"timings":{"dispatchMicros":904,"encodingMicros":9,"totalDispatchMicros":1465,"totalServerMicros":0,"totalMicros":4320,"serverMicros":0}}']

      issue occurs, without transaction also. attached cbcollect logs.

      Test case:
      guides/gradlew --refresh-dependencies testrunner -P jython=/opt/jython/bin/jython -P transaction_version=1.1.8 -P client_version=default -P 'args=-i /tmp/win10-bucket-ops.ini -p num_items=25000,doc_size=512,transaction_timeout=750,atomicity=True,GROUP=P0,afterTimePeriod=250,defer=True,get-cbcollect-info=True,infra_log_level=critical,log_level=info,bucket_storage=couchstore,upgrade_version=7.1.0-2284 -t rebalance_new.rebalance_durability.RebalanceDurability.test_replica_update_with_durability_without_adding_removing_nodes,nodes_init=1,nodes_in=3,replicas=0,num_items=10000,GROUP=P0;DEFER;atomicity -m rest'

      also
      guides/gradlew --refresh-dependencies testrunner -P jython=/opt/jython/bin/jython -P transaction_version=1.1.8 -P client_version=default -P 'args=-i /tmp/win10-bucket-ops.ini -p num_items=100000,GROUP=P0,get-cbcollect-info=False,bucket_storage=couchstore,upgrade_version=7.1.0-2224 -t failover.concurrent_failovers.ConcurrentFailoverTests.test_concurrent_failover,nodes_init=9,services_init=kv-kv-kv-kv-index-index-index-n1ql-n1ql,replicas=1,maxCount=5,timeout=30,failover_order=kv:n1ql:n1ql,failover_method=stop_couchbase,bucket_spec=single_bucket.default -m rest'

      Attachments

        Issue Links

          duplicates

          Improvement - An improvement or enhancement to an existing feature or task. MB-34998 DurabilityImpossibleExceptions seen during rebalance.

          • Critical - Crashes, loss of data, severe memory leak.
          • Reopened
          No reviews matched the request. Check your Options in the drop-down menu of this sections header.

          Activity

            People

              dfinlay Dave Finlay
              anitha.kuberan Anitha Kuberan
              Votes:
              0 Vote for this issue
              Watchers:
              9 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty