Java SDK3.1 with TLS connection failing with AmbiguousTimeoutException

Java SDK
,
1

I followed the steps mentioned in below link to enable TLS using java sdk3.1 client. But when I enable the TLS getting AmbiguousTimeoutException where as after disabling the TLS it is working fine.
Please help

https://docs.couchbase.com/server/current/manage/manage-security/configure-client-certificates.html

My sample code is like -

ClusterEnvironment.Builder envBuilder = ClusterEnvironment

  •            .builder().ioEnvironment(IoEnvironment.eventLoopThreadCount(10))//iopoolsize --should roughly correlate with the number of cores available to the JVM*

  •            .timeoutConfig(TimeoutConfig.connectTimeout(Duration.ofMillis(2500))).*

  •            securityConfig(SecurityConfig.enableTls(true).enableHostnameVerification(true).*

  •            trustStore((Paths.get("keystore path")), "****", Optional.empty()));*

ClusterEnvironment env = envBuilder.build();

  •    Cluster cluster = Cluster.connect("CBSIP,*
          *ClusterOptions.clusterOptions("user_name", "bucket_pwd").*

  •                    environment(env));*

Bucket pocDataBucket = cluster.bucket(“bucket_name”);

After this trying to save and get the document.

Exception -

Exception in thread “main” com.couchbase.client.core.error.AmbiguousTimeoutException: UpsertRequest, Reason: TIMEOUT {“cancelled”:true,“completed”:true,“coreId”:“0xd23f0900000001”,“idempotent”:false,“reason”:“TIMEOUT”,“requestId”:2,“requestType”:“UpsertRequest”,“retried”:14,“retryReasons”:[“BUCKET_OPEN_IN_PROGRESS”],“service”:{“bucket”:“ptxdata”,“collection”:"_default",“documentId”:“emp_1”,“opaque”:“0x1”,“scope”:"_default",“type”:“kv”},“timeoutMs”:2500,“timings”:{“encodingMicros”:3940,“totalMicros”:2506667}}

  •    at com.couchbase.client.java.AsyncUtils.block(AsyncUtils.java:51)*

  •    at com.couchbase.client.java.Collection.upsert(Collection.java:417)*

  •    at KnCBSTLSConnectionTest.saveDocument(KnCBSTLSConnectionTest.java:62)*

  •    at KnCBSTLSConnectionTest.main(KnCBSTLSConnectionTest.java:52)*

  •    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:170)*

  •            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.base/java.lang.Thread.run(Thread.java:834)*
2

@Sanjiv if it works without TLS but with TLS it times out, it is very likely that the SDK cannot reach the server on the TLS ports. The port that need to be accessible need to be different (please refer to the documentation for further info).

If you can share logs this would also help to further diagnose the issue.

3

Thank you daschl for the response.
As per the java sdk documentation I am not able to find option to provide port. please guide me if I am missing something here.
Below the complete log from my sample code -

