Spring-data-couchbase 3.2.7 java.util.concurrent.TimeoutException:

I am upgrading the version of springboot for my project from 1.4.7 to 2.2.7.I used spring-data-couchbase in my project.So the version of spring-data-couchbase would be change form 2.1.11 to 3.2.7 and the version of java-client is 2.7.14.
The project is deployed in the docker container, and the database is deployed in another docker container. I used docker-compose to start these containers,and the database will start first then the project container will start.
These startup scripts and processes have not changed, I just upgraded spring boot and spring-data-couchbase, and the project failed to start. After some minutes, I can restart the project using docker restart cmd. The error message is as follows:

Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [com.couchbase.client.java.Bucket]: Factory method ‘couchbaseClient’ threw exception; nested exception is java.lang.RuntimeException: java.util.concurrent.TimeoutException
at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:185)
at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:651)
… 141 common frames omitted
Caused by: java.lang.RuntimeException: java.util.concurrent.TimeoutException
at com.couchbase.client.core.utils.Blocking.blockForSingle(Blocking.java:74)
at com.couchbase.client.java.CouchbaseCluster.openBucket(CouchbaseCluster.java:349)
at com.couchbase.client.java.CouchbaseCluster.openBucket(CouchbaseCluster.java:333)
at com.couchbase.client.java.CouchbaseCluster.openBucket(CouchbaseCluster.java:322)
at org.springframework.boot.autoconfigure.couchbase.CouchbaseConfiguration.couchbaseClient(CouchbaseConfiguration.java:94)
at org.springframework.boot.autoconfigure.couchbase.CouchbaseConfiguration$$EnhancerBySpringCGLIB$$90b79f9b.CGLIB$couchbaseClient$1()
at org.springframework.boot.autoconfigure.couchbase.CouchbaseConfiguration$$EnhancerBySpringCGLIB$$90b79f9b$$FastClassBySpringCGLIB$$af50cb89.invoke()
at org.springframework.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:244)
at org.springframework.context.annotation.ConfigurationClassEnhancer$BeanMethodInterceptor.intercept(ConfigurationClassEnhancer.java:331)
at org.springframework.boot.autoconfigure.couchbase.CouchbaseConfiguration$$EnhancerBySpringCGLIB$$90b79f9b.couchbaseClient()
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:498)
at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:154)… 142 common frames omitted
Caused by: java.util.concurrent.TimeoutException: null
… 157 common frames omitted
BTW , I found that if I modify this configuration:

spring.couchbase.env.timeouts.connect=10000
The problem will be solved, but I don’t know if there will be other problems if I change this configuration. And when I use 2.1.11 spring-data-couchbase in my project, the timeout error does not appear

Looks like something takes longer to open the bucket in the newer SDK than in the older SDK - one thing to debug this is to get debug logs for both the old and and the new version and see how long the individual phases of the bootstrap take. With the increased timeout, how much slower is the new version over the older?

Thaks for your help.But what should I do to get the debug log? Do you mean should I modify the log level and start the project to get the debug log?

Yes, that would be a good approach I think

The following is the log of the application successfully launched, It can be seen that it takes 5s from initializing the couchbase environment to opening the bucket

