Using the Java SDK

Hi

Environment:
Java Client SDK: 3.0.2
Java 8

Hoping someone can point me in the correct direction here as am new to couchbase. I am trying to use the java SDK to connect with my couchbase instance. I use the following code:

        Cluster cluster = Cluster.connect("xxxxx:8091", "Administrator", "password");
        Bucket bucket = cluster.bucket("verification_state");
        Collection collection = bucket.defaultCollection();

        JsonObject content = JsonObject.create().put("foo", "bar");

        MutationResult result = collection.upsert("document-key", content);

When I try this it throws the folloiwng error when trying to insert the document into the database:

Mar 19, 2020 12:40:09 PM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.node][NodeDisconnectedEvent][7328us] Node disconnected {"coreId":"0x9b354cf700000001","managerPort":"8091","remote":"xxxxx"}
Exception in thread "main" com.couchbase.client.core.error.AmbiguousTimeoutException: UpsertRequest {"cancelled":true,"completed":true,"coreId":"0x9b354cf700000001","idempotent":false,"reason":"TIMEOUT","requestId":4,"requestType":"UpsertRequest","retried":14,"retryReasons":["BUCKET_NOT_AVAILABLE"],"service":{"bucket":"verification_state","collection":"_default","documentId":"document-key","opaque":"0x8","scope":"_default","syncDurability":{"present":false},"type":"kv"},"timeoutMs":2500,"timings":{"encodingMicros":9240,"totalMicros":2510871}}
	at com.couchbase.client.java.AsyncUtils.block(AsyncUtils.java:51)

The error seems to be that it cannot connect to the bucket as it shows in the log “retryReasons”:[“BUCKET_NOT_AVAILABLE”].

I can do the following curl request

/pools/default/buckets/verification_state

and I get a payload back about my bucket so not sure why the bucket not available is shown unless this is a red herring

Any advice appreciated

Thanks in advance

1 Like

@fshoukat you do not need to provide :8091 on the connection string. “BUCKET_NOT_AVAILABLE” is fine during bootstrap, since it will reschedule ops. Can you post the full logs maybe? You can also DM to me if you do not want to share with a wider audience.

If you do not want to see BUCKET_NOT_AVAILABLE you can do a bucket.waitUntilReady(…) before performing your first op, but it is usually harmless.

@daschl Thanks for the response.

Below are the full logs from the execution of the test

