Couchbase 5.5 with IPv6, Protocol family unavailable

connections

#1

Using Couchbase 5.5 (with IPv6) and SDK 2.6.1, the open bucket request fails (eventually) with a Protocol family unavailable error. I am guessing the error stems from using IPv6, but I am unsure of the real root cause?

Below are logs captured from Couchbase during the open bucket request.

2018.07.31 13:22:11:202 EDT
Got instructed to open bucket bwdyn

2018.07.31 13:22:11:204 EDT
Loading Config for bucket bwdyn

2018.07.31 13:22:11:206 EDT
Loading Config for bucket bwdyn

2018.07.31 13:22:11:209 EDT
New Services are enabled

2018.07.31 13:22:11:257 EDT
Got instructed to add Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 13:22:11:258 EDT
Connecting Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 13:22:11:258 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Got instructed to connect.

2018.07.31 13:22:11:261 EDT
Connect finished, registering for use.

2018.07.31 13:22:11:266 EDT
Successfully added Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 13:22:11:267 EDT
Got instructed to add Service BINARY, to Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 13:22:11:267 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Adding Service BINARY

2018.07.31 13:22:11:272 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Adding Service BINARY to registry and connecting it.

2018.07.31 13:22:11:272 EDT
[2620:100:10:2024:10:20:30:40][KeyValueService]: Got instructed to connect.

2018.07.31 13:22:11:278 EDT
Using a connectCallbackGracePeriod of 2000 on Endpoint 2620:100:10:2024:10:20:30:40:11210

2018.07.31 13:22:11:291 EDT
-Dcom.couchbase.client.deps.io.netty.leakDetection.level: simple

2018.07.31 13:22:11:292 EDT
-Dcom.couchbase.client.deps.io.netty.leakDetection.targetRecords: 4

2018.07.31 13:22:11:298 EDT
[2620:100:10:2024:10:20:30:40][KeyValueService]: New number of endpoints is 1

2018.07.31 13:22:11:300 EDT
[2620:100:10:2024:10:20:30:40][KeyValueService]: Connecting Endpoint during Service connect.

2018.07.31 13:22:11:320 EDT
-Dio.netty.threadLocalMap.stringBuilder.initialSize: 1024

2018.07.31 13:22:11:321 EDT
-Dio.netty.threadLocalMap.stringBuilder.maxSize: 4096

2018.07.31 13:22:11:334 EDT
-Dio.netty.allocator.type: unpooled

2018.07.31 13:22:11:334 EDT
-Dio.netty.threadLocalDirectBufferSize: 65536

2018.07.31 13:22:11:334 EDT
-Dio.netty.maxThreadLocalCharBufferSize: 16384

2018.07.31 13:22:11:375 EDT
Unhandled exception during channel connect, ignoring.

2018.07.31 13:22:11:377 EDT
Successfully enabled Service BINARY on Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 13:22:11:377 EDT
Starting to discover config through Carrier Bootstrap

2018.07.31 13:22:13:657 EDT
Received signal to proactively refresh (a maybe outdated) configuration.

2018.07.31 13:22:13:658 EDT
Ignoring outdated signal, since no buckets are open.

[The above 2 messages repeat for the next 1 min and 13 seconds]

2018.07.31 13:23:26:153 EDT
Received signal to proactively refresh (a maybe outdated) configuration.

2018.07.31 13:23:26:153 EDT
Ignoring outdated signal, since no buckets are open.

2018.07.31 13:23:26:398 EDT
Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true} already registered, skipping.

2018.07.31 13:23:26:398 EDT
Successfully added Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 13:23:26:398 EDT
Got instructed to add Service CONFIG, to Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 13:23:26:398 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Adding Service CONFIG

2018.07.31 13:23:26:401 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Adding Service CONFIG to registry and connecting it.

2018.07.31 13:23:26:401 EDT
[2620:100:10:2024:10:20:30:40][ConfigService]: Got instructed to connect.

2018.07.31 13:23:26:402 EDT
Successfully enabled Service CONFIG on Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 13:23:26:402 EDT
Starting to discover config through HTTP Bootstrap

2018.07.31 13:23:26:405 EDT
Using a connectCallbackGracePeriod of 2000 on Endpoint 2620:100:10:2024:10:20:30:40:8091

2018.07.31 13:23:26:420 EDT
-Dcom.couchbase.client.deps.io.netty.buffer.bytebuf.checkAccessible: true

2018.07.31 13:23:26:421 EDT
Loaded default ResourceLeakDetector: com.couchbase.client.deps.io.netty.util.ResourceLeakDetector@318aa5e6

