Durability requirement failed: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime, Why? What leads to this reason?


#1

Duriablity: ReplicateTo.ONE,
mutation: insert
situation: one of four nodes down

47328 [cb-io-1-2] WARN com.couchbase.client.core.endpoint.Endpoint - [slave3.hadoop.com/192.168.103.134:8092][ViewEndpoint]: Could not connect to endpoint, retrying with delay 4096 MILLISECONDS: 
java.net.ConnectException: Connection refused: no further information: slave3.hadoop.com/192.168.103.134:8092
    at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
    at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
    at com.couchbase.client.deps.io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:208)
    at com.couchbase.client.deps.io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:281)
    at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:528)
    at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
    at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
    at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
    at com.couchbase.client.deps.io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    at com.couchbase.client.deps.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)
    at java.lang.Thread.run(Thread.java:619)
47344 [cb-computations-2] INFO com.couchbase.client.core.node.Node - Disconnected from Node slave3.hadoop.com
onerror===Durability requirement failed: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
java.lang.Exception: com.couchbase.client.java.error.DurabilityException: Durability requirement failed: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
    at com.test.TestCouchBase.insertData(TestCouchBase.java:859)
    at com.test.TestCouchBase.testCheckData(TestCouchBase.java:475)
    at com.test.TestCouchBase.processPriceData(TestCouchBase.java:1016)
    at com.test.TestCouchBase.main(TestCouchBase.java:222)
Caused by: com.couchbase.client.java.error.DurabilityException: Durability requirement failed: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
    at com.couchbase.client.java.CouchbaseAsyncBucket$13$1.call(CouchbaseAsyncBucket.java:469)
    at com.couchbase.client.java.CouchbaseAsyncBucket$13$1.call(CouchbaseAsyncBucket.java:465)
    at rx.internal.operators.OperatorOnErrorResumeNextViaFunction$1.onError(OperatorOnErrorResumeNextViaFunction.java:77)
    at rx.internal.operators.OperatorMap$1.onError(OperatorMap.java:49)
    at rx.internal.operators.OperatorMap$1.onError(OperatorMap.java:49)
    at rx.internal.operators.OperatorTake$1.onError(OperatorTake.java:57)
    at rx.internal.operators.OperatorSkipWhile$1.onError(OperatorSkipWhile.java:54)
    at rx.internal.operators.OnSubscribeRedo$3$1.onNext(OnSubscribeRedo.java:273)
    at rx.internal.operators.OnSubscribeRedo$3$1.onNext(OnSubscribeRedo.java:257)
    at rx.subjects.SubjectSubscriptionManager$SubjectObserver.onNext(SubjectSubscriptionManager.java:224)
    at rx.subjects.PublishSubject.onNext(PublishSubject.java:121)
    at rx.internal.operators.OnSubscribeRedo$2$1.onError(OnSubscribeRedo.java:223)
    at rx.internal.operators.OperatorToObservableList$1.onError(OperatorToObservableList.java:81)
    at rx.internal.operators.OperatorToObservableList$1.onCompleted(OperatorToObservableList.java:75)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.drainAndComplete(OperatorMerge.java:481)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.completeInner(OperatorMerge.java:458)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.emit(OperatorMerge.java:617)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.onCompleted(OperatorMerge.java:559)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.drainAndComplete(OperatorMerge.java:481)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.completeInner(OperatorMerge.java:458)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.emit(OperatorMerge.java:632)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.onCompleted(OperatorMerge.java:559)
    at rx.internal.operators.OperatorOnErrorResumeNextViaObservable$1.onCompleted(OperatorOnErrorResumeNextViaObservable.java:85)
    at rx.subjects.SubjectSubscriptionManager$SubjectObserver.onCompleted(SubjectSubscriptionManager.java:232)
    at rx.subjects.AsyncSubject.onCompleted(AsyncSubject.java:102)
    at com.couchbase.client.core.endpoint.AbstractGenericHandler$1.call(AbstractGenericHandler.java:199)
    at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:47)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
Caused by: com.couchbase.client.core.DocumentConcurrentlyModifiedException: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
    at com.couchbase.client.core.message.observe.Observe$2.call(Observe.java:257)
    at com.couchbase.client.core.message.observe.Observe$2.call(Observe.java:237)
    at rx.internal.operators.OperatorSkipWhile$2.call(OperatorSkipWhile.java:69)
    at rx.internal.operators.OperatorSkipWhile$2.call(OperatorSkipWhile.java:65)
    at rx.internal.operators.OperatorSkipWhile$1.onNext(OperatorSkipWhile.java:43)
    at rx.internal.operators.OnSubscribeRedo$2$1.onNext(OnSubscribeRedo.java:231)
    at rx.internal.operators.OperatorToObservableList$1.onCompleted(OperatorToObservableList.java:72)
    ... 21 more