C:\apps\jdk1.8.0_201\bin\java.exe "-javaagent:C:\apps\JetBrains\IntelliJ IDEA Community Edition 2019.3.1\lib\idea_rt.jar=53809:C:\apps\JetBrains\IntelliJ IDEA Community Edition 2019.3.1\bin" -Dfile.encoding=UTF-8 -classpath C:\apps\jdk1.8.0_201\jre\lib\charsets.jar;C:\apps\jdk1.8.0_201\jre\lib\deploy.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\access-bridge-64.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\cldrdata.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\dnsns.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\jaccess.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\jfxrt.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\localedata.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\nashorn.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\sunec.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\sunjce_provider.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\sunmscapi.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\sunpkcs11.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\zipfs.jar;C:\apps\jdk1.8.0_201\jre\lib\javaws.jar;C:\apps\jdk1.8.0_201\jre\lib\jce.jar;C:\apps\jdk1.8.0_201\jre\lib\jfr.jar;C:\apps\jdk1.8.0_201\jre\lib\jfxswt.jar;C:\apps\jdk1.8.0_201\jre\lib\jsse.jar;C:\apps\jdk1.8.0_201\jre\lib\management-agent.jar;C:\apps\jdk1.8.0_201\jre\lib\plugin.jar;C:\apps\jdk1.8.0_201\jre\lib\resources.jar;C:\apps\jdk1.8.0_201\jre\lib\rt.jar;C:\dev\couchbase_test\target\classes;C:\Users\FSH10\.m2\repository\com\couchbase\client\java-client\3.0.2\java-client-3.0.2.jar;C:\Users\FSH10\.m2\repository\com\couchbase\client\core-io\2.0.3\core-io-2.0.3.jar;C:\Users\FSH10\.m2\repository\io\projectreactor\reactor-core\3.3.2.RELEASE\reactor-core-3.3.2.RELEASE.jar;C:\Users\FSH10\.m2\repository\org\reactivestreams\reactive-streams\1.0.3\reactive-streams-1.0.3.jar CouchbaseTest
Mar 19, 2020 2:59:09 PM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.core][CoreCreatedEvent] {"clientVersion":"3.0.2","clientGitHash":"99bb1bc0","coreVersion":"2.0.3","coreGitHash":"99bb1bc0","userAgent":"couchbase-java/3.0.2 (Windows 10 10.0 amd64; Java HotSpot(TM) 64-Bit Server VM 1.8.0_201-b09)","maxNumRequestsInRetry":32768,"ioEnvironment":{"nativeIoEnabled":true,"eventLoopThreadCount":4,"eventLoopGroups":["NioEventLoopGroup"]},"ioConfig":{"captureTraffic":[],"mutationTokensEnabled":true,"networkResolution":"auto","dnsSrvEnabled":true,"tcpKeepAlivesEnabled":true,"tcpKeepAliveTimeMs":60000,"configPollIntervalMs":2500,"kvCircuitBreakerConfig":"disabled","queryCircuitBreakerConfig":"disabled","viewCircuitBreakerConfig":"disabled","searchCircuitBreakerConfig":"disabled","analyticsCircuitBreakerConfig":"disabled","managerCircuitBreakerConfig":"disabled","numKvConnections":1,"maxHttpConnections":12,"idleHttpConnectionTimeoutMs":30000,"configIdleRedialTimeoutMs":300000},"compressionConfig":{"enabled":true,"minRatio":0.83,"minSize":32},"securityConfig":{"tlsEnabled":false,"nativeTlsEnabled":true,"hasTrustCertificates":false,"trustManagerFactory":null},"timeoutConfig":{"kvMs":2500,"kvDurableMs":10000,"managementMs":75000,"queryMs":75000,"viewMs":75000,"searchMs":75000,"analyticsMs":75000,"connectMs":10000,"disconnectMs":10000},"loggerConfig":{"customLogger":null,"fallbackToConsole":false,"disableSlf4j":false,"loggerName":"CouchbaseLogger","diagnosticContextEnabled":false},"orphanReporterConfig":{"emitIntervalMs":10000,"sampleSize":10,"queueLength":1024},"retryStrategy":"BestEffortRetryStrategy","requestTracer":"OwnedSupplier"} {"coreId":"0xab5bfc5a00000001"}
Mar 19, 2020 2:59:09 PM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.node][NodeConnectedEvent] Node connected {"coreId":"0xab5bfc5a00000001","managerPort":"8091","remote":"ud006063"}
Exception in thread "main" com.couchbase.client.core.error.AmbiguousTimeoutException: UpsertRequest {"cancelled":true,"completed":true,"coreId":"0xab5bfc5a00000001","idempotent":false,"reason":"TIMEOUT","requestId":3,"requestType":"UpsertRequest","retried":14,"retryReasons":["BUCKET_OPEN_IN_PROGRESS"],"service":{"bucket":"verification_state","collection":"_default","documentId":"document-key","opaque":"0x2","scope":"_default","syncDurability":{"present":false},"type":"kv"},"timeoutMs":2500,"timings":{"encodingMicros":2934,"totalMicros":2509474}}
	at com.couchbase.client.java.AsyncUtils.block(AsyncUtils.java:51)
	at com.couchbase.client.java.Collection.upsert(Collection.java:409)
	at CouchbaseTest.main(CouchbaseTest.java:36)
	Suppressed: java.lang.Exception: The above exception was originally thrown by another thread at the following location.
		at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:163)
		at com.couchbase.client.core.Timer.lambda$register$2(Timer.java:157)
		at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:672)
		at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:747)
		at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:472)
		at com.couchbase.client.core.deps.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
		at java.lang.Thread.run(Thread.java:748)

Process finished with exit code 1

@fshoukat can you try a bucket.waitUntilReady(…); before running the upsert operation?

1 Like

@daschl So I set my timeout to 2 minutes and got the following errors:

