Timeouts with Couchbase Java SDK 2.2.6

Java SDK
1

I’ve got a library, based on the Java client that passes all tests on the 2.2.5 client. As soon as I upgrade to the 2.2.6 client, all my tests fail.

I realize this may not be a trivial thing to reproduce, so I will be putting together a duplicator of this if there’s no responses before… The amount of time for me to get to that and do it.

Here’s a trace as to what’s going on:
/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/bin/java -ea -Didea.launcher.port=7533 "-Didea.launcher.bin.path=/Applications/IntelliJ IDEA.app/Contents/bin" -Didea.junit.sm_runner -Dfile.encoding=UTF-8 -classpath "/Applications/IntelliJ IDEA.app/Contents/lib/idea_rt.jar:/Applications/IntelliJ IDEA.app/Contents/plugins/junit/lib/junit-rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/tools.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/jfxswt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/cldrdata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/nashorn.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Users/unhuman/mycompany.git/com/our-library/target/test-classes:/Users/unhuman/mycompany.git/com/our-library/target/classes:/Users/unhuman/.m2/repository/com/couchbase/client/java-client/2.2.6/java-client-2.2.6.jar:/Users/unhuman/.m2/repository/com/couchbase/client/core-io/1.2.7/core-io-1.2.7.jar:/Users/unhuman/.m2/repository/io/reactivex/rxjava/1.0.17/rxjava-1.0.17.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/datatype/jackson-datatype-jsr310/2.3.3/jackson-datatype-jsr310-2.3.3.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/core/jackson-core/2.3.3/jackson-core-2.3.3.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.3.3/jackson-databind-2.3.3.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.3.0/jackson-annotations-2.3.0.jar:/Users/unhuman/.m2/repository/commons-codec/commons-codec/1.6/commons-codec-1.6.jar:/Users/unhuman/.m2/repository/org/apache/httpcomponents/httpcore/4.3.2/httpcore-4.3.2.jar:/Users/unhuman/.m2/repository/org/apache/httpcomponents/httpcore-nio/4.3.2/httpcore-nio-4.3.2.jar:/Users/unhuman/.m2/repository/org/apache/httpcomponents/httpclient/4.3.4/httpclient-4.3.4.jar:/Users/unhuman/.m2/repository/com/github/fge/json-schema-validator/2.2.5/json-schema-validator-2.2.5.jar:/Users/unhuman/.m2/repository/com/github/fge/json-schema-core/1.2.4/json-schema-core-1.2.4.jar:/Users/unhuman/.m2/repository/com/github/fge/uri-template/0.9/uri-template-0.9.jar:/Users/unhuman/.m2/repository/com/github/fge/msg-simple/1.1/msg-simple-1.1.jar:/Users/unhuman/.m2/repository/com/github/fge/btf/1.2/btf-1.2.jar:/Users/unhuman/.m2/repository/com/github/fge/jackson-coreutils/1.8/jackson-coreutils-1.8.jar:/Users/unhuman/.m2/repository/org/mozilla/rhino/1.7R4/rhino-1.7R4.jar:/Users/unhuman/.m2/repository/joda-time/joda-time/2.3/joda-time-2.3.jar:/Users/unhuman/.m2/repository/com/googlecode/libphonenumber/libphonenumber/6.0/libphonenumber-6.0.jar:/Users/unhuman/.m2/repository/javax/mail/mailapi/1.4.3/mailapi-1.4.3.jar:/Users/unhuman/.m2/repository/javax/activation/activation/1.1/activation-1.1.jar:/Users/unhuman/.m2/repository/net/sf/jopt-simple/jopt-simple/4.6/jopt-simple-4.6.jar:/Users/unhuman/.m2/repository/io/dropwizard/dropwizard-lifecycle/0.7.1.3/dropwizard-lifecycle-0.7.1.3.jar:/Users/unhuman/.m2/repository/org/slf4j/slf4j-api/1.7.6/slf4j-api-1.7.6.jar:/Users/unhuman/.m2/repository/com/google/guava/guava/17.0/guava-17.0.jar:/Users/unhuman/.m2/repository/org/eclipse/jetty/jetty-server/9.0.7.v20131107/jetty-server-9.0.7.v20131107.jar:/Users/unhuman/.m2/repository/org/eclipse/jetty/jetty-http/9.0.7.v20131107/jetty-http-9.0.7.v20131107.jar:/Users/unhuman/.m2/repository/org/eclipse/jetty/jetty-io/9.0.7.v20131107/jetty-io-9.0.7.v20131107.jar:/Users/unhuman/.m2/repository/io/dropwizard/dropwizard-util/0.7.1.3/dropwizard-util-0.7.1.3.jar:/Users/unhuman/.m2/repository/com/google/code/findbugs/jsr305/2.0.3/jsr305-2.0.3.jar:/Users/unhuman/.m2/repository/io/dropwizard/dropwizard-jersey/0.7.1.3/dropwizard-jersey-0.7.1.3.jar:/Users/unhuman/.m2/repository/io/dropwizard/dropwizard-jackson/0.7.1.3/dropwizard-jackson-0.7.1.3.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/datatype/jackson-datatype-guava/2.3.3/jackson-datatype-guava-2.3.3.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/module/jackson-module-afterburner/2.3.3/jackson-module-afterburner-2.3.3.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/datatype/jackson-datatype-joda/2.3.3/jackson-datatype-joda-2.3.3.jar:/Users/unhuman/.m2/repository/ch/qos/logback/logback-classic/1.1.2/logback-classic-1.1.2.jar:/Users/unhuman/.m2/repository/io/dropwizard/dropwizard-validation/0.7.1.3/dropwizard-validation-0.7.1.3.jar:/Users/unhuman/.m2/repository/org/hibernate/hibernate-validator/5.1.1.Final/hibernate-validator-5.1.1.Final.jar:/Users/unhuman/.m2/repository/javax/validation/validation-api/1.1.0.Final/validation-api-1.1.0.Final.jar:/Users/unhuman/.m2/repository/org/jboss/logging/jboss-logging/3.1.3.GA/jboss-logging-3.1.3.GA.jar:/Users/unhuman/.m2/repository/com/fasterxml/classmate/1.0.0/classmate-1.0.0.jar:/Users/unhuman/.m2/repository/org/glassfish/web/javax.el/2.2.6/javax.el-2.2.6.jar:/Users/unhuman/.m2/repository/javax/el/javax.el-api/2.2.5/javax.el-api-2.2.5.jar:/Users/unhuman/.m2/repository/io/dropwizard/dropwizard-logging/0.7.1.3/dropwizard-logging-0.7.1.3.jar:/Users/unhuman/.m2/repository/com/codahale/metrics/metrics-logback/3.0.2/metrics-logback-3.0.2.jar:/Users/unhuman/.m2/repository/org/slf4j/jul-to-slf4j/1.7.6/jul-to-slf4j-1.7.6.jar:/Users/unhuman/.m2/repository/ch/qos/logback/logback-core/1.1.2/logback-core-1.1.2.jar:/Users/unhuman/.m2/repository/org/slf4j/log4j-over-slf4j/1.7.6/log4j-over-slf4j-1.7.6.jar:/Users/unhuman/.m2/repository/org/slf4j/jcl-over-slf4j/1.7.6/jcl-over-slf4j-1.7.6.jar:/Users/unhuman/.m2/repository/org/eclipse/jetty/jetty-util/9.0.7.v20131107/jetty-util-9.0.7.v20131107.jar:/Users/unhuman/.m2/repository/org/eclipse/jetty/orbit/javax.servlet/3.0.0.v201112011016/javax.servlet-3.0.0.v201112011016.jar:/Users/unhuman/.m2/repository/com/sun/jersey/jersey-core/1.18.1/jersey-core-1.18.1.jar:/Users/unhuman/.m2/repository/com/sun/jersey/jersey-server/1.18.1/jersey-server-1.18.1.jar:/Users/unhuman/.m2/repository/com/sun/jersey/jersey-servlet/1.18.1/jersey-servlet-1.18.1.jar:/Users/unhuman/.m2/repository/com/codahale/metrics/metrics-jersey/3.0.2/metrics-jersey-3.0.2.jar:/Users/unhuman/.m2/repository/com/codahale/metrics/metrics-core/3.0.2/metrics-core-3.0.2.jar:/Users/unhuman/.m2/repository/com/codahale/metrics/metrics-annotation/3.0.2/metrics-annotation-3.0.2.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/jaxrs/jackson-jaxrs-json-provider/2.3.3/jackson-jaxrs-json-provider-2.3.3.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/jaxrs/jackson-jaxrs-base/2.3.3/jackson-jaxrs-base-2.3.3.jar:/Users/unhuman/.m2/repository/com/fasterxml/jackson/module/jackson-module-jaxb-annotations/2.3.3/jackson-module-jaxb-annotations-2.3.3.jar:/Users/unhuman/.m2/repository/com/codahale/metrics/metrics-healthchecks/3.0.2/metrics-healthchecks-3.0.2.jar:/Users/unhuman/.m2/repository/junit/junit/4.11/junit-4.11.jar:/Users/unhuman/.m2/repository/org/hamcrest/hamcrest-core/1.3/hamcrest-core-1.3.jar:/Users/unhuman/.m2/repository/org/easytesting/fest-assert-core/2.0M10/fest-assert-core-2.0M10.jar:/Users/unhuman/.m2/repository/org/easytesting/fest-util/1.2.5/fest-util-1.2.5.jar:/Users/unhuman/.m2/repository/org/apache/commons/commons-lang3/3.0/commons-lang3-3.0.jar" com.intellij.rt.execution.application.AppMain com.intellij.rt.execution.junit.JUnitStarter -ideVersion5 com.mycompany.couch.CouchbaseDAOTest 10:18:36.473 [main] DEBUG c.c.client.java.CouchbaseCluster - Returning still open, cached bucket "default" 10:18:38.975 [main] ERROR com.mycompany.couch.CouchbaseDAO - Unable to forceDeleteByKey: [Local::OurLibraryTest::couchbaseTestEntity::testForceUpdateItemDNE] 10:18:38.998 [main] DEBUG c.c.client.java.CouchbaseCluster - Returning still open, cached bucket "default" 10:18:41.527 [main] ERROR com.mycompany.couch.CouchbaseDAO - could not force upsert document: Local::OurLibraryTest::couchbaseTestEntity::testForceUpdateItemDNE java.lang.RuntimeException: java.util.concurrent.TimeoutException at com.couchbase.client.java.util.Blocking.blockForSingle(Blocking.java:75) ~[java-client-2.2.6.jar:na] at com.couchbase.client.java.CouchbaseBucket.upsert(CouchbaseBucket.java:359) ~[java-client-2.2.6.jar:na] at com.couchbase.client.java.CouchbaseBucket.upsert(CouchbaseBucket.java:354) ~[java-client-2.2.6.jar:na] at com.mycompany.couch.CouchbaseDAO.forceUpdate(CouchbaseDAO.java:259) ~[classes/:na] at com.mycompany.couch.CouchbaseDAOTest.testForceUpdateItemDNE(CouchbaseDAOTest.java:136) [test-classes/:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_31] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_31] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_31] at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_31] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [junit-4.11.jar:na] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.11.jar:na] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [junit-4.11.jar:na] at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [junit-4.11.jar:na] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) [junit-4.11.jar:na] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) [junit-4.11.jar:na] at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [junit-4.11.jar:na] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [junit-4.11.jar:na] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [junit-4.11.jar:na] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) [junit-4.11.jar:na] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) [junit-4.11.jar:na] at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na] at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [junit-4.11.jar:na] at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:119) [junit-rt.jar:na] at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:42) [junit-rt.jar:na] at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234) [junit-rt.jar:na] at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74) [junit-rt.jar:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_31] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_31] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_31] at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_31] at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144) [idea_rt.jar:na]