2018.07.31 13:23:26:432 EDT | Warn | CouchbaseCore
Protocol family unavailable: /2620:100:10:2024:10:20:30:40:8091

2018.07.31 13:23:26:433 EDT
Explicitly closing bucket bwdyn after failed open attempt to clean resources.

2018.07.31 13:23:26:433 EDT
Removing bucket bwdyn configuration from known configs.

2018.07.31 13:23:26:433 EDT
Got notified of a new configuration arriving.


#2

Generally “Protocol family unavailable” will indicate the OS/JVM won’t let the client open an IPv6 address. Can you ping6 (that’s IPv6 ping) the host in question from the client machine?


#3

ping6 works/resolves to the Couchbase IPv6 address

xsp-20:/var> ping6 2620:100:10:2024:10:20:30:40
PING 2620:100:10:2024:10:20:30:40(2620:100:10:2024:10:20:30:40) 56 data bytes
64 bytes from 2620:100:10:2024:10:20:30:40: icmp_seq=1 ttl=64 time=0.316 ms
64 bytes from 2620:100:10:2024:10:20:30:40: icmp_seq=2 ttl=64 time=0.335 ms
64 bytes from 2620:100:10:2024:10:20:30:40: icmp_seq=3 ttl=64 time=0.285 ms
64 bytes from 2620:100:10:2024:10:20:30:40: icmp_seq=4 ttl=64 time=0.252 ms
^C
— 2620:100:10:2024:10:20:30:40 ping statistics —
4 packets transmitted, 4 received, 0% packet loss, time 3001ms
rtt min/avg/max/mdev = 0.252/0.297/0.335/0.031 ms


#4

Hm, not that I think it impacts things, but did you use hostnames? Can you get us a log posted somwehere with DEBUG/FINE level details of trying to connect.

Sorry for the trouble-- we definitely test this scenario so I’m not quite sure where the problem is. The higher level of logging will show us what the configuration is being returned from the cluster.


#5

No, I did not use hostnames. I will increase the log level to DEBUG and collect another set of logs.


#6

Below are the DEBUG logs. There is one Unhandled exception (at 2018.07.31 15:48:04:514)?

2018.07.31 15:48:04:275 EDT
CouchbaseEnvironment: {sslEnabled=false, sslKeystoreFile=‘null’, sslTruststoreFile=‘null’, sslKeystorePassword=false, sslTruststorePassword=false, sslKeystore=null, sslTruststore=null, bootstrapHttpEnabled=true, bootstrapCarrierEnabled=true, bootstrapHttpDirectPort=8091, bootstrapHttpSslPort=18091, bootstrapCarrierDirectPort=11210, bootstrapCarrierSslPort=11207, ioPoolSize=3, computationPoolSize=3, responseBufferSize=16384, requestBufferSize=16384, kvServiceEndpoints=1, viewServiceEndpoints=12, queryServiceEndpoints=12, searchServiceEndpoints=12, configPollInterval=2500, configPollFloorInterval=50, networkResolution=NetworkResolution{name=‘auto’}, ioPool=NioEventLoopGroup, kvIoPool=null, viewIoPool=null, searchIoPool=null, queryIoPool=null, analyticsIoPool=null, coreScheduler=CoreScheduler, memcachedHashingStrategy=DefaultMemcachedHashingStrategy, eventBus=DefaultEventBus, packageNameAndVersion=couchbase-java-client/2.6.1 (git: 2.6.1, core: 1.6.1), 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, continuousKeepAliveEnabled=true, keepAliveErrorThreshold=4, keepAliveTimeout=2500, autoreleaseAfter=2000, bufferPoolingEnabled=false, tcpNodelayEnabled=true, mutationTokensEnabled=true, socketConnectTimeout=1000, callbacksOnIoPool=false, disconnectTimeout=25000, requestBufferWaitStrategy=com.couchbase.client.core.env.DefaultCoreEnvironment$4@546285cb, certAuthEnabled=false, coreSendHook=null, forceSaslPlain=false, compressionMinRatio=0.83, compressionMinSize=32, operationTracingEnabled=true, operationTracingServerDurationEnabled=true, tracer=ThresholdLogTracer, orphanResponseReportingEnabled=true, orphanResponseReporter=DefaultOrphanResponseReporter, keyValueServiceConfig=KeyValueServiceConfig{minEndpoints=1, maxEndpoints=1, pipelined=true, idleTime=0}, queryServiceConfig=QueryServiceConfig{minEndpoints=0, maxEndpoints=2, pipelined=false, idleTime=300}, searchServiceConfig=SearchServiceConfig{minEndpoints=0, maxEndpoints=12, pipelined=false, idleTime=300}, viewServiceConfig=ViewServiceConfig{minEndpoints=1, maxEndpoints=2, pipelined=false, idleTime=300}, analyticsServiceConfig=AnalyticsServiceConfig{minEndpoints=0, maxEndpoints=12, pipelined=false, idleTime=300}, queryTimeout=75000, viewTimeout=75000, searchTimeout=75000, analyticsTimeout=75000, kvTimeout=2500, connectTimeout=120000, dnsSrvEnabled=false, propagateParentSpan=true}