C:\apps\jdk1.8.0_201\bin\java.exe "-javaagent:C:\apps\JetBrains\IntelliJ IDEA Community Edition 2019.3.1\lib\idea_rt.jar=56210:C:\apps\JetBrains\IntelliJ IDEA Community Edition 2019.3.1\bin" -Dfile.encoding=UTF-8 -classpath C:\apps\jdk1.8.0_201\jre\lib\charsets.jar;C:\apps\jdk1.8.0_201\jre\lib\deploy.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\access-bridge-64.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\cldrdata.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\dnsns.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\jaccess.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\jfxrt.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\localedata.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\nashorn.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\sunec.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\sunjce_provider.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\sunmscapi.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\sunpkcs11.jar;C:\apps\jdk1.8.0_201\jre\lib\ext\zipfs.jar;C:\apps\jdk1.8.0_201\jre\lib\javaws.jar;C:\apps\jdk1.8.0_201\jre\lib\jce.jar;C:\apps\jdk1.8.0_201\jre\lib\jfr.jar;C:\apps\jdk1.8.0_201\jre\lib\jfxswt.jar;C:\apps\jdk1.8.0_201\jre\lib\jsse.jar;C:\apps\jdk1.8.0_201\jre\lib\management-agent.jar;C:\apps\jdk1.8.0_201\jre\lib\plugin.jar;C:\apps\jdk1.8.0_201\jre\lib\resources.jar;C:\apps\jdk1.8.0_201\jre\lib\rt.jar;C:\dev\couchbase_test\target\classes;C:\Users\FSH10\.m2\repository\com\couchbase\client\java-client\3.0.2\java-client-3.0.2.jar;C:\Users\FSH10\.m2\repository\com\couchbase\client\core-io\2.0.3\core-io-2.0.3.jar;C:\Users\FSH10\.m2\repository\io\projectreactor\reactor-core\3.3.2.RELEASE\reactor-core-3.3.2.RELEASE.jar;C:\Users\FSH10\.m2\repository\org\reactivestreams\reactive-streams\1.0.3\reactive-streams-1.0.3.jar CouchbaseTest
Mar 20, 2020 9:20:27 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.core][CoreCreatedEvent] {"clientVersion":"3.0.2","clientGitHash":"99bb1bc0","coreVersion":"2.0.3","coreGitHash":"99bb1bc0","userAgent":"couchbase-java/3.0.2 (Windows 10 10.0 amd64; Java HotSpot(TM) 64-Bit Server VM 1.8.0_201-b09)","maxNumRequestsInRetry":32768,"ioEnvironment":{"nativeIoEnabled":true,"eventLoopThreadCount":4,"eventLoopGroups":["NioEventLoopGroup"]},"ioConfig":{"captureTraffic":[],"mutationTokensEnabled":true,"networkResolution":"auto","dnsSrvEnabled":true,"tcpKeepAlivesEnabled":true,"tcpKeepAliveTimeMs":60000,"configPollIntervalMs":2500,"kvCircuitBreakerConfig":"disabled","queryCircuitBreakerConfig":"disabled","viewCircuitBreakerConfig":"disabled","searchCircuitBreakerConfig":"disabled","analyticsCircuitBreakerConfig":"disabled","managerCircuitBreakerConfig":"disabled","numKvConnections":1,"maxHttpConnections":12,"idleHttpConnectionTimeoutMs":30000,"configIdleRedialTimeoutMs":300000},"compressionConfig":{"enabled":true,"minRatio":0.83,"minSize":32},"securityConfig":{"tlsEnabled":false,"nativeTlsEnabled":true,"hasTrustCertificates":false,"trustManagerFactory":null},"timeoutConfig":{"kvMs":2500,"kvDurableMs":10000,"managementMs":75000,"queryMs":75000,"viewMs":75000,"searchMs":75000,"analyticsMs":75000,"connectMs":10000,"disconnectMs":10000},"loggerConfig":{"customLogger":null,"fallbackToConsole":false,"disableSlf4j":false,"loggerName":"CouchbaseLogger","diagnosticContextEnabled":false},"orphanReporterConfig":{"emitIntervalMs":10000,"sampleSize":10,"queueLength":1024},"retryStrategy":"BestEffortRetryStrategy","requestTracer":"OwnedSupplier"} {"coreId":"0xcf89c5a500000001"}
Mar 20, 2020 9:20:27 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.node][NodeConnectedEvent] Node connected {"coreId":"0xcf89c5a500000001","managerPort":"8091","remote":"ud006063"}
Mar 20, 2020 9:20:37 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger warn
WARNING: [com.couchbase.endpoint][EndpointConnectionFailedEvent][10s] Connect attempt 1 failed because of TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured) {"circuitBreaker":"DISABLED","coreId":"0xcf89c5a500000001","remote":"ud006063:8091","type":"KV"}
java.util.concurrent.TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured)
	at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:289)
	at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:274)
	at reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:396)
	at reactor.core.publisher.StrictSubscriber.onNext(StrictSubscriber.java:89)
	at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73)
	at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:117)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

Mar 20, 2020 9:20:39 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger warn
WARNING: [com.couchbase.core][InitGlobalConfigFailedEvent][11s] Initializing the global config failed: UNKNOWN {"coreId":"0xcf89c5a500000001"}
com.couchbase.client.core.error.ConfigException: Caught exception while loading global config.
	at com.couchbase.client.core.config.loader.GlobalLoader.lambda$load$3(GlobalLoader.java:70)
	at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:88)
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134)
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134)
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134)
	at reactor.core.publisher.Operators$MonoSubscriber.onError(Operators.java:1684)
	at reactor.core.publisher.MonoIgnoreThen$ThenAcceptInner.onError(MonoIgnoreThen.java:306)
	at reactor.core.publisher.FluxMap$MapSubscriber.onError(FluxMap.java:126)
	at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:100)
	at reactor.core.publisher.Operators.error(Operators.java:182)
	at reactor.core.publisher.MonoError.subscribe(MonoError.java:52)
	at reactor.core.publisher.Mono.subscribe(Mono.java:4105)
	at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:97)
	at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onError(FluxDoFinally.java:129)
	at com.couchbase.client.core.Reactor$SilentMonoCompletionStage.lambda$subscribe$0(Reactor.java:175)
	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760)
	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977)
	at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:168)
	at com.couchbase.client.core.Timer.lambda$register$2(Timer.java:157)
	at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:672)
	at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:747)
	at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:472)
	at com.couchbase.client.core.deps.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)