Starting the programe -
[root@CBS-54 1]# java KnCBSTLSConnectionTest
obj{“name”:“Sanjiv”,“address”:“Marathahalli”,“City”:“Bangalore”,“PIN”:“560037”}
Aug 24, 2021 6:04:20 PM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger warn
WARNING: [com.couchbase.config][InsecureSecurityConfigDetectedEvent] Detected a potentially insecure SecurityConfig - Reason: hostname validation is disabled
Aug 24, 2021 6:04:20 PM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.core][DnsSrvLookupFailedEvent][411ms] DNS SRV lookup failed (name not found), trying to bootstrap from given hostname directly.
Aug 24, 2021 6:04:20 PM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.core][CoreCreatedEvent] {“clientVersion”:“3.1.5”,“clientGitHash”:“a2bb5b42”,“coreVersion”:“2.1.5”,“coreGitHash”:“a2bb5b42”,“userAgent”:“couchbase-java/3.1.5 (Linux 3.10.0-1160.21.1.el7.x86_64 amd64; OpenJDK 64-Bit Server VM 11.0.10+9-LTS)”,“maxNumRequestsInRetry”:32768,“ioEnvironment”:{“nativeIoEnabled”:true,“eventLoopThreadCount”:10,“eventLoopGroups”:[“EpollEventLoopGroup”]},“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”:4500,“configIdleRedialTimeoutMs”:300000},“compressionConfig”:{“enabled”:true,“minRatio”:0.83,“minSize”:32},“securityConfig”:{“tlsEnabled”:true,“nativeTlsEnabled”:true,“hostnameVerificationEnabled”:false,“hasTrustCertificates”:false,“trustManagerFactory”:“TrustManagerFactory”,“ciphers”:[]},“timeoutConfig”:{“kvMs”:2500,“kvDurableMs”:10000,“managementMs”:75000,“queryMs”:75000,“viewMs”:75000,“searchMs”:75000,“analyticsMs”:75000,“connectMs”:5000,“disconnectMs”:10000},“loggerConfig”:{“customLogger”:null,“fallbackToConsole”:false,“disableSlf4j”:false,“loggerName”:“CouchbaseLogger”,“diagnosticContextEnabled”:false},“orphanReporterConfig”:{“emitIntervalMs”:10000,“sampleSize”:10,“queueLength”:1024,“enabled”:true},“thresholdRequestTracerConfig”:{“emitIntervalMs”:10000,“sampleSize”:10,“queueLength”:1024,“kvThresholdMs”:500,“queryThresholdMs”:1000,“searchThresholdMs”:1000,“analyticsThresholdMs”:1000,“viewThresholdMs”:1000},“aggregatingMeterConfig”:{“enabled”:false,“emitIntervalMs”:600000},“retryStrategy”:“BestEffortRetryStrategy”,“requestTracer”:“ThresholdRequestTracer”,“meter”:“NoopMeter”,“numRequestCallbacks”:0} {“coreId”:“0x214e3f6e00000001”,“seedNodes”:[{“address”:“prod-CBS-V1.service.1.kodiakptt.com”}]}
Aug 24, 2021 6:04:20 PM com.couchbase.client.core.cnc.LoggingEventConsumer$JdkLogger info
INFO: [com.couchbase.node][NodeConnectedEvent] Node connected {“coreId”:“0x214e3f6e00000001”,“managerPort”:“8091”,“remote”:“prod-CBS-V1.service.1.kodiakptt.com”}
Exception in thread “main” com.couchbase.client.core.error.AmbiguousTimeoutException: UpsertRequest, Reason: TIMEOUT {“cancelled”:true,“completed”:true,“coreId”:“0x214e3f6e00000001”,“idempotent”:false,“reason”:“TIMEOUT”,“requestId”:2,“requestType”:“UpsertRequest”,“retried”:14,“retryReasons”:[“BUCKET_OPEN_IN_PROGRESS”],“service”:{“bucket”:“ptxdata”,“collection”:"_default",“documentId”:“emp_1”,“opaque”:“0x1”,“scope”:"_default",“type”:“kv”},“timeoutMs”:2500,“timings”:{“encodingMicros”:4331,“totalMicros”:2511681}}

  •    at com.couchbase.client.java.AsyncUtils.block(AsyncUtils.java:51)*

  •    at com.couchbase.client.java.Collection.upsert(Collection.java:417)*

  •    at KnCBSTLSConnectionTest.saveDocument(KnCBSTLSConnectionTest.java:62)*

  •    at KnCBSTLSConnectionTest.main(KnCBSTLSConnectionTest.java:52)*

  •    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:170)*

  •            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.base/java.lang.Thread.run(Thread.java:834)*

[root@CBS-54 1]#
Ends here

4

@Sanjiv can you please do a couple things for me to try out:

  • use 3.2.0 sdk
  • enable debug logging
  • use bucket.WaitUntilReady() before sending any kv operations (and set the wait until ready duration to something like 1 minute, and check how long it took) – it should be in the debug logs as well.
5

Hi @daschl

I have changed my code as u suggested and still I can see it is failing,
Attaching the debug enabled log.

I can see SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE error in the logs. Wanted to know is there any possibility of my keystore not having valid certificates.

6