2018.07.31 15:48:04:285 EDT
Starting polling with interval 2500ms

2018.07.31 15:48:04:322 EDT
Setting seed hosts to [NetworkAddress{/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}]

2018.07.31 15:48:04:330 EDT
Initializing DB/cluster: couchAll, couchCluster

2018.07.31 15:48:04:341 EDT
Got instructed to open bucket bwdyn

2018.07.31 15:48:04:344 EDT
Loading Config for bucket bwdyn

2018.07.31 15:48:04:346 EDT
Loading Config for bucket bwdyn

2018.07.31 15:48:04:349 EDT
New Services are enabled

2018.07.31 15:48:04:399 EDT
Got instructed to add Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 15:48:04:399 EDT
Connecting Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 15:48:04:399 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Got instructed to connect.

2018.07.31 15:48:04:402 EDT
Connect finished, registering for use.

2018.07.31 15:48:04:404 EDT
Successfully added Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 15:48:04:405 EDT
Got instructed to add Service BINARY, to Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 15:48:04:405 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Adding Service BINARY

2018.07.31 15:48:04:410 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Adding Service BINARY to registry and connecting it.

2018.07.31 15:48:04:411 EDT
[2620:100:10:2024:10:20:30:40][KeyValueService]: Got instructed to connect.

2018.07.31 15:48:04:417 EDT
Using a connectCallbackGracePeriod of 2000 on Endpoint 2620:100:10:2024:10:20:30:40:11210

2018.07.31 15:48:04:431 EDT
-Dcom.couchbase.client.deps.io.netty.leakDetection.level: simple

2018.07.31 15:48:04:431 EDT
-Dcom.couchbase.client.deps.io.netty.leakDetection.targetRecords: 4

2018.07.31 15:48:04:437 EDT
[2620:100:10:2024:10:20:30:40][KeyValueService]: New number of endpoints is 1

2018.07.31 15:48:04:439 EDT
[2620:100:10:2024:10:20:30:40][KeyValueService]: Connecting Endpoint during Service connect.

2018.07.31 15:48:04:439 EDT
State (KeyValueEndpoint) DISCONNECTED -> CONNECTING

2018.07.31 15:48:04:439 EDT
State (EndpointStateZipper) DISCONNECTED -> CONNECTING

2018.07.31 15:48:04:439 EDT
State (KeyValueService) DISCONNECTED -> CONNECTING

2018.07.31 15:48:04:439 EDT
State (ServiceStateZipper) DISCONNECTED -> CONNECTING

2018.07.31 15:48:04:440 EDT
State (CouchbaseNode) DISCONNECTED -> CONNECTING

2018.07.31 15:48:04:458 EDT
-Dio.netty.threadLocalMap.stringBuilder.initialSize: 1024

2018.07.31 15:48:04:458 EDT
-Dio.netty.threadLocalMap.stringBuilder.maxSize: 4096

2018.07.31 15:48:04:471 EDT
-Dio.netty.allocator.type: unpooled

2018.07.31 15:48:04:471 EDT
-Dio.netty.threadLocalDirectBufferSize: 65536

2018.07.31 15:48:04:472 EDT
-Dio.netty.maxThreadLocalCharBufferSize: 16384

2018.07.31 15:48:04:511 EDT
[id: 0x2727b766] REGISTERED

2018.07.31 15:48:04:512 EDT
[id: 0x2727b766] CONNECT(/2620:100:10:2024:10:20:30:40:11210, null)

2018.07.31 15:48:04:514 EDT
Unhandled exception during channel connect, ignoring.

2018.07.31 15:48:04:522 EDT
Successfully enabled Service BINARY on Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 15:48:04:522 EDT
Starting to discover config through Carrier Bootstrap

2018.07.31 15:48:04:526 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100 MICROSECONDS

2018.07.31 15:48:04:528 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100 MICROSECONDS

2018.07.31 15:48:04:528 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100 MICROSECONDS