Caused by: com.couchbase.client.core.error.UnambiguousTimeoutException: CarrierGlobalConfigRequest {"cancelled":true,"completed":true,"coreId":"0xcf89c5a500000001","idempotent":true,"reason":"TIMEOUT","requestId":1,"requestType":"CarrierGlobalConfigRequest","retried":29,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque":"0x0","target":"ud006063","type":"kv"},"timeoutMs":10000}
	at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:163)
	... 6 more

Mar 20, 2020 9:20:39 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger warn
WARNING: [com.couchbase.endpoint][EndpointConnectionFailedEvent][10s] Connect attempt 1 failed because of TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured) {"bucket":"verification_state","circuitBreaker":"DISABLED","coreId":"0xcf89c5a500000001","remote":"ud006063:8091","type":"KV"}
java.util.concurrent.TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured)
	at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:289)
	at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:274)
	at reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:396)
	at reactor.core.publisher.StrictSubscriber.onNext(StrictSubscriber.java:89)
	at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73)
	at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:117)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

Mar 20, 2020 9:20:39 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.core][BucketOpenedEvent][10s] Opened bucket "verification_state" {"coreId":"0xcf89c5a500000001"}
Mar 20, 2020 9:20:39 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.request][RequestNotRetriedEvent] Request CarrierBucketConfigRequest not retried per RetryStrategy (Reason: ENDPOINT_NOT_AVAILABLE) {"cancelled":true,"completed":true,"coreId":"0xcf89c5a500000001","idempotent":true,"reason":"NO_MORE_RETRIES (ENDPOINT_NOT_AVAILABLE)","requestId":7,"requestType":"CarrierBucketConfigRequest","retried":0,"service":{"bucket":"verification_state","collection":"_default","opaque":"0x6","scope":"_default","target":"ud006063","type":"kv"},"timeoutMs":2500}
Mar 20, 2020 9:20:39 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.config][BucketConfigRefreshFailedEvent] Reason: INDIVIDUAL_REQUEST_FAILED, Type: KV, Cause: com.couchbase.client.core.error.RequestCanceledException: CarrierBucketConfigRequest {"cancelled":true,"completed":true,"coreId":"0xcf89c5a500000001","idempotent":true,"reason":"NO_MORE_RETRIES (ENDPOINT_NOT_AVAILABLE)","requestId":7,"requestType":"CarrierBucketConfigRequest","retried":0,"service":{"bucket":"verification_state","collection":"_default","opaque":"0x6","scope":"_default","target":"ud006063","type":"kv"},"timeoutMs":2500} {"coreId":"0xcf89c5a500000001"}
Mar 20, 2020 9:20:42 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.request][RequestNotRetriedEvent] Request CarrierBucketConfigRequest not retried per RetryStrategy (Reason: ENDPOINT_NOT_AVAILABLE) {"cancelled":true,"completed":true,"coreId":"0xcf89c5a500000001","idempotent":true,"reason":"NO_MORE_RETRIES (ENDPOINT_NOT_AVAILABLE)","requestId":8,"requestType":"CarrierBucketConfigRequest","retried":0,"service":{"bucket":"verification_state","collection":"_default","opaque":"0x7","scope":"_default","target":"ud006063","type":"kv"},"timeoutMs":2500}
Mar 20, 2020 9:20:42 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.config][BucketConfigRefreshFailedEvent] Reason: INDIVIDUAL_REQUEST_FAILED, Type: KV, Cause: com.couchbase.client.core.error.RequestCanceledException: CarrierBucketConfigRequest {"cancelled":true,"completed":true,"coreId":"0xcf89c5a500000001","idempotent":true,"reason":"NO_MORE_RETRIES (ENDPOINT_NOT_AVAILABLE)","requestId":8,"requestType":"CarrierBucketConfigRequest","retried":0,"service":{"bucket":"verification_state","collection":"_default","opaque":"0x7","scope":"_default","target":"ud006063","type":"kv"},"timeoutMs":2500} {"coreId":"0xcf89c5a500000001"}
Mar 20, 2020 9:20:45 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.request][RequestNotRetriedEvent] Request CarrierBucketConfigRequest not retried per RetryStrategy (Reason: ENDPOINT_NOT_AVAILABLE) {"cancelled":true,"completed":true,"coreId":"0xcf89c5a500000001","idempotent":true,"reason":"NO_MORE_RETRIES (ENDPOINT_NOT_AVAILABLE)","requestId":9,"requestType":"CarrierBucketConfigRequest","retried":0,"service":{"bucket":"verification_state","collection":"_default","opaque":"0x8","scope":"_default","target":"ud006063","type":"kv"},"timeoutMs":2500}
Mar 20, 2020 9:20:45 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.config][BucketConfigRefreshFailedEvent] Reason: INDIVIDUAL_REQUEST_FAILED, Type: KV, Cause: com.couchbase.client.core.error.RequestCanceledException: CarrierBucketConfigRequest {"cancelled":true,"completed":true,"coreId":"0xcf89c5a500000001","idempotent":true,"reason":"NO_MORE_RETRIES (ENDPOINT_NOT_AVAILABLE)","requestId":9,"requestType":"CarrierBucketConfigRequest","retried":0,"service":{"bucket":"verification_state","collection":"_default","opaque":"0x8","scope":"_default","target":"ud006063","type":"kv"},"timeoutMs":2500} {"coreId":"0xcf89c5a500000001"}
Mar 20, 2020 9:20:47 AM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger warn
WARNING: [com.couchbase.endpoint][EndpointConnectionFailedEvent][10s] Connect attempt 2 failed because of TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured) {"circuitBreaker":"DISABLED","coreId":"0xcf89c5a500000001","remote":"ud006063:8091","type":"KV"}
java.util.concurrent.TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured)
	at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:289)
	at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:274)
	at reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:396)
	at reactor.core.publisher.StrictSubscriber.onNext(StrictSubscriber.java:89)
	at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73)
	at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:117)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