java.lang.Exception: com.couchbase.client.java.error.DurabilityException: Durability requirement failed: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
    at com.test.TestCouchBase.insertData(TestCouchBase.java:859)
    at com.test.TestCouchBase.testCheckData(TestCouchBase.java:475)
    at com.test.TestCouchBase.processPriceData(TestCouchBase.java:1016)
    at com.test.TestCouchBase.main(TestCouchBase.java:222)
Caused by: com.couchbase.client.java.error.DurabilityException: Durability requirement failed: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
    at com.couchbase.client.java.CouchbaseAsyncBucket$13$1.call(CouchbaseAsyncBucket.java:469)
    at com.couchbase.client.java.CouchbaseAsyncBucket$13$1.call(CouchbaseAsyncBucket.java:465)
    at rx.internal.operators.OperatorOnErrorResumeNextViaFunction$1.onError(OperatorOnErrorResumeNextViaFunction.java:77)
    at rx.internal.operators.OperatorMap$1.onError(OperatorMap.java:49)
    at rx.internal.operators.OperatorMap$1.onError(OperatorMap.java:49)
    at rx.internal.operators.OperatorTake$1.onError(OperatorTake.java:57)
    at rx.internal.operators.OperatorSkipWhile$1.onError(OperatorSkipWhile.java:54)
    at rx.internal.operators.OnSubscribeRedo$3$1.onNext(OnSubscribeRedo.java:273)
    at rx.internal.operators.OnSubscribeRedo$3$1.onNext(OnSubscribeRedo.java:257)
    at rx.subjects.SubjectSubscriptionManager$SubjectObserver.onNext(SubjectSubscriptionManager.java:224)
    at rx.subjects.PublishSubject.onNext(PublishSubject.java:121)
    at rx.internal.operators.OnSubscribeRedo$2$1.onError(OnSubscribeRedo.java:223)
    at rx.internal.operators.OperatorToObservableList$1.onError(OperatorToObservableList.java:81)
    at rx.internal.operators.OperatorToObservableList$1.onCompleted(OperatorToObservableList.java:75)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.drainAndComplete(OperatorMerge.java:481)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.completeInner(OperatorMerge.java:458)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.emit(OperatorMerge.java:617)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.onCompleted(OperatorMerge.java:559)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.drainAndComplete(OperatorMerge.java:481)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.completeInner(OperatorMerge.java:458)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.emit(OperatorMerge.java:632)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.onCompleted(OperatorMerge.java:559)
    at rx.internal.operators.OperatorOnErrorResumeNextViaObservable$1.onCompleted(OperatorOnErrorResumeNextViaObservable.java:85)
    at rx.subjects.SubjectSubscriptionManager$SubjectObserver.onCompleted(SubjectSubscriptionManager.java:232)
    at rx.subjects.AsyncSubject.onCompleted(AsyncSubject.java:102)
    at com.couchbase.client.core.endpoint.AbstractGenericHandler$1.call(AbstractGenericHandler.java:199)
    at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:47)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
Caused by: com.couchbase.client.core.DocumentConcurrentlyModifiedException: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
    at com.couchbase.client.core.message.observe.Observe$2.call(Observe.java:257)
    at com.couchbase.client.core.message.observe.Observe$2.call(Observe.java:237)
    at rx.internal.operators.OperatorSkipWhile$2.call(OperatorSkipWhile.java:69)
    at rx.internal.operators.OperatorSkipWhile$2.call(OperatorSkipWhile.java:65)
    at rx.internal.operators.OperatorSkipWhile$1.onNext(OperatorSkipWhile.java:43)
    at rx.internal.operators.OnSubscribeRedo$2$1.onNext(OnSubscribeRedo.java:231)
    at rx.internal.operators.OperatorToObservableList$1.onCompleted(OperatorToObservableList.java:72)
    ... 21 more
java.lang.Exception: com.couchbase.client.java.error.DurabilityException: Durability requirement failed: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
    at com.test.TestCouchBase.insertData(TestCouchBase.java:859)
    at com.test.TestCouchBase.testCheckData(TestCouchBase.java:475)
    at com.test.TestCouchBase.processPriceData(TestCouchBase.java:1016)
    at com.test.TestCouchBase.main(TestCouchBase.java:222)