2020-07-08 05:35:47.104 INFO 9 — [ main] com.couchbase.client.core.CouchbaseCore : CouchbaseEnvironment: {sslEnabled=false, sslKeystoreFile=‘null’, sslTruststoreFile=‘null’, sslKeystorePassword=false, sslTruststorePassword=false, sslKeystore=null, sslTruststore=null, sslHostnameVerificationEnabled=false, bootstrapHttpEnabled=true, bootstrapCarrierEnabled=true, bootstrapHttpDirectPort=8091, bootstrapHttpSslPort=18091, bootstrapCarrierDirectPort=11210, bootstrapCarrierSslPort=11207, ioPoolSize=4, computationPoolSize=4, 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.7.14 (git: 2.7.14, core: 1.7.14), 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=true, tcpNodelayEnabled=true, mutationTokensEnabled=false, socketConnectTimeout=1000, callbacksOnIoPool=false, disconnectTimeout=25000, requestBufferWaitStrategy=com.couchbase.client.core.env.DefaultCoreEnvironment$4@72cde7cc, certAuthEnabled=false, coreSendHook=null, forceSaslPlain=false, compressionMinRatio=0.83, compressionMinSize=32, compressionEnabled=true, operationTracingEnabled=true, operationTracingServerDurationEnabled=true, tracer=ThresholdLogTracer, orphanResponseReportingEnabled=true, orphanResponseReporter=DefaultOrphanResponseReporter, keyValueServiceConfig=KeyValueServiceConfig{minEndpoints=1, maxEndpoints=1, pipelined=true, idleTime=0}, queryServiceConfig=QueryServiceConfig{minEndpoints=1, maxEndpoints=1, pipelined=false, idleTime=300}, searchServiceConfig=SearchServiceConfig{minEndpoints=0, maxEndpoints=12, pipelined=false, idleTime=300}, viewServiceConfig=ViewServiceConfig{minEndpoints=1, maxEndpoints=1, pipelined=false, idleTime=300}, analyticsServiceConfig=AnalyticsServiceConfig{minEndpoints=0, maxEndpoints=12, pipelined=false, idleTime=300}, queryTimeout=30000, viewTimeout=7500, searchTimeout=75000, analyticsTimeout=75000, kvTimeout=2500, connectTimeout=10000, dnsSrvEnabled=false, propagateParentSpan=true}
2020-07-08 05:35:51.243 INFO 9 — [ cb-io-1-1] com.couchbase.client.core.node.Node : Connected to Node database
2020-07-08 05:35:51.885 INFO 9 — [-computations-4] c.c.c.core.config.ConfigurationProvider : Selected network configuration: default
2020-07-08 05:35:52.030 INFO 9 — [-computations-4] c.c.c.core.config.ConfigurationProvider : Opened bucket testBucket

The following is the log of the application startup error. We can see the application try to connected node database two times,but open bucket failed, I don’t modify anything, I started the program twice, one failed and one succeeded

2020-07-08 05:10:08,344 [main] INFO c.c.client.core.CouchbaseCore 115 - CouchbaseEnvironment: {sslEnabled=false, sslKeystoreFile=‘null’, sslTruststoreFile=‘null’, sslKeystorePassword=false, sslTruststorePassword=false, sslKeystore=null, sslTruststore=null, sslHostnameVerificationEnabled=false, bootstrapHttpEnabled=true, bootstrapCarrierEnabled=true, bootstrapHttpDirectPort=8091, bootstrapHttpSslPort=18091, bootstrapCarrierDirectPort=11210, bootstrapCarrierSslPort=11207, ioPoolSize=4, computationPoolSize=4, 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.7.14 (git: 2.7.14, core: 1.7.14), 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=true, tcpNodelayEnabled=true, mutationTokensEnabled=false, socketConnectTimeout=1000, callbacksOnIoPool=false, disconnectTimeout=25000, requestBufferWaitStrategy=com.couchbase.client.core.env.DefaultCoreEnvironment$4@2f8dad04, certAuthEnabled=false, coreSendHook=null, forceSaslPlain=false, compressionMinRatio=0.83, compressionMinSize=32, compressionEnabled=true, operationTracingEnabled=true, operationTracingServerDurationEnabled=true, tracer=ThresholdLogTracer, orphanResponseReportingEnabled=true, orphanResponseReporter=DefaultOrphanResponseReporter, keyValueServiceConfig=KeyValueServiceConfig{minEndpoints=1, maxEndpoints=1, pipelined=true, idleTime=0}, queryServiceConfig=QueryServiceConfig{minEndpoints=1, maxEndpoints=1, pipelined=false, idleTime=300}, searchServiceConfig=SearchServiceConfig{minEndpoints=0, maxEndpoints=12, pipelined=false, idleTime=300}, viewServiceConfig=ViewServiceConfig{minEndpoints=1, maxEndpoints=1, pipelined=false, idleTime=300}, analyticsServiceConfig=AnalyticsServiceConfig{minEndpoints=0, maxEndpoints=12, pipelined=false, idleTime=300}, queryTimeout=30000, viewTimeout=7500, searchTimeout=75000, analyticsTimeout=75000, kvTimeout=2500, connectTimeout=10000, dnsSrvEnabled=false, propagateParentSpan=true}
2020-07-08 05:10:15,365 [cb-io-1-3] INFO com.couchbase.client.core.node.Node 120 - Connected to Node database
2020-07-08 05:10:17,364 [cb-io-1-3] INFO com.couchbase.client.core.node.Node 120 - Disconnected from Node database
2020-07-08 05:10:19,472 [cb-computations-3] INFO c.c.c.c.config.ConfigurationProvider 120 - Selected network configuration: default
2020-07-08 05:10:19,649 [cb-computations-3] INFO c.c.c.c.config.ConfigurationProvider 120 - Opened bucket testBucket
2020-07-08 05:10:19,978 [cb-io-1-2] INFO com.couchbase.client.core.node.Node 120 - Connected to Node database
2020-07-08 05:10:20,052 [main] INFO o.a.catalina.core.StandardService 173 - Stopping service [Tomcat]

