openBucket fails with password mismatch, next openBucket request (for a different/valid bucket) times out

Java SDK
1

This is very similar to a post made back in April 2015
TimeoutException trying to open a Bucket after a InvalidPasswordException

We are using CouchbaseServer 4.1.1-5914, and as shown in the Couchbase Environment below, we are using couchbase-java-client-2.2.8 and couchbase-io-core-1.2.9

Did the fix for the post/issue back in April 2015 get inadvertantly removed in the recent version of the jar files?

Thanks

Below are the logs showing the issue:

Jul 26, 2016 9:43:04 AM 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=3, computationPoolSize=3, responseBufferSize=16384, requestBufferSize=16384, kvServiceEndpoints=2, viewServiceEndpoints=2, queryServiceEndpoints=2, searchServiceEndpoints=1, ioPool=NioEventLoopGroup, coreScheduler=CoreScheduler, eventBus=DefaultEventBus, packageNameAndVersion=couchbase-java-client/2.2.8 (git: 2.2.8, core: 1.2.9), 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=true, 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}

(bwdyn openBucket is successful)
Invoking bucketProxy for schemaInstance bwdyn
Jul 26, 2016 9:43:04 AM com.couchbase.client.core.node.CouchbaseNode signalConnected
INFO: Connected to Node 10.16.168.105
Jul 26, 2016 9:43:04 AM com.couchbase.client.core.config.DefaultConfigurationProvider$8 call
INFO: Opened bucket bwdyn
Number of Buckets Added for bwdyn = 1

(bwecl openBucket fails due to password mismatch, which is correct)
Invoking bucketProxy for schemaInstance bwecl
Jul 26, 2016 9:43:04 AM com.couchbase.client.core.endpoint.AbstractEndpoint$2 operationComplete
WARNING: [null][KeyValueEndpoint]: Authentication Failure.
Jul 26, 2016 9:43:04 AM com.couchbase.client.core.endpoint.AbstractEndpoint$2 operationComplete
WARNING: [null][KeyValueEndpoint]: Authentication Failure.
Jul 26, 2016 9:43:04 AM com.couchbase.client.core.endpoint.ResponseStatusConverter fromHttp
WARNING: Unknown ResponseStatus with Protocol HTTP: 401
Jul 26, 2016 9:43:04 AM com.couchbase.client.core.endpoint.ResponseStatusConverter fromHttp
WARNING: Unknown ResponseStatus with Protocol HTTP: 401
Failed to get bucket for bwecl, cause = com.couchbase.client.java.error.InvalidPasswordException: Passwords for bucket “bwecl” do not match.
Number of Buckets Added for bwecl = 0

(bwsub openBucket request is attempted twice, and both time out)
Invoking bucketProxy for schemaInstance bwsub
Caught Timeout Exception during open bucket, retrying Bucket for: bwsub
Caught Timeout Exception during open bucket, retrying Bucket for: bwsub
Number of Buckets Added for bwsub = 0

(openBucket for bwsub is then attempted on a new CouchbaseCluster.create(…) connection, and then it works - as it should)
getPreferredBucket was null for schemaInstance bwsub
Jul 26, 2016 9:43:14 AM com.couchbase.client.core.CouchbaseCore
Calling Test openBucket for instance: bwsub
Jul 26, 2016 9:43:14 AM com.couchbase.client.core.node.CouchbaseNode signalConnected
INFO: Connected to Node 10.16.168.105
Jul 26, 2016 9:43:14 AM com.couchbase.client.core.config.DefaultConfigurationProvider$8 call
INFO: Opened bucket bwsub
Jul 26, 2016 9:43:14 AM com.couchbase.client.core.config.DefaultConfigurationProvider$11 call
INFO: Closed bucket bwsub
Jul 26, 2016 9:43:14 AM com.couchbase.client.core.node.CouchbaseNode signalDisconnected
INFO: Disconnected from Node 10.16.168.105

2

hi @amckinzie
We were able to reproduce that issue, and we’re now looking into it. Unfortunately we didn’t get to the bottom of this yet :disappointed:

3

I am seeing same issue with Couchbase 4.5 and Java Client 2.3.1

Any update?

4

Dang I was able to reproduce the issue at some point, but now I cannot :frowning:

Are you able to repro it consistently in a self-contained unit test, preferably using sample buckets?
If so, would you mind sharing the steps to trigger the issue?

I wonder if things like having an actual password on the bucket factors in…

5

Simon,

Yes, I can (could) easily reproduce this issue, and we do have passwords on
all of our buckets.

The problem happens more frequently as the server/VM comes under a load.
Thus to easily reproduce
the issue, we just put the VM under a load while our application was coming
up (and creating connections to each bucket).