2018.07.31 15:48:04:531 EDT
[id: 0x2727b766] CLOSE()

2018.07.31 15:48:04:532 EDT
[id: 0x2727b766] UNREGISTERED

2018.07.31 15:48:04:532 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100 MICROSECONDS

2018.07.31 15:48:04:533 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100 MICROSECONDS

2018.07.31 15:48:04:534 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100 MICROSECONDS

2018.07.31 15:48:04:535 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100 MICROSECONDS

2018.07.31 15:48:04:536 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100 MICROSECONDS

2018.07.31 15:48:04:536 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 128 MICROSECONDS

2018.07.31 15:48:04:537 EDT
[null][KeyValueEndpoint]: Not cancelling operations - sent queue is empty.

2018.07.31 15:48:04:539 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 256 MICROSECONDS

2018.07.31 15:48:04:540 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 512 MICROSECONDS

2018.07.31 15:48:04:543 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 1024 MICROSECONDS

2018.07.31 15:48:04:544 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 2048 MICROSECONDS

2018.07.31 15:48:04:547 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 4096 MICROSECONDS

2018.07.31 15:48:04:552 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 8192 MICROSECONDS

2018.07.31 15:48:04:562 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 16384 MICROSECONDS

2018.07.31 15:48:04:580 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 32768 MICROSECONDS

2018.07.31 15:48:04:614 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 65536 MICROSECONDS

2018.07.31 15:48:04:686 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:04:789 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:04:895 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:04:999 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:05:100 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:05:202 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:05:303 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:05:405 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:05:509 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:05:611 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:05:711 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:05:813 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:05:914 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:018 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:119 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:221 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:323 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:424 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:526 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:629 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:729 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:786 EDT
Received signal to proactively refresh (a maybe outdated) configuration.

2018.07.31 15:48:06:786 EDT
Ignoring outdated signal, since no buckets are open.

2018.07.31 15:48:06:833 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:06:933 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:034 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:139 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:240 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:342 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:443 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:546 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:648 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:750 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:851 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:07:952 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:053 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:154 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:254 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:356 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:459 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:561 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:666 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:768 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:869 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:08:971 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:09:074 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:09:176 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:09:277 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

2018.07.31 15:48:09:287 EDT
Received signal to proactively refresh (a maybe outdated) configuration.

2018.07.31 15:48:09:287 EDT
Ignoring outdated signal, since no buckets are open.

2018.07.31 15:48:09:378 EDT
Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@58076d3e, bucket=‘bwdyn’} with a delay of 100000 MICROSECONDS

[The above logs repeat for the next 3 mins and 40 seconds]

    Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@75bead4d, bucket='bwdyn'} with a delay of 100000 MICROSECONDS

2018.07.31 15:51:49:696 EDT

    Retrying GetBucketConfigRequest{observable=rx.subjects.AsyncSubject@75bead4d, bucket='bwdyn'} with a delay of 100000 MICROSECONDS

2018.07.31 15:51:49:798 EDT
Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true} already registered, skipping.

2018.07.31 15:51:49:799 EDT
Successfully added Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 15:51:49:799 EDT
Got instructed to add Service CONFIG, to Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 15:51:49:799 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Adding Service CONFIG

2018.07.31 15:51:49:799 EDT
[2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40]: Adding Service CONFIG to registry and connecting it.

2018.07.31 15:51:49:799 EDT
[2620:100:10:2024:10:20:30:40][ConfigService]: Got instructed to connect.

2018.07.31 15:51:49:801 EDT
Successfully enabled Service CONFIG on Node NetworkAddress{2620:100:10:2024:10:20:30:40/2620:100:10:2024:10:20:30:40, fromHostname=false, reverseDns=true}

2018.07.31 15:51:49:801 EDT
Starting to discover config through HTTP Bootstrap

2018.07.31 15:51:49:801 EDT
Using a connectCallbackGracePeriod of 2000 on Endpoint 2620:100:10:2024:10:20:30:40:8091

2018.07.31 15:51:49:802 EDT
State (EndpointStateZipper) IDLE -> DISCONNECTED

2018.07.31 15:51:49:802 EDT
State (ConfigService) IDLE -> DISCONNECTED

2018.07.31 15:51:49:802 EDT
State (ConfigEndpoint) DISCONNECTED -> CONNECTING

2018.07.31 15:51:49:802 EDT
State (EndpointStateZipper) DISCONNECTED -> CONNECTING

2018.07.31 15:51:49:802 EDT
State (ConfigService) DISCONNECTED -> CONNECTING

2018.07.31 15:51:49:803 EDT
[id: 0x28573ee6] REGISTERED

2018.07.31 15:51:49:804 EDT
[id: 0x28573ee6] CONNECT(/2620:100:10:2024:10:20:30:40:8091, null)

2018.07.31 15:51:49:804 EDT
State (ConfigEndpoint) CONNECTING -> DISCONNECTED

2018.07.31 15:51:49:804 EDT
State (EndpointStateZipper) CONNECTING -> DISCONNECTED

2018.07.31 15:51:49:804 EDT
State (ConfigService) CONNECTING -> DISCONNECTED

2018.07.31 15:51:49:806 EDT
State (EndpointStateZipper) DISCONNECTED -> IDLE

2018.07.31 15:51:49:806 EDT
State (ConfigService) DISCONNECTED -> IDLE

2018.07.31 15:51:49:806 EDT | Warn | CouchbaseCore
Protocol family unavailable: /2620:100:10:2024:10:20:30:40:8091

2018.07.31 15:51:49:806 EDT
Explicitly closing bucket bwdyn after failed open attempt to clean resources.

2018.07.31 15:51:49:807 EDT
Removing bucket bwdyn configuration from known configs.

2018.07.31 15:51:49:807 EDT
Got notified of a new configuration arriving.


#7

Will have a look (or a colleague will) when we can. Nothing immediately jumps out. That doesn’t have the config I’d hoped for, that must be at the deeper FINER/TRACE levels.


#8

Actually, I remembered something else that may help at least validate there aren’t any other problems: sdk-doctor. It may not find anything, but it’s worth a shot.

You’ll find pre-built binaries on the release page. You should be able to just download it to the client machine and run it.

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.


#9

I had seen the use of the SDK Doctor in another post earlier. However, it did not like the connection string I gave it . I tried both of these, with and without brackets:
“diagnose couchbase://[2620:100:10:2024:10:20:30:40]/default -u …”
“diagnose couchbase://2620:100:10:2024:10:20:30:40/default -u …”


#10

Oh, sorry about that. Looking into it, there’s some special connection string handling that seems to be incorrect. It’s not common with the SDK and I guess our IPv6 testing there (which we did before doing the SDKs) was hostname based. Filed an issue to track.


#11

Matt,

Thanks for taking a look at this and filing an issue.

Alan

This email is intended solely for the person or entity to which it is addressed and may contain confidential and/or privileged information. If you are not the intended recipient and have received this email in error, please notify BroadSoft, Inc. immediately by replying to this message, and destroy all copies of this message, along with any attachment, prior to reading, distributing or copying it.

Ce message confidentiel et les éventuelles pièces jointes sont à l’usage exclusif de son ou de sa destinataire. Il est interdit, pour toute autre personne, de le distribuer, d’en dévoiler le contenu ou de le reproduire. Si vous avez reçu cette communication par erreur, veuillez en informer immédiatement l’expéditeur par courrier électronique et détruire l’original de ce message ainsi que toute copie.


#12

I added an entry into /etc/hosts for the Couchbase server, and executed sdk-doctor using that hostname (couchbase-5-5). Below are the results (there was a failure retreiving the cluster information (status code: 401)).

Note: Diagnostics can only provide accurate results when your cluster
is in a stable state. Active rebalancing and other cluster configuration
changes can cause the output of the doctor to be inconsistent or in the
worst cases, completely incorrect.

08:17:25.978 INFO ▒ Parsing connection string couchbase://couchbase-5-5/bwdyn
08:17:25.978 INFO ▒ Connection string was parsed as a potential DNS SRV record
08:17:26.115 INFO ▒ Connection string identifies the following CCCP endpoints:
08:17:26.115 INFO ▒ 1. couchbase-5-5:11210
08:17:26.115 INFO ▒ Connection string identifies the following HTTP endpoints:
08:17:26.115 INFO ▒ 1. couchbase-5-5:8091
08:17:26.115 INFO ▒ Connection string specifies bucket bwdyn
08:17:26.123 WARN ▒ Your connection string specifies only a single host. You should consider adding additional static nodes from your cluster to this list to improve your applications fault-tolerance
08:17:26.123 INFO ▒ Performing DNS lookup for host couchbase-5-5
08:17:26.123 INFO ▒ Bootstrap host couchbase-5-5 refers to a server with the address 2620:100:10:2024:10:20:30:40
08:17:26.123 WARN ▒ Bootstrap host couchbase-5-5 has IPv6 addresses associated. This is not a supported configuration and will likely cause SDK connection errors.
08:17:26.123 INFO ▒ Attempting to connect to cluster via CCCP
08:17:26.124 INFO ▒ Attempting to fetch config via cccp from couchbase-5-5:11210
08:17:26.129 INFO ▒ Identified the following nodes:
08:17:26.129 INFO ▒ [0] couchbase-5-5
08:17:26.129 INFO ▒ moxi: 11211, n1qlSSL: 18093, eventingSSL: 18096
08:17:26.129 INFO ▒ indexHttp: 9102, capi: 8092, projector: 9999
08:17:26.130 INFO ▒ kv: 11210, indexStreamMaint: 9105, indexHttps: 19102
08:17:26.130 INFO ▒ kvSSL: 11207, n1ql: 8093, mgmt: 8091
08:17:26.130 INFO ▒ mgmtSSL: 18091, fts: 8094, ftsSSL: 18094
08:17:26.131 INFO ▒ capiSSL: 18092, eventingAdminPort: 8096, indexAdmin: 9100
08:17:26.131 INFO ▒ indexScan: 9101, indexStreamInit: 9103, indexStreamCatchup: 9104
08:17:26.132 INFO ▒ Fetching config from couchbase-5-5:8091
08:17:26.136 INFO ▒ Failed to retreive cluster information (status code: 401)
08:17:26.138 INFO ▒ Successfully connected to KV service at couchbase-5-5:11210
08:17:26.141 INFO ▒ Successfully connected to MGMT service at couchbase-5-5:8091
08:17:26.142 INFO ▒ Successfully connected to CAPI service at couchbase-5-5:8092
08:17:26.143 INFO ▒ Successfully connected to N1QL service at couchbase-5-5:8093
08:17:26.144 INFO ▒ Successfully connected to FTS service at couchbase-5-5:8094
08:17:26.148 INFO ▒ Memd Nop Pinged couchbase-5-5:11210 10 times, 0 errors, 0ms min, 0ms max, 0ms mean
08:17:26.148 INFO ▒ Diagnostics completed

Summary:
[WARN] Your connection string specifies only a single host. You should consider adding additional static nodes from your cluster to this list to improve your applications fault-tolerance
[WARN] Bootstrap host couchbase-5-5 has IPv6 addresses associated. This is not a supported configuration and will likely cause SDK connection errors.

Found multiple issues, see listing above.


#13

What options are you using on the JVM to run the Java application?


#14

Here are the Diagnostics that are printed out from the Couchbase Core Logs. If you need anything else, please let me know.