@daschl any pointers on the above exception?

@fshoukat yes please remove the :8091 from the connection string, that should resolve the issue

1 Like

Performed this. But I am still getting the same error as mentioned in the original error post.

Hi,

I have, today, run into the same problem. I am using version 3.0.5 of the Java SDK. One thing that I notice is that the problem occurs when connecting to an instance of Couchbase server, version 5.5.2. The error does not occur when connecting to an instance of Couchbase server, version 6.5.0. The two instances are on distinct virtual machines and there may be other factors involved, but this immediately caught my eye.

Here is the log:

2020-09-14 18:59:18,723 [      cb-events] core                      INFO  [com.couchbase.core][CoreCreatedEvent] {"clientVersion":"3.0.5","clientGitHash":"ac204fc7","coreVe
rsion":"2.0.6","coreGitHash":"ac204fc7","userAgent":"couchbase-java/3.0.5 (Windows 10 10.0 amd64; Java HotSpot(TM) 64-Bit Server VM 1.8.0_201-b09)","maxNumRequestsInRetry":
32768,"ioEnvironment":{"nativeIoEnabled":true,"eventLoopThreadCount":4,"eventLoopGroups":["NioEventLoopGroup"]},"ioConfig":{"captureTraffic":[],"mutationTokensEnabled":true
,"networkResolution":"auto","dnsSrvEnabled":true,"tcpKeepAlivesEnabled":true,"tcpKeepAliveTimeMs":60000,"configPollIntervalMs":2500,"kvCircuitBreakerConfig":"disabled","que
ryCircuitBreakerConfig":"disabled","viewCircuitBreakerConfig":"disabled","searchCircuitBreakerConfig":"disabled","analyticsCircuitBreakerConfig":"disabled","managerCircuitB
reakerConfig":"disabled","numKvConnections":1,"maxHttpConnections":12,"idleHttpConnectionTimeoutMs":30000,"configIdleRedialTimeoutMs":300000},"compressionConfig":{"enabled"
:true,"minRatio":0.83,"minSize":32},"securityConfig":{"tlsEnabled":false,"nativeTlsEnabled":true,"hasTrustCertificates":false,"trustManagerFactory":null},"timeoutConfig":{"
kvMs":2500,"kvDurableMs":10000,"managementMs":75000,"queryMs":75000,"viewMs":75000,"searchMs":75000,"analyticsMs":75000,"connectMs":10000,"disconnectMs":10000},"loggerConfi
g":{"customLogger":null,"fallbackToConsole":false,"disableSlf4j":false,"loggerName":"CouchbaseLogger","diagnosticContextEnabled":false},"orphanReporterConfig":{"emitInterva
lMs":10000,"sampleSize":10,"queueLength":1024},"retryStrategy":"BestEffortRetryStrategy","requestTracer":"OwnedSupplier"} {"coreId":"0xcb55c9f200000001","seedNodes":[{"addr
ess":"10.236.82.20"}]}
2020-09-14 18:59:18,736 [      cb-events] node                      INFO  [com.couchbase.node][NodeConnectedEvent] Node connected {"coreId":"0xcb55c9f200000001","managerPor
t":"8091","remote":"10.236.82.20"}
2020-09-14 18:59:28,705 [      cb-events] endpoint                  WARN  [com.couchbase.endpoint][EndpointConnectionFailedEvent][10s] Connect attempt 1 failed because of T
imeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured) {"circuitBreaker":"DISABLED","coreI
d":"0xcb55c9f200000001","remote":"10.236.82.20:11210","type":"KV"}
java.util.concurrent.TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured)
        at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:289)
        at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:274)
        at reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:396)
        at reactor.core.publisher.StrictSubscriber.onNext(StrictSubscriber.java:89)
        at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73)
        at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:117)
        at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
        at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