2

Here’s the source for my test.

Interestingly, this fails 100% of the time with “localhost” but if I pick a different cluster, it seems to function properly.

Pretty simple and fails in 2.2.6, works with 2.2.5:

@Test
public void CouchbaseClientTest() {
    List<String> nodes = Collections.singletonList("localhost");
    CouchbaseCluster client = CouchbaseCluster.create(nodes);
    Bucket bucket = client.openBucket("default");
    Document document = StringDocument.create("Test Document", 10000, "This is a test of String");
    bucket.upsert(document);
}

The output of the above is:
/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/bin/java -ea -Didea.launcher.port=7534 “-Didea.launcher.bin.path=/Applications/IntelliJ IDEA.app/Contents/bin” -Didea.junit.sm_runner -Dfile.encoding=UTF-8 -classpath “/Applications/IntelliJ IDEA.app/Contents/lib/idea_rt.jar:/Applications/IntelliJ IDEA.app/Contents/plugins/junit/lib/junit-rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/lib/tools.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/jfxswt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/cldrdata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/nashorn.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_31.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Users/human/code/cb226timeouts/target/test-classes:/Users/human/.m2/repository/com/couchbase/client/java-client/2.2.6/java-client-2.2.6.jar:/Users/human/.m2/repository/com/couchbase/client/core-io/1.2.7/core-io-1.2.7.jar:/Users/human/.m2/repository/io/reactivex/rxjava/1.0.17/rxjava-1.0.17.jar:/Users/human/.m2/repository/junit/junit/4.11/junit-4.11.jar:/Users/human/.m2/repository/org/hamcrest/hamcrest-core/1.3/hamcrest-core-1.3.jar” com.intellij.rt.execution.application.AppMain com.intellij.rt.execution.junit.JUnitStarter -ideVersion5 com.mycompany.CouchbaseClientTest,CouchbaseClientTest
May 02, 2016 3:20:57 PM com.couchbase.client.core.CouchbaseCore
INFO: CouchbaseEnvironment: {sslEnabled=false, sslKeystoreFile=‘null’, sslKeystorePassword=‘null’, queryEnabled=false, queryPort=8093, bootstrapHttpEnabled=true, bootstrapCarrierEnabled=true, bootstrapHttpDirectPort=8091, bootstrapHttpSslPort=18091, bootstrapCarrierDirectPort=11210, bootstrapCarrierSslPort=11207, ioPoolSize=8, computationPoolSize=8, responseBufferSize=16384, requestBufferSize=16384, kvServiceEndpoints=1, viewServiceEndpoints=1, queryServiceEndpoints=1, searchServiceEndpoints=1, ioPool=NioEventLoopGroup, coreScheduler=CoreScheduler, eventBus=DefaultEventBus, packageNameAndVersion=couchbase-java-client/2.2.6 (git: 2.2.6, core: 1.2.7), dcpEnabled=false, retryStrategy=BestEffort, maxRequestLifetime=75000, retryDelay=ExponentialDelay{growBy 1.0 MICROSECONDS, powers of 2; lower=100, upper=100000}, reconnectDelay=ExponentialDelay{growBy 1.0 MILLISECONDS, powers of 2; lower=32, upper=4096}, observeIntervalDelay=ExponentialDelay{growBy 1.0 MICROSECONDS, powers of 2; lower=10, upper=100000}, keepAliveInterval=30000, autoreleaseAfter=2000, bufferPoolingEnabled=true, tcpNodelayEnabled=true, mutationTokensEnabled=false, socketConnectTimeout=1000, dcpConnectionBufferSize=20971520, dcpConnectionBufferAckThreshold=0.2, dcpConnectionName=dcp/core-io, callbacksOnIoPool=false, queryTimeout=75000, viewTimeout=75000, kvTimeout=2500, connectTimeout=5000, disconnectTimeout=25000, dnsSrvEnabled=false}
May 02, 2016 3:20:58 PM com.couchbase.client.core.endpoint.AbstractEndpoint$2 operationComplete
WARNING: [null][KeyValueEndpoint]: Authentication Failure.
May 02, 2016 3:20:58 PM com.couchbase.client.core.config.DefaultConfigurationProvider$8 call
INFO: Opened bucket default

