I have some code that works locally, but I’m trying to access it from a remote location and cannot get it to work.
I have two nodes in my cluster which externally share the same IP address (the IP address of my router). I have configured them to have distinct port ranges for 8091-8096 and 11210. I have configured both of them to have the appropriate external alternate address as well (the same for each of them).
I am able to connect to each of the servers from outside using the appropriate REST ports in my browser and everything looks good.
In my Java code, I appear to be successful in connecting and everything runs smoothly until my first operation - which times out. I suspect that in fact what is timing out is the bucket opening but because that is lazy it is only showing up when I cannot do the upsert.
This is about the simplest code I can use to reproduce the problem:
package test.ziniki.characterization.couchbase30;
import java.time.Duration;
import java.time.temporal.ChronoUnit;
import java.util.Arrays;
import java.util.HashSet;
import java.util.Optional;
import java.util.Set;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import com.couchbase.client.core.env.IoConfig;
import com.couchbase.client.core.env.NetworkResolution;
import com.couchbase.client.core.env.SeedNode;
import com.couchbase.client.core.env.TimeoutConfig;
import com.couchbase.client.core.retry.BestEffortRetryStrategy;
import com.couchbase.client.java.Bucket;
import com.couchbase.client.java.Cluster;
import com.couchbase.client.java.ClusterOptions;
import com.couchbase.client.java.Collection;
import com.couchbase.client.java.env.ClusterEnvironment;
import com.couchbase.client.java.json.JsonObject;
public class MainCB30 {
public static final Logger logger = LoggerFactory.getLogger("Test");
public static void main(String[] argv) throws Exception {
String host = System.getenv("COUCHBASE30_HOST");
String pwd = System.getenv("CBTEST_PASSWORD");
String bucketName = System.getenv("BUCKET");
ClusterEnvironment env =
ClusterEnvironment.builder()
.ioConfig(IoConfig.builder()
.enableDnsSrv(false)
.networkResolution(NetworkResolution.EXTERNAL))
// .timeoutConfig(TimeoutConfig.builder().connectTimeout(Duration.of(60, ChronoUnit.SECONDS))
// .kvTimeout(Duration.of(60, ChronoUnit.SECONDS)))
.retryStrategy(BestEffortRetryStrategy.INSTANCE)
.build();
Set<SeedNode> seedNodes = new HashSet<>(Arrays.asList(
SeedNode.create(host,
Optional.of(42210),
Optional.of(42091)),
SeedNode.create(host,
Optional.of(52210),
Optional.of(52091))
));
Cluster cluster = Cluster.connect(seedNodes, ClusterOptions.clusterOptions("test", pwd).environment(env));
logger.info("connected");
Bucket bucket = cluster.bucket(bucketName);
Collection syncColl = bucket.defaultCollection();
try {
syncColl.upsert("exists", JsonObject.jo().put("exists", true));
logger.info("done upsert");
} finally {
cluster.disconnect();
logger.info("disconnected");
}
}
}
As you can see, I have experimented with extending the timeout but that just slows down the failure and produces larger log files
I couldn’t attach the complete log file because it wasn’t an acceptable file type but I think the key information is contained in these lines:
20200212-20:23:08.065 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceAddedEvent][99ms] Service added to Node {"coreId":1,"remote":"external.ip.address:42210","type":"KV"}
20200212-20:23:08.067 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent] Request CarrierGlobalConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":1,"requestType":"CarrierGlobalConfigRequest","retried":6,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque":"0x0","target":"external.ip.address","type":"kv"},"timeoutMs":10000}
20200212-20:23:08.068 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent][1000us] Request CarrierGlobalConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":1,"requestType":"CarrierGlobalConfigRequest","retried":6,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque":"0x0","target":"external.ip.address","type":"kv"},"timeoutMs":10000}
20200212-20:23:08.068 com.couchbase.node/ts INFO: [com.couchbase.node][NodeConnectedEvent] Node connected {"coreId":1,"managerPort":"52091","remote":"external.ip.address"}
20200212-20:23:08.068 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceConnectInitiatedEvent] Starting to connect service with 1 minimum endpoints {"coreId":1,"remote":"external.ip.address:52210","type":"KV"}
20200212-20:23:08.068 couchbase.endpoint/ts DEBUG: [com.couchbase.endpoint][EndpointStateChangedEvent] Endpoint changed state from DISCONNECTED to CONNECTING {"circuitBreaker":"DISABLED","coreId":1,"remote":"external.ip.address:52210","type":"KV"}
20200212-20:23:08.068 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceStateChangedEvent] Service changed state from DISCONNECTED to CONNECTING {"coreId":1,"remote":"external.ip.address:52210","type":"KV"}
20200212-20:23:08.069 com.couchbase.node/ts DEBUG: [com.couchbase.node][NodeStateChangedEvent] Node changed state from DISCONNECTED to CONNECTING {"coreId":1,"managerPort":"52091","remote":"external.ip.address"}
20200212-20:23:08.069 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceAddedEvent][705us] Service added to Node {"coreId":1,"remote":"external.ip.address:52210","type":"KV"}
20200212-20:23:08.069 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent] Request CarrierGlobalConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":2,"requestType":"CarrierGlobalConfigRequest","retried":6,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque":"0x1","target":"external.ip.address","type":"kv"},"timeoutMs":10000}
20200212-20:23:08.069 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent][2000us] Request CarrierGlobalConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":1,"requestType":"CarrierGlobalConfigRequest","retried":6,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque":"0x0","target":"external.ip.address","type":"kv"},"timeoutMs":10000}
20200212-20:23:08.070 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent][1000us] Request CarrierGlobalConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":2,"requestType":"CarrierGlobalConfigRequest","retried":6,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque":"0x1","target":"external.ip.address","type":"kv"},"timeoutMs":10000}
20200212-20:23:08.070 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceConnectInitiatedEvent] Starting to connect service with 1 minimum endpoints {"bucket":"bucket-name","coreId":1,"remote":"external.ip.address:42210","type":"KV"}
20200212-20:23:08.070 couchbase.endpoint/ts DEBUG: [com.couchbase.endpoint][EndpointStateChangedEvent] Endpoint changed state from DISCONNECTED to CONNECTING {"bucket":"bucket-name","circuitBreaker":"DISABLED","coreId":1,"remote":"external.ip.address:42210","type":"KV"}
20200212-20:23:08.070 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceStateChangedEvent] Service changed state from DISCONNECTED to CONNECTING {"bucket":"bucket-name","coreId":1,"remote":"external.ip.address:42210","type":"KV"}
20200212-20:23:08.070 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceAddedEvent][885us] Service added to Node {"bucket":"bucket-name","coreId":1,"remote":"external.ip.address:42210","type":"KV"}
20200212-20:23:08.070 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent] Request CarrierBucketConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":3,"requestType":"CarrierBucketConfigRequest","retried":6,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"bucket":"bucket-name","collection":"_default","opaque":"0x2","scope":"_default","target":"external.ip.address","type":"kv"},"timeoutMs":10000}
20200212-20:23:08.071 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceConnectInitiatedEvent] Starting to connect service with 1 minimum endpoints {"bucket":"bucket-name","coreId":1,"remote":"external.ip.address:52210","type":"KV"}
20200212-20:23:08.071 couchbase.endpoint/ts DEBUG: [com.couchbase.endpoint][EndpointStateChangedEvent] Endpoint changed state from DISCONNECTED to CONNECTING {"bucket":"bucket-name","circuitBreaker":"DISABLED","coreId":1,"remote":"external.ip.address:52210","type":"KV"}
20200212-20:23:08.071 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceStateChangedEvent] Service changed state from DISCONNECTED to CONNECTING {"bucket":"bucket-name","coreId":1,"remote":"external.ip.address:52210","type":"KV"}
20200212-20:23:08.071 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent][4000us] Request CarrierGlobalConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":1,"requestType":"CarrierGlobalConfigRequest","retried":6,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque":"0x0","target":"external.ip.address","type":"kv"},"timeoutMs":10000}
20200212-20:23:08.071 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent][2000us] Request CarrierGlobalConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":2,"requestType":"CarrierGlobalConfigRequest","retried":6,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"opaque":"0x1","target":"external.ip.address","type":"kv"},"timeoutMs":10000}
20200212-20:23:08.071 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent][1000us] Request CarrierBucketConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":3,"requestType":"CarrierBucketConfigRequest","retried":6,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"bucket":"bucket-name","collection":"_default","opaque":"0x2","scope":"_default","target":"external.ip.address","type":"kv"},"timeoutMs":10000}
20200212-20:23:08.071 .couchbase.service/ts DEBUG: [com.couchbase.service][ServiceAddedEvent][11ms] Service added to Node {"bucket":"bucket-name","coreId":1,"remote":"external.ip.address:52210","type":"KV"}
20200212-20:23:08.072 .couchbase.request/ts DEBUG: [com.couchbase.request][RequestRetryScheduledEvent] Request CarrierBucketConfigRequest retry scheduled per RetryStrategy (Reason: NODE_NOT_AVAILABLE) {"completed":false,"coreId":1,"idempotent":true,"requestId":4,"requestType":"CarrierBucketConfigRequest","retried":5,"retryReasons":["NODE_NOT_AVAILABLE"],"service":{"bucket":"bucket-name","collection":"_default","opaque":"0x3","scope":"_default","target":"external.ip.address","type":"kv"},"timeoutMs":10000}