Got notified from Channel as inactive, attempting reconnect. constantly repeating

rdeva3 · May 10, 2020, 2:18pm

Hi All,

we are getting - “Got notified from Channel as inactive, attempting reconnect.” constantly repeating,

We are using the JAVA SDK 2.7.5

JBoos7X app server

primaryCluster = CouchbaseAsyncCluster.create( default environment, XXX);

primaryCluster.authenticate(authenticator);

failOverCluster = CouchbaseAsyncCluster.create(environment, XXXX);

failOverCluster.authenticate(authenticator);

Server startup logs :-

06:24:23,801 INFO [com.couchbase.client.core.env.CoreEnvironment] (ServerService Thread Pool – 68) ioPoolSize is less than 3 (1), setting to: 3

06:24:23,802 INFO [com.couchbase.client.core.env.CoreEnvironment] (ServerService Thread Pool – 68) computationPoolSize is less than 3 (1), setting to: 3

06:24:24,454 INFO [com.couchbase.client.core.CouchbaseCore] (ServerService Thread Pool – 68) 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.7.7 (git: 2.7.7, core: 1.7.7), 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@6ae66471, 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=12, maxEndpoints=12, pipelined= ** false ** , idleTime=300}, searchServiceConfig=SearchServiceConfig{minEndpoints=0, maxEndpoints=12, pipelined= ** false ** , idleTime=300}, viewServiceConfig=ViewServiceConfig{minEndpoints=0, maxEndpoints=12, 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=5000, dnsSrvEnabled= ** false ** , propagateParentSpan= ** true ** }

06:24:24,864 INFO [com.couchbase.client.core.CouchbaseCore] (ServerService Thread Pool – 68) 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.7.7 (git: 2.7.7, core: 1.7.7), 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@6ae66471, 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=12, maxEndpoints=12, pipelined= ** false ** , idleTime=300}, searchServiceConfig=SearchServiceConfig{minEndpoints=0, maxEndpoints=12, pipelined= ** false ** , idleTime=300}, viewServiceConfig=ViewServiceConfig{minEndpoints=0, maxEndpoints=12, 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=5000, dnsSrvEnabled= ** false ** , propagateParentSpan= ** true ** }

06:24:27,919 INFO [com.couchbase.client.core.node.Node] (cb-io-1-2) Connected to Node 10.22.77.30

06:24:27,918 INFO [com.couchbase.client.core.node.Node] (cb-io-1-1) Connected to Node 10.22.77.31

06:24:28,811 INFO [com.couchbase.client.core.config.ConfigurationProvider] (cb-computations-1) Selected network configuration: ** default **

06:24:29,611 INFO [com.couchbase.client.core.config.ConfigurationProvider] (cb-computations-1) Opened bucket dp_token

06:24:30,019 INFO [com.couchbase.client.core.node.Node] (cb-io-1-2) Disconnected from Node 10.22.77.30

06:24:30,101 INFO [com.couchbase.client.core.node.Node] (cb-io-1-1) Disconnected from Node 10.22.77.31

06:24:30,313 INFO [com.couchbase.client.core.node.Node] (cb-io-1-1) Connected to Node XXXXa01b

06:24:30,435 INFO [com.couchbase.client.core.node.Node] (cb-io-1-1) Connected to Node XXXXa01c

06:24:30,601 INFO [com.couchbase.client.core.node.Node] (cb-io-1-1) Connected to Node XXXXa01d

06:24:30,713 INFO [com.couchbase.client.core.node.Node] (cb-io-1-3) Connected to Node XXXXa01a

06:24:31,001 INFO [com.couchbase.client.core.node.Node] (cb-io-1-2) Connected to Node 10.22.77.35

06:24:31,036 INFO [com.couchbase.client.core.config.ConfigurationProvider] (cb-computations-1) Selected network configuration: ** default **

06:24:31,405 INFO [com.couchbase.client.core.node.Node] (cb-io-1-3) Connected to Node 10.22.77.34

06:24:31,606 INFO [com.couchbase.client.core.config.ConfigurationProvider] (cb-computations-1) Opened bucket dp_token

06:24:31,921 INFO [com.couchbase.client.core.node.Node] (cb-io-1-3) Disconnected from Node 10.22.77.34

06:24:31,922 INFO [com.couchbase.client.core.node.Node] (cb-io-1-2) Disconnected from Node 10.22.77.35

06:24:32,111 INFO [com.couchbase.client.core.node.Node] (cb-io-1-1) Connected to Node XXXXa02a

06:24:32,308 INFO [com.couchbase.client.core.node.Node] (cb-io-1-2) Connected to Node XXXXa02c

06:24:32,321 INFO [com.couchbase.client.core.node.Node] (cb-io-1-2) Connected to Node XXXXa02d