java.lang.RuntimeException: java.util.concurrent.TimeoutException

    at com.couchbase.client.java.util.Blocking.blockForSingle(Blocking.java:75)
    at com.couchbase.client.java.CouchbaseBucket.upsert(CouchbaseBucket.java:359)
    at com.couchbase.client.java.CouchbaseBucket.upsert(CouchbaseBucket.java:354)
    at com.mycompany.CouchbaseClientTest.CouchbaseClientTest(CouchbaseClientTest.java:23)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:483)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:160)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:119)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:42)
    at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234)
    at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:483)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144)
Caused by: java.util.concurrent.TimeoutException
    ... 31 more


Process finished with exit code 255
3

What version & build of Couchbase Server are you using on localhost and remote cluster, respectively?

4

Localhost: Version: 4.5.0-1308 Enterprise Edition (build-1308) - on Mac
Remote: Version: 4.1.0-5005 Enterprise Edition (build-5005) - Centos 6.5

5

These lines seem relevant too. I don’t know of any changes to the library that would cause an auth failure though.

6

Can you try with Couchbase 4.5 BETA?
It’s freshly out and build 1308 is an old one (not even dev preview)…

7

Yep, I found the error boggling.

As requested by @simonbasle, I tried with 4.5 beta and it’s fine.

1 Like
8

FYI - I had this just occur with 2.2.6 against
Version: 4.1.0-5005 Enterprise Edition (build-5005)
Cluster State ID: 036-080-81

2.2.6 was working fine for weeks and then all of a sudden decided to not work any more.

Upgraded to 2.2.7 and the problem went away.

I’m getting pretty convinced that 2.2.6 is problematic.

9

Meh. Just had the same issue with 2.2.7.

Investigating further.

10

Hey @unhuman

We recently found an issue introduced in 2.2.6 that has caused timeouts in some users’ codebase. This is related to a change in the underlying Netty configuration we made that had the side effect of not sending keep alive messages anymore.

Would it be possible that your network is also somehow configured to drop idle connections, and that regression in keep alive in the SDK causes a drop, and these timeouts, to happen?

The bug has been fixed and there should be a 2.2.8 release this week.

11

Excellent. When I was having problems with it locally and initially reported the problem with 2.2.6, there was nothing like that, it was local.

When we noticed the problem again, in our CI platform, an upgrade to 2.2.7 temporarily corrected the problem, but then it recurred. Generally, when that problem occurs, the system is under high load (CPU) and so that could mesh with your timeout theories.

Additionally, we seem to notice timeouts in 2.2.5 when the system is memory constrained (essentially out of memory on the Java processes). Certainly not an ideal way to surface that error, but we are definitely in “unknown behavior” territory sometimes with that.

BTW, the bug notes v1.2.x and not v2.2.x.

Thanks though. This is a great help to us!

-H

12

that was just a theory though… if the system is constantly under high load, it wouldn’t manifest. But if there is an off-peak, where the connections are idle and end up dropped due to the bug, then when workload resumes later on you’d see timeouts due to this bug.

This is a bug in the core-io layer underneath the SDK, so its numbering is different: 1.2.9 is the artifact that’ll get shipped with SDK 2.2.8.

13

In our CI env, the initial request to connect times out. Other processes are doing a lot of work and this one attempts to connect to Couchbase at startup and times out.