Caused by: com.couchbase.client.java.error.DurabilityException: Durability requirement failed: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
    at com.couchbase.client.java.CouchbaseAsyncBucket$13$1.call(CouchbaseAsyncBucket.java:469)
    at com.couchbase.client.java.CouchbaseAsyncBucket$13$1.call(CouchbaseAsyncBucket.java:465)
    at rx.internal.operators.OperatorOnErrorResumeNextViaFunction$1.onError(OperatorOnErrorResumeNextViaFunction.java:77)
    at rx.internal.operators.OperatorMap$1.onError(OperatorMap.java:49)
    at rx.internal.operators.OperatorMap$1.onError(OperatorMap.java:49)
    at rx.internal.operators.OperatorTake$1.onError(OperatorTake.java:57)
    at rx.internal.operators.OperatorSkipWhile$1.onError(OperatorSkipWhile.java:54)
    at rx.internal.operators.OnSubscribeRedo$3$1.onNext(OnSubscribeRedo.java:273)
    at rx.internal.operators.OnSubscribeRedo$3$1.onNext(OnSubscribeRedo.java:257)
    at rx.subjects.SubjectSubscriptionManager$SubjectObserver.onNext(SubjectSubscriptionManager.java:224)
    at rx.subjects.PublishSubject.onNext(PublishSubject.java:121)
    at rx.internal.operators.OnSubscribeRedo$2$1.onError(OnSubscribeRedo.java:223)
    at rx.internal.operators.OperatorToObservableList$1.onError(OperatorToObservableList.java:81)
    at rx.internal.operators.OperatorToObservableList$1.onCompleted(OperatorToObservableList.java:75)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.drainAndComplete(OperatorMerge.java:481)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.completeInner(OperatorMerge.java:458)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.emit(OperatorMerge.java:617)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.onCompleted(OperatorMerge.java:559)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.drainAndComplete(OperatorMerge.java:481)
    at rx.internal.operators.OperatorMerge$MergeSubscriber.completeInner(OperatorMerge.java:458)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.emit(OperatorMerge.java:632)
    at rx.internal.operators.OperatorMerge$InnerSubscriber.onCompleted(OperatorMerge.java:559)
    at rx.internal.operators.OperatorOnErrorResumeNextViaObservable$1.onCompleted(OperatorOnErrorResumeNextViaObservable.java:85)
    at rx.subjects.SubjectSubscriptionManager$SubjectObserver.onCompleted(SubjectSubscriptionManager.java:232)
    at rx.subjects.AsyncSubject.onCompleted(AsyncSubject.java:102)
    at com.couchbase.client.core.endpoint.AbstractGenericHandler$1.call(AbstractGenericHandler.java:199)
    at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:47)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
Caused by: com.couchbase.client.core.DocumentConcurrentlyModifiedException: The CAS on the active node changed for ID "Price_85646084", indicating it has been modified in the meantime.
    at com.couchbase.client.core.message.observe.Observe$2.call(Observe.java:257)
    at com.couchbase.client.core.message.observe.Observe$2.call(Observe.java:237)
    at rx.internal.operators.OperatorSkipWhile$2.call(OperatorSkipWhile.java:69)
    at rx.internal.operators.OperatorSkipWhile$2.call(OperatorSkipWhile.java:65)
    at rx.internal.operators.OperatorSkipWhile$1.onNext(OperatorSkipWhile.java:43)
    at rx.internal.operators.OnSubscribeRedo$2$1.onNext(OnSubscribeRedo.java:231)
    at rx.internal.operators.OperatorToObservableList$1.onCompleted(OperatorToObservableList.java:72)
    ... 21 more
47625 [cb-io-1-3] INFO com.couchbase.client.core.node.Node - Disconnected from Node slave1.hadoop.com
47625 [cb-io-1-1] INFO com.couchbase.client.core.node.Node - Disconnected from Node slave2.hadoop.com
47625 [main] INFO com.couchbase.client.core.config.ConfigurationProvider - Closed bucket price_datapool
47625 [cb-io-1-1] INFO com.couchbase.client.core.node.Node - Disconnected from Node master.hadoop.com

#2

This message is thrown by the Observe operation, which is the one that checks that your durability constraints are met. It works by polling the master and replicas nodes until enough have acknowledged the mutation for the constraints to be met.

When the cas of the mutated observed document and the cas known to the master node at the time of polling are different, the exception you see is thrown.

I reckon slave3 was the master node for this Price_85646084 key? Was the exception seen just after shutting the node down, or after doing the failover?

From what I can see in the logs I think it is after a failover, and the new master having been elected results in a state where the Observe is unsure if everything is in order.

I guess the best way is then to react to the DurabilityException (after all, your durability constraint couldn’t be met). Check that DurabilityException's getCause() is the DocumentConcurrentlyModifiedException and if so, retry the operation, maybe as an upsert (to be sure that if the insert was only partially done, eg. it is present in some replica nodes but not others, things will work).

@daschl wdyt?

Note: the exception above could also happen if the key is inserted/updated by another client on the same cluster in parallel.

N.B.: I’ve edited your post to isolate the log dumping into a code block (by wrapping it between three backticks `). Try to use formatting for that sort of things to be more readable.


#3

Yes, The new Cluster of Three nodes is created I think by the alert’
47344 [cb-computations-2] INFO com.couchbase.client.core.node.Node - Disconnected from Node slave3.hadoop.com


#4

Does it indicate that the cluster map on client side has not been corrected?


#5

What leads to the problem that the cas Value is changed ?
Because I now just do the insert mutation, and it didnot appear.