06:24:32,406 INFO [com.couchbase.client.core.node.Node] (cb-io-1-2) Connected to Node XXXXa02b

06:24:35,100 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-3) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,106 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-3) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,108 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-3) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,109 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-3) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,110 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-3) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,113 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-3) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,114 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-2) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,300 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-1) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,206 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-2) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,301 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-1) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,301 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-2) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,302 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-1) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,302 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-2) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,302 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-1) [XXXXa01c/10.22.77.32:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,304 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-2) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,305 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-1) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,305 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-2) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,306 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-2) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,308 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-1) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,410 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-1) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:35,418 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-1) [XXXXa01d/10.22.77.33:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:36,523 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-1) [XXXXa02c/10.22.77.36:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

06:24:36,744 INFO [com.couchbase.client.core.endpoint.Endpoint] (cb-io-1-2) [XXXXa02c/10.22.77.36:8093][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

ingenthr · May 14, 2020, 10:17pm

I suspect you’ve upgraded to Couchbase Server 6.0.4. There was a change made there that has it drop the connection if idle for 5 seconds. The other side of the change is that the SDK needs to adjust its behavior relative to the new server behavior, but that wasn’t identified before Server 6.0.4 went out.

It’s mostly just ignore-able log noise and you can get rid of it by adjusting the idle period for the query service which is the fix we’ll be introducing:

CouchbaseEnvironment env = DefaultCouchbaseEnvironment.builder().queryServiceConfig(QueryServiceConfig.create(0, 12, 10)).build();

See the docs for more info on how to add that to your client config.

Wayne_Stone · October 15, 2020, 3:23pm

Hello,
Tried above code snippet but I am still getting log lines in every 5 seconds. Kindly advise. Appreciate the help.

10-14-2020 16:35:40.597 | INFO | | c.c.client.core.endpoint.Endpoint.info | [##IP##][QueryEndpoint]: Got notified from Channel as inactive, attempting reconnect.

Thanks

david.nault · October 15, 2020, 6:30pm

Hi Wayne,

How about if you lower the idle timeout to 4 seconds, like this?

int idleTimeoutSeconds = 4;
CouchbaseEnvironment env = DefaultCouchbaseEnvironment.builder()
    .queryServiceConfig(QueryServiceConfig.create(0, 12, idleTimeoutSeconds))
    .build();

Wayne_Stone · October 15, 2020, 8:46pm

david.nault:

int idleTimeoutSeconds = 4;
CouchbaseEnvironment env = DefaultCouchbaseEnvironment.builder()
    .queryServiceConfig(QueryServiceConfig.create(0, 12, idleTimeoutSeconds))
    .build();

Hi David,
I placed suggested code in the main method of the application and ran it. Still observing same logs continuously printing. What else can we try? thanks in advance.

below is out configuration in application.yml
spring:
couchbase.bootstrap-hosts: ##IP##
couchbase.bucket.name: ##bucket##
couchbase.bucket.password: ##psw##
couchbase.env.timeouts.connect: 15000ms
data.couchbase.auto-index: true
Below is one of the interface classes
@ViewIndexed(designDoc=“model”,viewName=“all”)
public interface Modelrepository extends CouchbasePagingAndSortingRepository<Model, String> {

}

david.nault · October 15, 2020, 9:02pm

You’re using Spring Data Couchbase? I’m not sure if there’s a spring property for the query idle timeout. Maybe we can summon @mreiche or @daschl

mreiche · October 15, 2020, 11:59pm

Hi @Wayne_Stone -
That’s the correct setting. To get spring-data-couchbase to use the ClusterEnvironment you are creating, override the the getEnvironment() method in AbstractCouchbaseConfiguration.

/**
 * Override this method if you want a customized {@link CouchbaseEnvironment}.
 * This environment will be managed by Spring, which will call its shutdown()
 * method upon bean destruction, unless you override {@link #isEnvironmentManagedBySpring()}
 * as well to return false.
 *
 * @return a customized environment, defaults to a {@link DefaultCouchbaseEnvironment}.
 */
protected CouchbaseEnvironment getEnvironment() {
    return DefaultCouchbaseEnvironment.create();
}

Wayne_Stone · October 22, 2020, 7:52pm

Hi mreiche and @david.nault ,
I gave the idle period as “1” and I no longer see thse logs. Thanks for the suggestions and help.

@Override
protected CouchbaseEnvironment getEnvironment() {
CouchbaseEnvironment env = DefaultCouchbaseEnvironment.builder()
.queryServiceConfig(QueryServiceConfig.create(0, 12, 1))
.sslEnabled(true)
.sslKeystoreFile(certificatePath)
.build();
return env;
}