Details
-
Bug
-
Resolution: Incomplete
-
Major
-
None
-
3.0.0-beta.2
-
java-client-3.0.0-beta.2.jar
core-io-2.0.0-beta.2.jar
Description
Server Build: 6.5.0-4959
Java sdk: 3.0-beta.2
Scenario:
- 2 node cluster, couchbase bucket(replica=1)
- Stop replica node and initiate sub_doc insert with timeout=60 using client-1
- Try to perform the same sub_doc insert on same document from client-2 in parallel
Observation:
Client-2 returns 'AmbiguousTimeoutException'.
Expected behavior:
Since fail_fast is not enabled as part the test procedure, client-2 should see 'RequestTimeoutException' with reason 'KV_SYNC_WRITE_IN_PROGRESS'.
Note: This was working as expected in beta.1 release
Test logs:
2019-12-24 02:45:45,809 | test | INFO | MainThread | [subdoc_xattr:test_subdoc_sync_write_in_progress:1760] Testing SyncWriteInProgress with upsert
|
2019-12-24 02:45:45,839 | test | INFO | MainThread | [cb_error:create:37] Simulating 'stop_memcached' in 172.23.104.228
|
2019-12-24 02:45:46,009 | test | INFO | MainThread | [basetestcase:sleep:473] Reason: Wait for doc_op task to start. Sleep for 5 secs ...
|
2019-12-24 02:45:54,016 | test | ERROR | MainThread | [basetestcase:log_failure:478] Invalid exception: {u'xattrs-0': {'error': com.couchbase.client.core.error.AmbiguousTimeoutException: SubdocMutateRequest {"cancelled":true,"completed":true,"coreId":29,"idempotent":false,"lastChannelId":"000000000000001D/0000000004CBFBCB","lastDispatchedFrom":"172.23.96.240:59670","lastDispatchedTo":"172.23.104.229:11210","reason":"TIMEOUT","requestId":805,"requestType":"SubdocMutateRequest","retried":15,"retryReasons":["KV_SYNC_WRITE_IN_PROGRESS"],"service":{"bucket":"default","collection":"_default","documentId":"xattrs-0","opaque":"0x5ad","scope":"_default","syncDurability":{"present":true},"type":"kv"},"timeoutMs":3000,"timings":{"dispatchMicros":602}}, 'cas': 0, 'value': None}}
|
2019-12-24 02:45:54,019 | test | INFO | MainThread | [cb_error:revert:60] Reverting 'stop_memcached' in 172.23.104.228
|
2019-12-24 02:45:54,157 | test | INFO | MainThread | [subdoc_xattr:test_subdoc_sync_write_in_progress:1760] Testing SyncWriteInProgress with replace
|
2019-12-24 02:45:54,187 | test | INFO | MainThread | [cb_error:create:37] Simulating 'stop_memcached' in 172.23.104.228
|
2019-12-24 02:45:54,331 | test | INFO | MainThread | [basetestcase:sleep:473] Reason: Wait for doc_op task to start. Sleep for 5 secs ...
|
2019-12-24 02:46:02,335 | test | ERROR | MainThread | [basetestcase:log_failure:478] Invalid exception: {u'xattrs-0': {'error': com.couchbase.client.core.error.AmbiguousTimeoutException: SubdocMutateRequest {"cancelled":true,"completed":true,"coreId":29,"idempotent":false,"lastChannelId":"000000000000001D/0000000004CBFBCB","lastDispatchedFrom":"172.23.96.240:59670","lastDispatchedTo":"172.23.104.229:11210","reason":"TIMEOUT","requestId":855,"requestType":"SubdocMutateRequest","retried":15,"retryReasons":["KV_SYNC_WRITE_IN_PROGRESS"],"service":{"bucket":"default","collection":"_default","documentId":"xattrs-0","opaque":"0x5f5","scope":"_default","syncDurability":{"present":true},"type":"kv"},"timeoutMs":3000,"timings":{"dispatchMicros":6955}}, 'cas': 0, 'value': None}}
|
2019-12-24 02:46:02,338 | test | INFO | MainThread | [cb_error:revert:60] Reverting 'stop_memcached' in 172.23.104.228
|
2019-12-24 02:46:02,484 | test | INFO | MainThread | [subdoc_xattr:test_subdoc_sync_write_in_progress:1760] Testing SyncWriteInProgress with insert
|
2019-12-24 02:46:02,509 | test | INFO | MainThread | [cb_error:create:37] Simulating 'stop_memcached' in 172.23.104.228
|
2019-12-24 02:46:02,655 | test | INFO | MainThread | [basetestcase:sleep:473] Reason: Wait for doc_op task to start. Sleep for 5 secs ...
|
2019-12-24 02:46:10,667 | test | ERROR | MainThread | [basetestcase:log_failure:478] Invalid exception: {u'xattrs-0': {'error': com.couchbase.client.core.error.AmbiguousTimeoutException: SubdocMutateRequest {"cancelled":true,"completed":true,"coreId":29,"idempotent":false,"lastChannelId":"000000000000001D/0000000004CBFBCB","lastDispatchedFrom":"172.23.96.240:59670","lastDispatchedTo":"172.23.104.229:11210","reason":"TIMEOUT","requestId":907,"requestType":"SubdocMutateRequest","retried":15,"retryReasons":["KV_SYNC_WRITE_IN_PROGRESS"],"service":{"bucket":"default","collection":"_default","documentId":"xattrs-0","opaque":"0x63f","scope":"_default","syncDurability":{"present":true},"type":"kv"},"timeoutMs":3000,"timings":{"dispatchMicros":580}}, 'cas': 0, 'value': None}}
|
2019-12-24 02:46:10,667 | test | INFO | MainThread | [cb_error:revert:60] Reverting 'stop_memcached' in 172.23.104.228
|
2019-12-24 02:46:10,806 | test | INFO | MainThread | [subdoc_xattr:test_subdoc_sync_write_in_progress:1760] Testing SyncWriteInProgress with remove
|
2019-12-24 02:46:10,835 | test | INFO | MainThread | [cb_error:create:37] Simulating 'stop_memcached' in 172.23.104.228
|
2019-12-24 02:46:10,970 | test | INFO | MainThread | [basetestcase:sleep:473] Reason: Wait for doc_op task to start. Sleep for 5 secs ...
|
2019-12-24 02:46:18,976 | test | ERROR | MainThread | [basetestcase:log_failure:478] Invalid exception: {u'xattrs-0': {'error': com.couchbase.client.core.error.AmbiguousTimeoutException: SubdocMutateRequest {"cancelled":true,"completed":true,"coreId":29,"idempotent":false,"lastChannelId":"000000000000001D/0000000004CBFBCB","lastDispatchedFrom":"172.23.96.240:59670","lastDispatchedTo":"172.23.104.229:11210","reason":"TIMEOUT","requestId":957,"requestType":"SubdocMutateRequest","retried":15,"retryReasons":["KV_SYNC_WRITE_IN_PROGRESS"],"service":{"bucket":"default","collection":"_default","documentId":"xattrs-0","opaque":"0x687","scope":"_default","syncDurability":{"present":true},"type":"kv"},"timeoutMs":3000,"timings":{"dispatchMicros":681}}, 'cas': 0, 'value': None}}
|
2019-12-24 02:46:18,977 | test | INFO | MainThread | [cb_error:revert:60] Reverting 'stop_memcached' in 172.23.104.228
|
TAF testcase:
subdoc.subdoc_xattr.SubdocXattrDurabilityTest.test_subdoc_sync_write_in_progress,nodes_init=2,replicas=1,sdk_timeout=60,xattr=False,durabiilty=MAJORITY
|