2020-09-14 18:59:29,615 [      cb-events] core                      WARN  [com.couchbase.core][InitGlobalConfigFailedEvent][10s] Initializing the global config failed: UNKN
OWN {"coreId":"0xcb55c9f200000001"}
com.couchbase.client.core.error.ConfigException: Caught exception while loading global config.
        at com.couchbase.client.core.config.loader.GlobalLoader.lambda$load$3(GlobalLoader.java:70)
        at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:88)
        at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134)
        at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134)
        at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134)
        at reactor.core.publisher.Operators$MonoSubscriber.onError(Operators.java:1802)
        at reactor.core.publisher.MonoIgnoreThen$ThenAcceptInner.onError(MonoIgnoreThen.java:306)
        at reactor.core.publisher.FluxMap$MapSubscriber.onError(FluxMap.java:126)
        at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:100)
        at reactor.core.publisher.Operators.error(Operators.java:196)
        at reactor.core.publisher.MonoError.subscribe(MonoError.java:52)
        at reactor.core.publisher.Mono.subscribe(Mono.java:4218)
        at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:97)
        at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onError(FluxDoFinally.java:129)
        at com.couchbase.client.core.Reactor$SilentMonoCompletionStage.lambda$subscribe$0(Reactor.java:175)
        at java.util.concurrent.CompletableFuture.uniWhenComplete(Unknown Source)
        at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(Unknown Source)
        at java.util.concurrent.CompletableFuture.postComplete(Unknown Source)
        at java.util.concurrent.CompletableFuture.completeExceptionally(Unknown Source)
        at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:168)
        at com.couchbase.client.core.Timer.lambda$register$2(Timer.java:157)
        at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:672)
        at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:747)
        at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:472)
        at com.couchbase.client.core.deps.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Unknown Source)
Caused by: com.couchbase.client.core.error.UnambiguousTimeoutException: CarrierGlobalConfigRequest {"cancelled":true,"completed":true,"coreId":"0xcb55c9f200000001","idempot
ent":true,"reason":"TIMEOUT","requestId":1,"requestType":"CarrierGlobalConfigRequest","retried":29,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque":"0x0","target":
"10.236.82.20","type":"kv"},"timeoutMs":10000}
        at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:163)
        ... 6 more

After which it keeps trying to connect indefinitely.

Thanks in advance

@jsb would it be okay for you to double check if the issue still happens with 3.0.8 (the latest release?) Thanks!

Hi @daschl,

Unfortunately, I get the same result with version 3.0.8. One thing that catches my eye is that even though I set the waitUntilReady to 15000ms, the log reports not observing “any item or terminal signal within 10000ms”.

Here’s the log:

2020-09-15 08:56:09,459 [      cb-events] core                           INFO  [com.couchbase.core][CoreCreatedEvent] {"clientVersion":"3.0.8","clientGitHash":"39d39e0d","c
oreVersion":"2.0.9","coreGitHash":"39d39e0d","userAgent":"couchbase-java/3.0.8 (Windows 10 10.0 amd64; Java HotSpot(TM) 64-Bit Server VM 1.8.0_201-b09)","maxNumRequestsInRe
try":32768,"ioEnvironment":{"nativeIoEnabled":true,"eventLoopThreadCount":4,"eventLoopGroups":["NioEventLoopGroup"]},"ioConfig":{"captureTraffic":[],"mutationTokensEnabled"
:true,"networkResolution":"auto","dnsSrvEnabled":true,"tcpKeepAlivesEnabled":true,"tcpKeepAliveTimeMs":60000,"configPollIntervalMs":2500,"kvCircuitBreakerConfig":"disabled"
,"queryCircuitBreakerConfig":"disabled","viewCircuitBreakerConfig":"disabled","searchCircuitBreakerConfig":"disabled","analyticsCircuitBreakerConfig":"disabled","managerCir
cuitBreakerConfig":"disabled","numKvConnections":1,"maxHttpConnections":12,"idleHttpConnectionTimeoutMs":4500,"configIdleRedialTimeoutMs":300000},"compressionConfig":{"enab
led":true,"minRatio":0.83,"minSize":32},"securityConfig":{"tlsEnabled":false,"nativeTlsEnabled":true,"hasTrustCertificates":false,"trustManagerFactory":null},"timeoutConfig
":{"kvMs":2500,"kvDurableMs":10000,"managementMs":75000,"queryMs":75000,"viewMs":75000,"searchMs":75000,"analyticsMs":75000,"connectMs":10000,"disconnectMs":10000},"loggerC
onfig":{"customLogger":null,"fallbackToConsole":false,"disableSlf4j":false,"loggerName":"CouchbaseLogger","diagnosticContextEnabled":false},"orphanReporterConfig":{"emitInt
ervalMs":10000,"sampleSize":10,"queueLength":1024},"thresholdRequestTracerConfig":{"emitIntervalMs":10000,"sampleSize":10,"queueLength":1024,"kvThresholdMs":500,"queryThres
holdMs":1000,"searchThresholdMs":1000,"analyticsThresholdMs":1000,"viewThresholdMs":1000},"retryStrategy":"BestEffortRetryStrategy","requestTracer":"ThresholdRequestTracer"
} {"coreId":"0x61fe176900000001","seedNodes":[{"address":"10.236.82.20"}]}
2020-09-15 08:56:09,480 [      cb-events] node                           INFO  [com.couchbase.node][NodeConnectedEvent] Node connected {"coreId":"0x61fe176900000001","manag
erPort":"8091","remote":"10.236.82.20"}
2020-09-15 08:56:20,367 [      cb-events] endpoint                       WARN  [com.couchbase.endpoint][EndpointConnectionFailedEvent][10s] Connect attempt 1 failed because
 of TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured) {"circuitBreaker":"DISABLED","
coreId":"0x61fe176900000001","remote":"10.236.82.20:11210","type":"KV"}
java.util.concurrent.TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured)
        at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:288)
        at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:273)
        at reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:395)
        at reactor.core.publisher.StrictSubscriber.onNext(StrictSubscriber.java:89)
        at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73)
        at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:117)
        at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
        at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