@Sanjiv yeah that is likely. To test this, you can disable the certificate check by using a .trustManager() with the InsecureTrustManagerFactory. Of course this is only to check if your certificates are broken, since it is insecure and will accept any.

7

@daschl
I did not get .trustManager() option but .trustManagerFactory() is available hence I made the changes as below

TrustManagerFactory insecureTrustManagerFac = InsecureTrustManagerFactory.INSTANCE;
ClusterEnvironment.Builder envBuilder = ClusterEnvironment
.builder().ioEnvironment(IoEnvironment.eventLoopThreadCount(10))
.timeoutConfig(TimeoutConfig.connectTimeout(Duration.ofMillis(2500))).
securityConfig(SecurityConfig.enableTls(true).enableHostnameVerification(true).trustManagerFactory(insecureTrustManagerFac));

Still I see handshake failure as below -

Aug 25, 2021 7:53:34 PM com.couchbase.client.core.deps.io.netty.handler.ssl.util.InsecureTrustManagerFactory$1 checkServerTrusted
FINE: Accepting a server certificate: CN=Couchbase Server
Aug 25, 2021 7:53:34 PM com.couchbase.client.core.deps.io.netty.handler.ssl.ReferenceCountedOpenSslEngine shutdownWithError
FINE: SSL_read failed with 1: OpenSSL error: 268436496 error:10000410:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE
Aug 25, 2021 7:53:34 PM com.couchbase.client.core.deps.io.netty.handler.ssl.util.InsecureTrustManagerFactory$1 checkServerTrusted
FINE: Accepting a server certificate: CN=Couchbase Server
Aug 25, 2021 7:53:34 PM com.couchbase.client.core.deps.io.netty.handler.ssl.ReferenceCountedOpenSslEngine shutdownWithError
FINE: SSL_read failed with 1: OpenSSL error: 268436496 error:10000410:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE
Aug 25, 2021 7:53:34 PM com.couchbase.client.core.deps.io.netty.handler.ssl.util.InsecureTrustManagerFactory$1 checkServerTrusted
FINE: Accepting a server certificate: CN=Couchbase Server
Aug 25, 2021 7:53:34 PM com.couchbase.client.core.deps.io.netty.handler.ssl.ReferenceCountedOpenSslEngine shutdownWithError
FINE: SSL_read failed with 1: OpenSSL error: 268436496 error:10000410:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE
Aug 25, 2021 7:53:34 PM com.couchbase.client.core.deps.io.netty.handler.ssl.util.InsecureTrustManagerFactory$1 checkServerTrusted
FINE: Accepting a server certificate: CN=Couchbase Server
Aug 25, 2021 7:53:34 PM com.couchbase.client.core.deps.io.netty.handler.ssl.ReferenceCountedOpenSslEngine shutdownWithError
FINE: SSL_read failed with 1: OpenSSL error: 268436496 error:10000410:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE

8

@Sanjiv which server version are you using? and which jvm version exactly?

9

@daschl we are using server version as Couchbase Server 6.6.2-9588 (EE) and java version is openjdk version “11.0.10” .

10

To rule out any bugs with native IO and native tls, can you try the following:

    ClusterEnvironment env = ClusterEnvironment.builder()
            .ioEnvironment(IoEnvironment.enableNativeIo(false))
            .securityConfig(SecurityConfig.enableNativeTls(false))
            .build();

Also of course add your other tls settings you had.

11

@daschl thank you for your response.
I tried with above configuration but still I see the same exception.
However, after changing the configuration " Require Client Certificate" from Mandatory to Enable in server UI setting it is working fine. (Security → Client Certificate)
In the client certificate username is added as Common Name provided as Subject and I could see the user name in client keystore file also. But still if we set as Mandatory it is not working.
Self signed client certificate imported in keystore is as -

Alias name: selfsigned
Creation date: Sep 1, 2021
Entry type: PrivateKeyEntry
Certificate chain length: 2
Certificate[1]:
Owner: CN=clientuser, OU=People, O=MyCompany, L=None, ST=None, C=UA

But our requirement is to set as Mandatory. Please suggest how to proceed.