BTW,both times were started with the new version of spring-data-couchbase, when using the old version, it takes about 4s to open the bucket

@Pengpengwang can you please enable DEBUG log? INFO level is not very helpful for the issue at hand - thank you!

@daschl I am confused, when DEBUG logging is enabled, my application starts successfully. Can’t get any useful logs.I am trying to reproduce the error in debug mode

I modify the connectTimeOut value to 5s, then start my application, the timeOut error is reproduced. These logs may be useful

2020-07-08 08:18:47,578 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory 217 - Creating shared instance of singleton bean ‘couchbaseCluster’
2020-07-08 08:18:47,787 [main] DEBUG c.c.client.core.CouchbaseCore 85 - Diagnostics {
gc.ps marksweep.collectionCount=2,
gc.ps marksweep.collectionTime=1623,
gc.ps scavenge.collectionCount=7,
gc.ps scavenge.collectionTime=2711,
heap.pendingFinalize=0,
heap.used=init = 264241152(258048K) used = 139464344(136195K) committed = 649592832(634368K) max = 3739746304(3652096K),
mem.physical.free=9974067200,
mem.physical.total=16825786368,
mem.swap.free=17175666688,
mem.swap.total=17175666688,
mem.virtual.comitted=7280877568,
offHeap.used=init = 2555904(2496K) used = 55028664(53738K) committed = 57606144(56256K) max = -1(-1K),
proc.cpu.time=18150000000,
runtime.name=9@856122b7d7d6,
runtime.spec=Oracle Corporation/Java Virtual Machine Specification: 1.8,
runtime.startTime=1594196292063,
runtime.sysProperties={awt.toolkit=sun.awt.X11.XToolkit, file.encoding.pkg=sun.io, java.specification.version=1.8, com.couchbase.client.deps.io.netty.packagePrefix=com.couchbase.client.deps., sun.cpu.isalist=, sun.jnu.encoding=ANSI_X3.4-1968, java.class.path=/jar/flowgate-api.jar, java.vm.vendor=Oracle Corporation, sun.arch.data.model=64, java.vendor.url=http://java.oracle.com/, catalina.useNaming=false, user.timezone=GMT, os.name=Linux, java.vm.specification.version=1.8, user.country=US, sun.java.launcher=SUN_STANDARD, sun.boot.library.path=/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/amd64, sun.java.command=/jar/flowgate-api.jar, sun.cpu.endian=little, user.home=/root, user.language=en, java.specification.vendor=Oracle Corporation, java.home=/usr/lib/jvm/OpenJDK-1.8.0/jre, file.separator=/, line.separator=
, java.vm.specification.vendor=Oracle Corporation, java.specification.name=Java Platform API Specification, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, java.awt.headless=true, sun.boot.class.path=/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/resources.jar:/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/rt.jar:/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/sunrsasign.jar:/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/jsse.jar:/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/jce.jar:/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/charsets.jar:/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/jfr.jar:/usr/lib/jvm/OpenJDK-1.8.0/jre/classes:/jar, java.protocol.handler.pkgs=org.springframework.boot.loader, sun.management.compiler=HotSpot 64-Bit Tiered Compilers, java.runtime.version=1.8.0-internal-_2020_04_23_16_32-b00, user.name=root, path.separator=:, os.version=4.9.228-1.ph2, java.endorsed.dirs=/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/endorsed, java.runtime.name=OpenJDK Runtime Environment, file.encoding=ANSI_X3.4-1968, spring.beaninfo.ignore=true, sun.nio.ch.bugLevel=, java.vm.name=OpenJDK 64-Bit Server VM, java.vendor.url.bug=http://bugreport.sun.com/bugreport/, java.io.tmpdir=/tmp, catalina.home=/tmp/tomcat.7660262204122551767.49610, java.version=1.8.0-internal, user.dir=/, os.arch=amd64, java.vm.specification.name=Java Virtual Machine Specification, PID=9, java.awt.printerjob=sun.print.PSPrinterJob, sun.os.patch.level=unknown, catalina.base=/tmp/tomcat.7660262204122551767.49610, java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib, java.vm.info=mixed mode, java.vendor=Oracle Corporation, java.vm.version=25.71-b00, java.ext.dirs=/usr/lib/jvm/OpenJDK-1.8.0/jre/lib/ext:/usr/java/packages/lib/ext, sun.io.unicode.encoding=UnicodeLittle, java.class.version=52.0},
runtime.uptime=35878,
runtime.vm=Oracle Corporation/OpenJDK 64-Bit Server VM: 25.71-b00,
sys.cpu.loadAvg=13.37,
sys.cpu.num=4,
sys.os.arch=amd64,
sys.os.name=Linux,
sys.os.version=4.9.228-1.ph2,
thread.count=12,
thread.peakCount=12,
thread.startedCount=14
}
2020-07-08 08:18:47,907 [main] DEBUG c.c.c.c.c.refresher.CarrierRefresher 90 - Starting polling with interval 2500ms
2020-07-08 08:18:48,183 [main] DEBUG c.c.c.c.config.ConfigurationProvider 90 - Setting seed hosts to [database]
2020-07-08 08:18:48,200 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory 217 - Creating shared instance of singleton bean ‘couchbaseClient’
2020-07-08 08:18:48,211 [main] DEBUG c.c.c.c.config.ConfigurationProvider 90 - Got instructed to open bucket flowgate
2020-07-08 08:18:48,303 [main] DEBUG c.c.client.core.config.loader.Loader 90 - Loading Config for bucket flowgate
2020-07-08 08:18:48,404 [main] DEBUG c.c.client.core.config.loader.Loader 90 - Loading Config for bucket flowgate
2020-07-08 08:18:48,507 [main] DEBUG c.c.c.core.service.ServiceFactory 85 - New Services are enabled
2020-07-08 08:18:48,529 [main] DEBUG c.c.client.core.RequestHandler 90 - Got instructed to add Node database
2020-07-08 08:18:48,531 [main] DEBUG c.c.client.core.RequestHandler 85 - Connecting Node database
2020-07-08 08:18:48,533 [main] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Got instructed to connect.
2020-07-08 08:18:48,555 [main] DEBUG c.c.client.core.RequestHandler 85 - Connect finished, registering for use.
2020-07-08 08:18:48,567 [cb-computations-1] DEBUG c.c.client.core.config.loader.Loader 90 - Successfully added Node database
2020-07-08 08:18:48,570 [cb-computations-1] DEBUG c.c.client.core.RequestHandler 95 - Got instructed to add Service BINARY, to Node database
2020-07-08 08:18:48,571 [cb-computations-1] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Adding Service BINARY
2020-07-08 08:18:48,601 [cb-computations-1] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Adding Service BINARY to registry and connecting it.
2020-07-08 08:18:48,605 [cb-computations-1] DEBUG c.c.client.core.service.Service 85 - [database][KeyValueService]: Got instructed to connect.
2020-07-08 08:18:48,693 [cb-computations-1] DEBUG c.c.client.core.endpoint.Endpoint 100 - Using a connectCallbackGracePeriod of 2000 on Endpoint database:11210
2020-07-08 08:18:48,829 [cb-computations-1] DEBUG c.c.c.d.i.n.u.ResourceLeakDetector 130 - -Dcom.couchbase.client.deps.io.netty.leakDetection.level: simple
2020-07-08 08:18:48,829 [cb-computations-1] DEBUG c.c.c.d.i.n.u.ResourceLeakDetector 131 - -Dcom.couchbase.client.deps.io.netty.leakDetection.targetRecords: 4
2020-07-08 08:18:48,849 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 156 - -Dio.netty.allocator.numHeapArenas: 8
2020-07-08 08:18:48,850 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 157 - -Dio.netty.allocator.numDirectArenas: 8
2020-07-08 08:18:48,850 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 159 - -Dio.netty.allocator.pageSize: 8192
2020-07-08 08:18:48,851 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 164 - -Dio.netty.allocator.maxOrder: 11
2020-07-08 08:18:48,851 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 168 - -Dio.netty.allocator.chunkSize: 16777216
2020-07-08 08:18:48,851 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 169 - -Dio.netty.allocator.tinyCacheSize: 512
2020-07-08 08:18:48,852 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 170 - -Dio.netty.allocator.smallCacheSize: 256
2020-07-08 08:18:48,852 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 171 - -Dio.netty.allocator.normalCacheSize: 64
2020-07-08 08:18:48,852 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 172 - -Dio.netty.allocator.maxCachedBufferCapacity: 32768
2020-07-08 08:18:48,853 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 173 - -Dio.netty.allocator.cacheTrimInterval: 8192
2020-07-08 08:18:48,853 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 174 - -Dio.netty.allocator.cacheTrimIntervalMillis: 0
2020-07-08 08:18:48,853 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 175 - -Dio.netty.allocator.useCacheForAllThreads: true
2020-07-08 08:18:48,854 [cb-computations-1] DEBUG c.c.c.d.i.n.b.PooledByteBufAllocator 176 - -Dio.netty.allocator.maxCachedByteBuffersPerChunk: 1023
2020-07-08 08:18:48,987 [cb-computations-1] DEBUG c.c.client.core.service.Service 90 - [database][KeyValueService]: New number of endpoints is 1
2020-07-08 08:18:48,992 [cb-computations-1] DEBUG c.c.client.core.service.Service 85 - [database][KeyValueService]: Connecting Endpoint during Service connect.
2020-07-08 08:18:49,238 [cb-computations-1] DEBUG c.c.c.d.i.n.channel.DefaultChannelId 79 - -Dio.netty.processId: 9 (auto-detected)
2020-07-08 08:18:49,278 [cb-computations-1] DEBUG c.c.c.deps.io.netty.util.NetUtil 139 - -Djava.net.preferIPv4Stack: false
2020-07-08 08:18:49,282 [cb-computations-1] DEBUG c.c.c.deps.io.netty.util.NetUtil 140 - -Djava.net.preferIPv6Addresses: false
2020-07-08 08:18:49,295 [cb-computations-1] DEBUG c.c.c.deps.io.netty.util.NetUtil 224 - Loopback interface: lo (lo, 127.0.0.1)
2020-07-08 08:18:49,315 [cb-computations-1] DEBUG c.c.c.deps.io.netty.util.NetUtil 271 - /proc/sys/net/core/somaxconn: 128
2020-07-08 08:18:49,330 [cb-computations-1] DEBUG c.c.c.d.i.n.channel.DefaultChannelId 101 - -Dio.netty.machineId: 02:42:ac:ff:fe:1b:00:03 (auto-detected)
2020-07-08 08:18:49,684 [cb-computations-1] DEBUG c.c.c.d.io.netty.buffer.ByteBufUtil 86 - -Dio.netty.allocator.type: pooled
2020-07-08 08:18:49,701 [cb-computations-1] DEBUG c.c.c.d.io.netty.buffer.ByteBufUtil 95 - -Dio.netty.threadLocalDirectBufferSize: 0
2020-07-08 08:18:49,701 [cb-computations-1] DEBUG c.c.c.d.io.netty.buffer.ByteBufUtil 98 - -Dio.netty.maxThreadLocalCharBufferSize: 16384
2020-07-08 08:18:50,440 [cb-computations-3] DEBUG c.c.c.c.c.refresher.CarrierRefresher 85 - No bucket open to refresh, ignoring outdated signal.
2020-07-08 08:18:51,008 [cb-io-1-1] DEBUG c.c.c.d.i.n.buffer.AbstractByteBuf 63 - -Dcom.couchbase.client.deps.io.netty.buffer.checkAccessible: true
2020-07-08 08:18:51,009 [cb-io-1-1] DEBUG c.c.c.d.i.n.buffer.AbstractByteBuf 64 - -Dcom.couchbase.client.deps.io.netty.buffer.checkBounds: true
2020-07-08 08:18:51,103 [cb-io-1-1] DEBUG c.c.c.d.i.n.u.ResourceLeakDetectorFactory 195 - Loaded default ResourceLeakDetector: com.couchbase.client.deps.io.netty.util.ResourceLeakDetector@79829e03
2020-07-08 08:18:51,107 [cb-io-1-1] DEBUG c.c.c.c.e.kv.KeyValueFeatureHandler 90 - Requesting supported features: [TCPNODELAY, XATTR, SELECT_BUCKET, TRACING, SNAPPY, XERROR]
2020-07-08 08:18:51,148 [cb-io-1-1] DEBUG c.c.c.deps.io.netty.util.Recycler 97 - -Dio.netty.recycler.maxCapacityPerThread: 4096
2020-07-08 08:18:51,151 [cb-io-1-1] DEBUG c.c.c.deps.io.netty.util.Recycler 98 - -Dio.netty.recycler.maxSharedCapacityFactor: 2
2020-07-08 08:18:51,151 [cb-io-1-1] DEBUG c.c.c.deps.io.netty.util.Recycler 99 - -Dio.netty.recycler.linkCapacity: 16
2020-07-08 08:18:51,151 [cb-io-1-1] DEBUG c.c.c.deps.io.netty.util.Recycler 100 - -Dio.netty.recycler.ratio: 8
2020-07-08 08:18:51,199 [cb-io-1-1] DEBUG c.c.c.c.e.kv.KeyValueFeatureHandler 90 - Negotiated supported features: [TCPNODELAY, XATTR, XERROR, SELECT_BUCKET, SNAPPY]
2020-07-08 08:18:51,200 [cb-io-1-1] DEBUG c.c.c.c.e.kv.KeyValueErrorMapHandler 90 - Requesting error map in version 1
2020-07-08 08:18:51,886 [cb-io-1-1] DEBUG c.c.c.c.e.kv.KeyValueErrorMapHandler 95 - Trying to update Error Map With Version 1, Revision 1.
2020-07-08 08:18:52,317 [RxComputationScheduler-1] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Disconnected (CONNECTING) from Node
2020-07-08 08:18:52,326 [cb-computations-3] DEBUG c.c.client.core.config.loader.Loader 95 - Could not add service on database because of {}, removing it again.
com.couchbase.client.deps.io.netty.channel.ConnectTimeoutException: Connect callback did not return, hit safeguarding timeout.
at com.couchbase.client.core.endpoint.AbstractEndpoint$3.call(AbstractEndpoint.java:413)
at com.couchbase.client.core.endpoint.AbstractEndpoint$3.call(AbstractEndpoint.java:406)
at rx.internal.operators.SingleOperatorOnErrorResumeNext$2.onError(SingleOperatorOnErrorResumeNext.java:69)
at rx.internal.operators.SingleTimeout$TimeoutSingleSubscriber$OtherSubscriber.onError(SingleTimeout.java:133)
at rx.Single$1.call(Single.java:477)
at rx.Single$1.call(Single.java:473)
at rx.Single.subscribe(Single.java:1979)
at rx.Single$18.call(Single.java:2518)
at rx.Single$18.call(Single.java:2505)
at rx.internal.operators.SingleTimeout$TimeoutSingleSubscriber.call(SingleTimeout.java:110)
at rx.internal.schedulers.EventLoopsScheduler$EventLoopWorker$2.call(EventLoopsScheduler.java:189)
at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:55)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
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)
2020-07-08 08:18:52,333 [cb-computations-3] DEBUG c.c.client.core.RequestHandler 95 - Got instructed to remove Service BINARY, from Node database
2020-07-08 08:18:52,333 [cb-computations-3] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Removing Service BINARY
2020-07-08 08:18:52,341 [cb-computations-3] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Disconnected (CONNECTING) from Node
2020-07-08 08:18:52,341 [cb-computations-3] DEBUG c.c.client.core.service.Service 85 - [database][KeyValueService]: Got instructed to disconnect.
2020-07-08 08:18:52,349 [cb-computations-3] DEBUG c.c.client.core.service.Service 90 - [database][KeyValueService]: New number of endpoints is 1
2020-07-08 08:18:52,351 [cb-computations-3] DEBUG c.c.client.core.service.Service 85 - [database][KeyValueService]: Disconnecting Endpoint during Service disconnect.
2020-07-08 08:18:52,433 [cb-io-1-1] DEBUG c.c.c.c.e.AbstractGenericHandler 85 - [database/172.26.0.2:11210][KeyValueEndpoint]: Channel Active.
2020-07-08 08:18:52,466 [cb-computations-4] DEBUG c.c.client.core.RequestHandler 90 - Node database already registered, skipping.
2020-07-08 08:18:52,469 [cb-io-1-1] DEBUG c.c.c.c.e.AbstractGenericHandler 85 - [database/172.26.0.2:11210][KeyValueEndpoint]: Channel Inactive.
2020-07-08 08:18:52,480 [cb-computations-1] DEBUG c.c.client.core.config.loader.Loader 90 - Successfully added Node database
2020-07-08 08:18:52,481 [cb-computations-1] DEBUG c.c.client.core.RequestHandler 95 - Got instructed to add Service CONFIG, to Node database
2020-07-08 08:18:52,481 [cb-computations-1] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Adding Service CONFIG
2020-07-08 08:18:52,485 [cb-io-1-2] DEBUG c.c.c.c.e.kv.KeyValueFeatureHandler 90 - Requesting supported features: [TCPNODELAY, XATTR, SELECT_BUCKET, TRACING, SNAPPY, XERROR]
2020-07-08 08:18:52,495 [cb-computations-1] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Adding Service CONFIG to registry and connecting it.
2020-07-08 08:18:52,495 [cb-computations-1] DEBUG c.c.client.core.service.Service 85 - [database][ConfigService]: Got instructed to connect.
2020-07-08 08:18:52,521 [cb-computations-2] DEBUG c.c.client.core.config.loader.Loader 95 - Successfully enabled Service CONFIG on Node database
2020-07-08 08:18:52,522 [cb-computations-2] DEBUG c.c.c.core.config.loader.HttpLoader 85 - Starting to discover config through HTTP Bootstrap
2020-07-08 08:18:52,525 [cb-io-1-2] DEBUG c.c.c.c.e.kv.KeyValueFeatureHandler 90 - Negotiated supported features: [TCPNODELAY, XATTR, XERROR, SELECT_BUCKET, SNAPPY]
2020-07-08 08:18:52,525 [cb-io-1-2] DEBUG c.c.c.c.e.kv.KeyValueErrorMapHandler 90 - Requesting error map in version 1
2020-07-08 08:18:52,550 [cb-core-3-2] DEBUG c.c.client.core.endpoint.Endpoint 100 - Using a connectCallbackGracePeriod of 2000 on Endpoint database:8091
2020-07-08 08:18:52,562 [cb-core-3-2] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Disconnected (IDLE) from Node
2020-07-08 08:18:52,575 [cb-io-1-2] DEBUG c.c.c.c.e.kv.KeyValueErrorMapHandler 95 - Trying to update Error Map With Version 1, Revision 1.
2020-07-08 08:18:52,827 [cb-io-1-3] DEBUG c.c.client.core.endpoint.Endpoint 85 - [database/172.26.0.2:8091][ConfigEndpoint]: Connected Endpoint.
2020-07-08 08:18:52,835 [cb-io-1-3] DEBUG com.couchbase.client.core.node.Node 85 - [database]: Connected (CONNECTING) to Node
2020-07-08 08:18:52,919 [cb-io-1-2] DEBUG c.c.client.core.endpoint.Endpoint 85 - [database:11210][KeyValueEndpoint]: Endpoint connect completed, but got instructed to disconnect in the meantime.
2020-07-08 08:18:52,922 [cb-io-1-2] DEBUG c.c.c.c.e.AbstractGenericHandler 85 - [database/172.26.0.2:11210][KeyValueEndpoint]: Channel Active.