I discovered some odd behavior using the Java SDK (version 3.4.7) when attempting to unlock a document that is not actually locked. The unlock call times out rather than doing nothing as I would have expected, or even throwing an exception.
Super simplified example:
public void testUnlockWhenNotLocked(AsyncCollection collection) throws Exception {
var testDoc = Map.of("a", "b", "c", "d");
long cas = collection.upsert("TEST", testDoc).get().cas();
collection.unlock("TEST", cas).get();
}
This runs for 30 seconds (my default timeout value) and throws this:
java.util.concurrent.ExecutionException: com.couchbase.client.core.error.AmbiguousTimeoutException: UnlockRequest, Reason: TIMEOUT {"cancelled":true,"completed":true,"coreId":"0x4facb45400000001","idempotent":false,"lastChannelId":"4FACB45400000001/00000000C9485634","lastDispatchedFrom":"127.0.0.1:64819","lastDispatchedTo":"localhost:11210","reason":"TIMEOUT","requestId":11,"requestType":"UnlockRequest","retried":68,"retryReasons":["KV_TEMPORARY_FAILURE"],"service":{"bucket":"test","collection":"_default","documentId":"TEST","errorCode":{"description":"Temporary failure. Try again","name":"ETMPFAIL"},"opaque":"0xf","scope":"_default","type":"kv","vbucket":746},"timeoutMs":30000,"timings":{"dispatchMicros":4095,"totalDispatchMicros":230630,"totalServerMicros":2,"totalMicros":30022193,"serverMicros":0}}
at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
at com.sample.AsyncTest.testUnlockWhenNotLocked(AsyncTest.java:245)
at com.sample.AsyncTest.sample(AsyncTest.java:239)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:568)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69)
at com.intellij.rt.junit.IdeaTestRunner$Repeater$1.execute(IdeaTestRunner.java:38)
at com.intellij.rt.execution.junit.TestsRepeater.repeat(TestsRepeater.java:11)
at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:35)
at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)
Caused by: com.couchbase.client.core.error.AmbiguousTimeoutException: UnlockRequest, Reason: TIMEOUT {"cancelled":true,"completed":true,"coreId":"0x4facb45400000001","idempotent":false,"lastChannelId":"4FACB45400000001/00000000C9485634","lastDispatchedFrom":"127.0.0.1:64819","lastDispatchedTo":"localhost:11210","reason":"TIMEOUT","requestId":11,"requestType":"UnlockRequest","retried":68,"retryReasons":["KV_TEMPORARY_FAILURE"],"service":{"bucket":"test","collection":"_default","documentId":"TEST","errorCode":{"description":"Temporary failure. Try again","name":"ETMPFAIL"},"opaque":"0xf","scope":"_default","type":"kv","vbucket":746},"timeoutMs":30000,"timings":{"dispatchMicros":4095,"totalDispatchMicros":230630,"totalServerMicros":2,"totalMicros":30022193,"serverMicros":0}}
at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:184)
at com.couchbase.client.core.msg.Request.cancel(Request.java:71)
at com.couchbase.client.core.Timer.lambda$register$2(Timer.java:172)
at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelTimeout.run(HashedWheelTimer.java:715)
at com.couchbase.client.core.deps.io.netty.util.concurrent.ImmediateExecutor.execute(ImmediateExecutor.java:34)
at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:703)
at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:790)
at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:503)
at com.couchbase.client.core.deps.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:833)
This seems like a bug to me. Can you confirm, or explain why this might be?
Thanks,
-Tom