2020-09-15 08:56:20,371 [      cb-events] core                           WARN  [com.couchbase.core][InitGlobalConfigFailedEvent][10s] Initializing the global config failed:
 UNKNOWN {"coreId":"0x61fe176900000001"}
com.couchbase.client.core.error.ConfigException: Caught exception while loading global config.
        at com.couchbase.client.core.config.loader.GlobalLoader.lambda$load$3(GlobalLoader.java:72)
        at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:88)
        at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134)
        at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134)
        at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:134)
        at reactor.core.publisher.Operators$MonoSubscriber.onError(Operators.java:1829)
        at reactor.core.publisher.MonoIgnoreThen$ThenAcceptInner.onError(MonoIgnoreThen.java:306)
        at reactor.core.publisher.FluxMap$MapSubscriber.onError(FluxMap.java:126)
        at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:100)
        at reactor.core.publisher.Operators.error(Operators.java:196)
        at reactor.core.publisher.MonoError.subscribe(MonoError.java:52)
        at reactor.core.publisher.Mono.subscribe(Mono.java:4213)
        at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:97)
        at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onError(FluxDoFinally.java:129)
        at com.couchbase.client.core.Reactor$SilentMonoCompletionStage.lambda$subscribe$0(Reactor.java:175)
        at java.util.concurrent.CompletableFuture.uniWhenComplete(Unknown Source)
        at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(Unknown Source)
        at java.util.concurrent.CompletableFuture.postComplete(Unknown Source)
        at java.util.concurrent.CompletableFuture.completeExceptionally(Unknown Source)
        at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:168)
        at com.couchbase.client.core.Timer.lambda$register$2(Timer.java:157)
        at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:672)
        at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:747)
        at com.couchbase.client.core.deps.io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:472)
        at com.couchbase.client.core.deps.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Unknown Source)
Caused by: com.couchbase.client.core.error.UnambiguousTimeoutException: CarrierGlobalConfigRequest, Reason: TIMEOUT {"cancelled":true,"completed":true,"coreId":"0x61fe17690
0000001","idempotent":true,"reason":"TIMEOUT","requestId":1,"requestType":"CarrierGlobalConfigRequest","retried":29,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque
":"0x0","target":"10.236.82.20","type":"kv"},"timeoutMs":10000}
        at com.couchbase.client.core.msg.BaseRequest.cancel(BaseRequest.java:163)
        ... 6 more
2020-09-15 08:56:30,331 [      cb-events] endpoint                       WARN  [com.couchbase.endpoint][EndpointConnectionFailedEvent][10s] Connect attempt 2 failed because
 of TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured) {"circuitBreaker":"DISABLED","
coreId":"0x61fe176900000001","remote":"10.236.82.20:11210","type":"KV"}
java.util.concurrent.TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured)
        at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:288)
        at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:273)
        at reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:395)
        at reactor.core.publisher.StrictSubscriber.onNext(StrictSubscriber.java:89)
        at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73)
        at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:117)
        at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68)
        at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)

I attach a log with the log level set to DEBUG.

Thanks!

couchbase-client.zip (7.8 KB)

@jsb I think what you observed is semantically correct: the socket retry delay is different from the timeout specified in the waitUntilReady.