2018.08.01 09:05:52:236 EDT | FieldDebug | CouchbaseCore

    Diagnostics {

gc.ps marksweep.collectionCount=2,
gc.ps marksweep.collectionTime=231,
gc.ps scavenge.collectionCount=16,
gc.ps scavenge.collectionTime=244,
heap.pendingFinalize=0,
heap.used=init = 134217728(131072K) used = 69284392(67660K) committed = 240123904(234496K) max = 415760384(406016K),
mem.physical.free=84770816,
mem.physical.total=2457362432,
mem.swap.free=4227768320,
mem.swap.total=4227854336,
mem.virtual.comitted=3221585920,
offHeap.used=init = 2555904(2496K) used = 60562600(59143K) committed = 62324736(60864K) max = -1(-1K),
proc.cpu.time=14130000000,
runtime.name=11393@xsp-20,
runtime.spec=Oracle Corporation/Java Virtual Machine Specification: 1.8,
runtime.startTime=1533128715597,
runtime.sysProperties={awt.toolkit=sun.awt.X11.XToolkit, jdk.tls.rejectClientInitiatedRenegotiation=true, java.specification.version=1.8, com.couchbase.client.deps.io.netty.packagePrefix=com.couchbase.client.deps., sun.cpu.isalist=, sun.jnu.encoding=ISO-8859-1, sun.arch.data.model=64, catalina.useNaming=true, java.vendor.url=http://java.oracle.com/, java.net.preferIPv6Addresses=false, sun.boot.library.path=/usr/local/java/jdk1.8.0_171/jre/lib/amd64, org.apache.catalina.connector.CoyoteAdapter.ALLOW_BACKSLASH=false, sun.java.command=org.apache.catalina.startup.Bootstrap start, xy.nameservice.nCachePolicy=Configured, java.specification.vendor=Oracle Corporation, java.naming.factory.url.pkgs=org.apache.naming, java.home=/usr/local/java/jdk1.8.0_171/jre, org.apache.coyote.USE_CUSTOM_STATUS_MSG_IN_HEADER=false, file.separator=/, line.separator=
, java.vm.specification.vendor=Oracle Corporation, java.specification.name=Java Platform API Specification, xy.nameservice.timeBoundedPoolSize=2, entityExpansionLimit=1024, xy.nameservice.useAdditionalSrvRrs=true, maxNotificationTransmitterInternalQueueSize=1000, package.definition=sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.jasper.,org.apache.naming.,org.apache.tomcat., xy.config.container.name=tomcat, sun.boot.class.path=/usr/local/java/java_base/jre/lib/alpn-boot.jar:/usr/local/java/jdk1.8.0_171/jre/lib/resources.jar:/usr/local/java/jdk1.8.0_171/jre/lib/rt.jar:/usr/local/java/jdk1.8.0_171/jre/lib/sunrsasign.jar:/usr/local/java/jdk1.8.0_171/jre/lib/jsse.jar:/usr/local/java/jdk1.8.0_171/jre/lib/jce.jar:/usr/local/java/jdk1.8.0_171/jre/lib/charsets.jar:/usr/local/java/jdk1.8.0_171/jre/lib/jfr.jar:/usr/local/java/jdk1.8.0_171/jre/classes, java.util.logging.config.file=/usr/local/tomcat/tomcat_base/conf/logging.properties, sun.management.compiler=HotSpot 64-Bit Tiered Compilers, xy.nameservice.nCacheTtlSecs=600, java.runtime.version=1.8.0_171-b25, user.name=work, com.xyz.webcontainer.jvm=true, file.encoding=ISO-8859-1, xy.nameservice.unreachableServerLingerSecs=60, org.apache.catalina.security.SecurityListener.UMASK=0002, org.apache.catalina.STRICT_SERVLET_COMPLIANCE=true, java.io.tmpdir=/usr/local/tomcat/tomcat_base/temp, tomcat.util.scan.StandardJarScanFilter.jarsToScan=log4j-core*.jar,log4j-taglib*.jar, java.version=1.8.0_171, tomcat.util.scan.StandardJarScanFilter.jarsToSkip=bootstrap.jar,commons-daemon.jar,tomcat-juli.jar,annotations-api.jar,el-api.jar,jsp-api.jar,servlet-api.jar,websocket-api.jar,catalina.jar,catalina-ant.jar,catalina-ha.jar,catalina-storeconfig.jar,catalina-tribes.jar,jasper.jar,jasper-el.jar,ecj-.jar,tomcat-api.jar,tomcat-util.jar,tomcat-util-scan.jar,tomcat-coyote.jar,tomcat-dbcp.jar,tomcat-jni.jar,tomcat-websocket.jar,tomcat-i18n-en.jar,tomcat-i18n-es.jar,tomcat-i18n-fr.jar,tomcat-i18n-ja.jar,tomcat-juli-adapters.jar,catalina-jmx-remote.jar,catalina-ws.jar,tomcat-jdbc.jar,tools.jar,commons-beanutils.jar,commons-codec*.jar,commons-collections*.jar,commons-dbcp*.jar,commons-digester*.jar,commons-fileupload*.jar,commons-httpclient*.jar,commons-io*.jar,commons-lang*.jar,commons-logging*.jar,commons-math*.jar,commons-pool*.jar,jstl.jar,taglibs-standard-spec-.jar,geronimo-spec-jaxrpc.jar,wsdl4j*.jar,ant.jar,ant-junit*.jar,aspectj*.jar,jmx.jar,h2*.jar,hibernate*.jar,httpclient*.jar,jmx-tools.jar,jta*.jar,log4j*.jar,mail*.jar,slf4j*.jar,xercesImpl.jar,xmlParserAPIs.jar,xml-apis.jar,junit.jar,junit-.jar,ant-launcher.jar,cobertura-.jar,asm-.jar,dom4j-.jar,icu4j-.jar,jaxen-.jar,jdom-.jar,jetty-.jar,oro-.jar,servlet-api-.jar,tagsoup-.jar,xmlParserAPIs-.jar,xom-.jar, sun.net.inetaddr.ttl=0, java.vm.specification.name=Java Virtual Machine Specification, sun.security.pkcs11.enable-solaris=false, java.awt.printerjob=sun.print.PSPrinterJob, sun.os.patch.level=unknown, sun.net.inetaddr.negative.ttl=0, p=tomcat, java.library.path=/usr/local/xyz/base/lib:/usr/local/TimesTen/tt_base/lib, xy.nameservice.defaultAddressOption=Any, java.vendor=Oracle Corporation, sun.io.unicode.encoding=UnicodeLittle, tomcat.util.buf.StringCache.byte.enabled=true, org.apache.tomcat.util.buf.UDecoder.ALLOW_ENCODED_SLASH=false, file.encoding.pkg=sun.io, xy.nameservice.denyTimeBoundedDuplicateLookups=true, java.class.path=/usr/local/tomcat/tomcat_base/bin/bootstrap.jar:/usr/local/tomcat/tomcat_base/bin/tomcat-juli.jar, java.vm.vendor=Oracle Corporation, xy.nameservice.cachePolicy=Configured, sun.net.spi.nameservice.provider.1=dns,Xyz, user.timezone=America/New_York, os.name=Linux, java.vm.specification.version=1.8, com.couchbase.connectTimeout=120000, oracle.jdbc.timezoneAsRegion=false, sun.java.launcher=SUN_STANDARD, user.country=US, sun.cpu.endian=little, user.home=/var/empty/work, user.language=en, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, package.access=sun.,org.apache.catalina.,org.apache.coyote.,org.apache.jasper.,org.apache.tomcat., hazelcast.logging.class=com.xyz.util.hazelcast.log.HazelcastLoggerFactory, server.loader=, java.naming.factory.initial=org.apache.naming.java.javaURLContextFactory, java.net.preferIPv4Stack=true, path.separator=:, common.loader="${catalina.base}/lib/CommunicationUtility.jar","${catalina.base}/lib","${catalina.base}/lib/.jar","${catalina.home}/lib","${catalina.home}/lib/*.jar", os.version=3.10.0-514.el7.x86_64, java.endorsed.dirs=/usr/local/tomcat/tomcat_base/endorsed, java.runtime.name=Java™ SE Runtime Environment, sun.nio.ch.bugLevel=, java.vm.name=Java HotSpot™ 64-Bit Server VM, java.vendor.url.bug=http://bugreport.sun.com/bugreport/, catalina.home=/usr/local/tomcat/8.0.22a, user.dir=/usr/local/xyz/base/bin, org.apache.catalina.connector.RECYCLE_FACADES=true, os.arch=amd64, xy.nameservice.cacheTtlSecs=86400, catalina.base=/usr/local/tomcat/8.0.22a, shared.loader=, java.util.logging.manager=org.apache.juli.ClassLoaderLogManager, java.vm.info=mixed mode, java.vm.version=25.171-b25, java.ext.dirs=/usr/local/java/jdk1.8.0_171/jre/lib/ext:/usr/java/packages/lib/ext, java.class.version=52.0},
runtime.uptime=36714,
runtime.vm=Oracle Corporation/Java HotSpot™ 64-Bit Server VM: 25.171-b25,
sys.cpu.loadAvg=1.87,
sys.cpu.num=2,
sys.os.arch=amd64,
sys.os.name=Linux,
sys.os.version=3.10.0-514.el7.x86_64,
thread.count=92,
thread.peakCount=93,
thread.startedCount=93
}


#15

These two JVM setting could be causing the issue:

java.net.preferIPv6Addresses=false
java.net.preferIPv4Stack=true

As mention in the net-properties:

java.net.preferIPv4Stack (default: false)
If IPv6 is available on the operating system the underlying native socket will be, by default, an IPv6 socket which lets applications connect to, and accept connections from, both IPv4 and IPv6 hosts. However, in the case an application would rather use IPv4 only sockets, then this property can be set to true. The implication is that it will not be possible for the application to communicate with IPv6 only hosts.

Can you try changing java.net.preferIPv4Stack back to the default of false and see if that addresses the issue.


#16

Thanks, I will give that a try and reply back with the results.


#17

Setting java.net.preferIPv4Stack = false seemed to help, more logs were produced.
From those logs were exceptions stating it could not parse the configuration.
Thus, I deleted my Couchbase Cluster (name = cluster_5.5) and setup a new Couchbase cluster (name = cluster5).
The open bucket requests are now successful.
Thanks for your help :slight_smile:


#18

Great it’s resolved!

Interesting that you only saw the config parsing issue afterwards and also interesting that there is a config parsing issue in general. Hmm.

If you have a suggestion about how we may be able to set up a similar config for testing-- see if we can find an issue, I’d appreciate it.

Related, the sdk-doctor issue is fixed too. We’d added IPv6 support there before the server support was done and clearly missed direct address parsing. It works now with the address you supplied!


#19

The only thing I changed (that I know of) between the 2 cluster configs was the cluster name (from cluster_5.5 to cluster5). Thus, my guess was the “_” or the “.” in the cluster name was causing the config parsing issue?
Thanks again for your help with this.