I am in the middle of something right now, but I will send you instructions
later today on how we reproduce the problem. (FYI - it is a simple script
(runs on linux) which hogs CPU, and this should allow you to reproduce the
issue as well.)

Thanks,
Alan

6

Sorry, in my earlier response I confused this post with another one (Client intermittently fails to open bucket or connect to a node during bootstrap)

I can easily reproduce this issue, but it does not require anything special (like extra/heavy CPU load that I mentioned in my last post).

As I noted earlier, I have 3 buckets and each has a password configured. When the 2nd bucket (in the list of buckets) has an invalid password configured, then the attempt to connect to the 3rd bucket fails as well.
Would it help you if I enable additional Couchbase Client logs (FINER or FINEST level), and capture that for you?

7

FINEST logs could be interesting yes

8

I have captured the logs with level=FINEST. The log file is about 370KB. How is the best/preferred way for me to get the log file to you?

9

You should be able to upload it here or by direct message if you prefer.

10

Simon,

Attached is the log file which shows an openBucket was attempted with an
invalid password, and then a Timeout for the next openBucket request.

Also, the few lines that start with " DOC: " are output from the
application itself.

Thanks,
Alan

11

:cold_sweat: attachments don’t seem to work when answering to the forum post via email. Can you go and upload the logs via the website?

12

cli.FINEST_logs_9285.txt.zip (30.4 KB)

13

dang, attachments don’t seem to work at all on the forums :frowning:

However, there is a ticket open for that issue: JVMCBC-353. Maybe you can make an attachment there?

If your forum credentials don’t work on the Couchbase JIRA or you cannot make the attachment, please send it to us via email: sdk_dev at the domain couchbase.com (please reference the Java SDK and the issue above)…

Sorry for the trouble!

14

I have just committed a fix for an issue that might cause this behavior. I’m not entirely sure this is the exact same issue as the one you’re seeing. (JVMCBC-361).

@amckinzie @nkapre would you be able to build core-io 1.3.3-SNAPSHOT and java-client 2.3.3-SNAPSHOT from their respective master branches and test that this fixes your bucket opening issues?

15

Simon,

I have not built anything from the master branches before. Are there some
simple instructions on how to do this?

16

It’s just a matter of cloning each repo and using maven, as mentioned in the couchbase-jvm-core README:

git clone https://github.com/couchbase/couchbase-jvm-core.git
cd couchbase-jvm-core
mvn clean install -Dmaven.test.skip=true

cd ..

git clone https://github.com/couchbase/couchbase-java-client.git
cd couchbase-java-client
mvn clean install -Dmaven.test.skip=true

And you should then have the java-client 2.3.3-SNAPSHOT artifact in your local Maven repository.

17

Thanks Simon.

I built the SNAPSHOT jars and replaced my existing jar files. The
new/updated jars corrected the problem :slight_smile:

However I should note that when I start my application I now get over 4500
logs (WARNING) from Couchbase regarding it cannot connect. A couple/few
logs at the Warning level is good to have, but can the rest of these logs
be turned into FINER or FINEST logs?

Thanks for your help,
Alan

2016.08.25 15:19:08:795 EDT | Warn | CouchbaseCore
[null][KeyValueEndpoint]: Authentication Failure.

2016.08.25 15:19:08:802 EDT | Warn | CouchbaseCore
[null][KeyValueEndpoint]: Authentication Failure.

2016.08.25 15:19:08:806 EDT | Warn | CouchbaseCore
[null][KeyValueEndpoint]: Authentication Failure.

2016.08.25 15:19:08:806 EDT | Warn | CouchbaseCore
Error during reconnect:

2016.08.25 15:19:08:806 EDT | Warn | CouchbaseCore
[null][KeyValueEndpoint]: Could not connect to endpoint, retrying with
delay *32 *MILLISECONDS:

2016.08.25 15:19:08:810 EDT | Warn | CouchbaseCore
[null][KeyValueEndpoint]: Authentication Failure.

…

2016.08.25 15:19:08:971 EDT | Warn | CouchbaseCore
[null][KeyValueEndpoint]: Could not connect to endpoint, retrying with
delay *4096 *MILLISECONDS:

2016.08.25 15:19:08:978 EDT | Warn | CouchbaseCore
[null][KeyValueEndpoint]: Authentication Failure.

…

18

Yeah I’ve come across the same issue and we’ll be investigating :spy:
Glad to hear that version seems to fix your issue!
I don’t think it entirely fixes bucket connection issues though, as I’ve since seen a timeout on openBucket once :frowning: