Unambiguous and Ambiguous Timeout Exceptions with Java SDK

These timeout exceptions are frequently happening while using Java SDK 3.0 that connects with Couchbase Server 6.0. What could be the cause of it. Below is the env settings I am using,

ClusterEnvironment.builder()
            .timeoutConfig(TimeoutConfig
                .kvTimeout(Duration.ofMillis(300000))
                .kvDurableTimeout(Duration.ofMillis(300000))
                .queryTimeout(Duration.ofMillis(300000))
            )
            .ioConfig(IoConfig
                .captureTraffic(ServiceType.KV)
                .captureTraffic(ServiceType.QUERY)
                .numKvConnections(2)
            )
            .loggerConfig(LoggerConfig
                .enableDiagnosticContext(true)
            )
            .ioEnvironment(IoEnvironment
                .eventLoopThreadCount(4)
            )
            .orphanReporterConfig(OrphanReporterConfig
                .sampleSize(Integer.MAX_VALUE)
            )
            .retryStrategy(BestEffortRetryStrategy.INSTANCE)
            .build();

Exceptions,

com.couchbase.client.core.error.AmbiguousTimeoutException: InsertRequest
	at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:163) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.Timer.lambda$register$2(Timer.java:157) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:672) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:747) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:472) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.deps.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[core-io-2.0.5.jar!/:na]
	at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]

com.couchbase.client.core.error.UnambiguousTimeoutException: GetRequest
	at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:163) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.Timer.lambda$register$2(Timer.java:157) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:672) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:747) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:472) ~[core-io-2.0.5.jar!/:na]
	at com.couchbase.client.core.deps.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[core-io-2.0.5.jar!/:na]
	at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]

Hi @sekar, could you please post the full exception including the getMessage()? It will contain more diagnostic info to help debug this.

Hi Graham, Would this help. The getMessage() has just he timeout, hence turned on DEBUG logging. BUCKET_NOT_AVAILABLE is the error received before the timeout exception is thrown.

2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][8000us] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13249,"requestType":"InsertRequest","retried":8,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"IC:79363165186190,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3451","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":58}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][8000us] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13250,"requestType":"InsertRequest","retried":8,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"IC:46668933055536,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3452","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":34}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][8000us] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13251,"requestType":"InsertRequest","retried":8,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"C:78490371374285,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3453","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":59}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][8000us] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13252,"requestType":"InsertRequest","retried":8,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"C:43207323507684,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3454","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":37}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][8000us] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13253,"requestType":"InsertRequest","retried":8,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"IC:78490371374285,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3455","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":38}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][8000us] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13254,"requestType":"InsertRequest","retried":8,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"IC:43207323507684,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3456","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":33}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][128ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13239,"requestType":"InsertRequest","retried":9,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"C:17802681368522,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3447","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":40}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][128ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13240,"requestType":"InsertRequest","retried":9,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"C:13728679309706,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3448","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":21}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][128ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13241,"requestType":"InsertRequest","retried":9,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"IC:17802681368522,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3449","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":20}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][128ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13242,"requestType":"InsertRequest","retried":9,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"IC:13728679309706,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x344a","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":19}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][128ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13243,"requestType":"InsertRequest","retried":9,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"C:87531564897997,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x344b","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":39}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][128ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13244,"requestType":"InsertRequest","retried":9,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"C:56203948024204,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x344c","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":22}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][128ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13245,"requestType":"InsertRequest","retried":9,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"IC:87531564897997,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x344d","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":20}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][128ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13246,"requestType":"InsertRequest","retried":9,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"IC:56203948024204,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x344e","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":20}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][16ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13247,"requestType":"InsertRequest","retried":8,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"C:79363165186190,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x344f","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":90}}
2020-06-11 06:46:04.405     DEBUG shared-approval-service:devperf [-,-,-] 23 --- [cb-events] com.couchbase.request                    : [com.couchbase.request][RequestRetryScheduledEvent][16ms] Request InsertRequest retry scheduled per RetryStrategy (Reason: BUCKET_NOT_AVAILABLE) {"completed":false,"coreId":"0xc4b0a20c00000001","idempotent":false,"requestId":13248,"requestType":"InsertRequest","retried":8,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"eventProcessor","collection":"_default","documentId":"C:46668933055536,2231bb94-05c9-4914-a37e-55ce1907fd02","opaque":"0x3450","scope":"_default","syncDurability":{"empty":true,"present":false},"type":"kv"},"timeoutMs":300000,"timings":{"encodingMicros":37}}