Two more questions for clarification if you don’t mind:

  • Does the waitUntilReady time out?
  • Does your app work (so is this affecting your app or just noise in the logs)

@daschl the waitUntilReady does not seem to be working in that there is a ten second pause between:

2020-09-15 19:08:35,171 [                     cb-events] node                           INFO  [com.couchbase.node][NodeConnectedEvent] Node connected {"coreId":"0xcf854ebc0
0000001","managerPort":"8091","remote":"10.236.82.20"}

And

2020-09-15 19:08:46,057 [                     cb-events] endpoint                       WARN  [com.couchbase.endpoint][EndpointConnectionFailedEvent][10s] Connect attempt 1
 failed because of TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured) {"circuitBreake
r":"DISABLED","coreId":"0xcf854ebc00000001","remote":"10.236.82.20:11210","type":"KV"}
java.util.concurrent.TimeoutException: Did not observe any item or terminal signal within 10000ms in 'source(MonoDefer)' (and no fallback has been configured)

My app does not work as it ends up trying, and failing, to connect indefinitely (yesterday, having been distracted by something else, it got to around 150 attempts before I killed it).

I was wondering if it could be a networking thing. The Couchbase server is in a container in an OpenShift environment and the client app is on my laptop. I can access the Couchbase UI, using Chrome, on port 31091. However, if I try to connect using cbq, specifying “-e http://10.236.82.20:31091”, I get:

ERROR 100 : N1QL: Connection failed Post http://10.236.82.20:8093/query/service: dial tcp 10.236.82.20:8093: connectex: No connection could be made because the target machine actively refused it.

@jsb oh that’s a good point. If you run in docker you should make sure to run it as described in this doc: https://docs.couchbase.com/server/current/install/getting-started-docker.html#section_jvt_zvj_42b

The SDK expects it to be running at certain ports when connecting.

Hi @daschl, it is looking like a networking issue: if I copy my client program to a container in the OpenShift environment (note, not the one running the Couchbase server, as it does not have Java installed) and run it, there is no error.

Yeah that could be - it is a bit tricky with port configurations to communicate from inside to outside and vice versa. If you are inside the OpenShift environment I think it is easier. Does this setup work for you now?

Hi @daschl, I am still chipping away at this :-). In a different OpenShift environment, we have Couchbase server 6.5.1 running, with the analytics service enabled, but for some reason only ports 8091-9094 are open. My client, running from another container in the same environment, fails with the “waitUntilReady timed out” exception. My suspicion is that the SDK learns from the server that the analytics service is running and tries to connect to it… With the log level set to DEBUG, I see things like:

2020-09-23 02:39:14,121 [ cb-events] request DEBUG [com.couchbase.request][RequestRetryScheduledEvent][500ms] Request AnalyticsPingRequest retry scheduled per RetryStrategy (Reason: ENDPOINT_NOT_AVAILABLE) {"completed":false,"coreId":"0x2afe9c3e00000001","idempotent":true,"requestId":4,"requestType":"AnalyticsPingRequest","retried":33,"retryReasons":["ENDPOINT_NOT_AVAILABLE","ENDPOINT_TEMPORARILY_NOT_AVAILABLE"],"service":{"target":"couchbase","type":"analytics"},"timeoutMs":20000}

However, the final timeout message does not make it clear whether this is the cause of the timeout or whether there is some other issue. Any thoughts?

In the meantime, I will try to get port 8095 opened to see whether that solves the problem.

Many thanks for your help!

Hi both! Assuming this is using the Couchbase Operator, all of the networking options are documented. Public Networking with TLS is a little involved to set up, but it works really well with applications running outside OpenShift if that’s what you need.

If you’re specifically trying to poke open particular ports, that’s probably not the right approach. In general, the Operator will do that for you based on the exposed services. Have a look there and see if that helps.

I do not believe that we’re using Couchbase Operator (this is the first time I have heard of it).
Another data point: a client program using version 2.7 of the SDK does not fail.
The container holding the Couchbase server appears to be incorrectly configured but it is not clear, from the error message, that this is what is causing the SDK 3.0 client program to fail (given that the SDK 2.7 client program does not fail).

Chances are this has something to do with how you’re exposing Couchbase from OpenShift to the external network. If you’re not using the Couchbase Autonomous Operator or one of it’s approaches, then it’s really down to how you set things up. At a basic level, the error message:

Means the SDK cannot make a TCP connection to the service at the hostname/port number in the configuration.

This SDK 2.7 version of the app, does it also contact analytics?

Any time you’re having connectivity issues, it’d be good to diagnostically check for lower level details with SDK doctor. Maybe try running it in that env? It may not find anything, but it will validate that common connectivity problems aren’t there.

You’ll find pre-built binaries on the release page.

Usually the summary at the end is pretty easy to interpret. If you need help with interpretation, please feel free to post it or a link to it here.