CouchbaseError: Client-Side timeout exceeded for operation


#1

Hi,

I am running couchbase server 3.0.1, with NodeJS SDK. I have set up a server with two buckets, and no documents. I opened a connections via:

var dbCluster = new couchbase.Cluster([my_host]);
var db = dbCluster.openBucket( [my_bucket_name]);

When I try to execute ‘db.upsert’, I get the following error:

Error: CouchbaseError: Client-Side timeout exceeded for operation. Inspect network conditions or increase the timeout.

Now the strangest part, is that the document still gets added. So the command executes successfully, but still returns the error. Also the call gets executed very fast, and definitely does not take 2.5 sec (default operation timeout).

I have tried increasing the timeout via:

db.operationTimeout = 5000;

This did not work. Again the call was executed successfully, but timeout error was returned even though the specified timeout did not pass (the call was very fast).

I am running OSX Yosemite 10.10.2. Any help would be really appreciated, as I do not know where to look next.

Thank you,


Getting couchbase error: Client-Side timeout exceeded for operation
#2

What is the version of the library you are using? Also, are you linking to an external libcouchbase, or are you using the one embedded in couchnode?


#3

I’m using the one embedded in couchnode, I tried couchnode versions 2.0.5 and 2.0.6
Also, using iojs 1.2

(the libcouchbase embeded seems to be 2.4.7 according the commit history)


#4

Update:
We also just tried installing libouchbase 2.4.8 separately, and then compiling couchnode against it, but we get the same problem.


#5

Can you set LCB_LOGLEVEL=5 in your environment (i.e. as an environment variable) and re-run the code? This will allow the C library to dump verbose logging information to stderr, which may help reveal more information as to why it’s timing out.


#6

Ok, this is the output from logging:

0ms [I0] {1299} [INFO] (instance - L:372) Version=2.4.0, Changeset=0ac7fc4 0ms [I0] {1299} [INFO] (instance - L:373) Effective connection string: couchbase://couchbase.mysubdomain.com/main. Bucket=main 0ms [I0] {1299} [DEBUG] (instance - L:63) Adding host couchbase.mysubdomain.com:8091 to initial HTTP bootstrap list 0ms [I0] {1299} [DEBUG] (instance - L:63) Adding host couchbase.mysubdomain.com:11210 to initial CCCP bootstrap list 148ms [I0] {1299} [DEBUG] (confmon - L:89) Preparing providers (this may be called multiple times) 148ms [I0] {1299} [DEBUG] (confmon - L:99) Provider FILE is DISABLED 148ms [I0] {1299} [DEBUG] (confmon - L:96) Provider CCCP is ENABLED 148ms [I0] {1299} [DEBUG] (confmon - L:96) Provider HTTP is ENABLED 148ms [I0] {1299} [DEBUG] (confmon - L:99) Provider MCRAW is DISABLED 148ms [I0] {1299} [TRACE] (confmon - L:292) Start refresh requested 148ms [I0] {1299} [TRACE] (confmon - L:271) Current provider is CCCP 148ms [I0] {1299} [INFO] (cccp - L:118) Requesting connection to node couchbase.mysubdomain.com:11210 for CCCP configuration 148ms [I0] {1299} [DEBUG] (lcbio_mgr - L:416) <couchbase.mysubdomain.com:11210> (HE=0x103000000) Creating new connection because none are available in the pool 148ms [I0] {1299} [DEBUG] (lcbio_mgr - L:321) <couchbase.mysubdomain.com:11210> (HE=0x103000000) Starting connection on I=0x101700590 149ms [I0] {1299} [INFO] (connection - L:441) <couchbase.mysubdomain.com:11210> (SOCK=0x1017009b0) Starting. Timeout=2000000us 151ms [I0] {1299} [TRACE] (connection - L:335) <couchbase.mysubdomain.com:11210> (SOCK=0x1017009b0) Received completion handler. Status=0. errno=0 151ms [I0] {1299} [INFO] (connection - L:116) <couchbase.mysubdomain.com:11210> (SOCK=0x1017009b0) Connected 151ms [I0] {1299} [DEBUG] (lcbio_mgr - L:271) <couchbase.mysubdomain.com:11210> (HE=0x103000000) Received result for I=0x101700590,C=0x1017009b0; E=0x0 151ms [I0] {1299} [DEBUG] (lcbio_mgr - L:223) <couchbase.mysubdomain.com:11210> (HE=0x103000000) Assigning R=0x101700350 SOCKET=0x1017009b0 152ms [I0] {1299} [DEBUG] (ioctx - L:101) <couchbase.mysubdomain.com:11210> (CTX=0x10100f710,unknown) Pairing with SOCK=0x1017009b0 152ms [I0] {1299} [DEBUG] (ioctx - L:151) <couchbase.mysubdomain.com:11210> (CTX=0x10100f710,sasl) Destroying. PND=0,ENT=1,SORC=1 152ms [I0] {1299} [DEBUG] (ioctx - L:101) <couchbase.mysubdomain.com:11210> (CTX=0x10131c050,unknown) Pairing with SOCK=0x1017009b0 152ms [I0] {1299} [DEBUG] (ioctx - L:151) <couchbase.mysubdomain.com:11210> (CTX=0x10131c050,bc_cccp) Destroying. PND=0,ENT=1,SORC=1 152ms [I0] {1299} [INFO] (lcbio_mgr - L:491) <couchbase.mysubdomain.com:11210> (HE=0x103000000) Placing socket back into the pool. I=0x101700590,C=0x1017009b0 153ms [I0] {1299} [INFO] (confmon - L:174) Setting new configuration. Received via CCCP 153ms [I0] {1299} [DEBUG] (bootstrap - L:55) Instance configured! Successfully opened bucket 157ms [I0] {1299} [INFO] (lcbio_mgr - L:407) <couchbase.mysubdomain.com:11210> (HE=0x103000000) Found ready connection in pool. Reusing socket and not creating new connection 157ms [I0] {1299} [DEBUG] (lcbio_mgr - L:223) <couchbase.mysubdomain.com:11210> (HE=0x103000000) Assigning R=0x10100f880 SOCKET=0x1017009b0 157ms [I0] {1299} [DEBUG] (ioctx - L:101) <couchbase.mysubdomain.com:11210> (CTX=0x10100fde0,unknown) Pairing with SOCK=0x1017009b0 157ms [I0] {1299} [DEBUG] (server - L:507) <couchbase.mysubdomain.com:11210> (SRV=0x10100fae0,IX=0) Setting initial timeout=0ms 157ms [I0] {1299} [WARN] (server - L:375) <couchbase.mysubdomain.com:11210> (SRV=0x10100fae0,IX=0) Failing command (pkt=0x10204e000, opaque=0, opcode=0x1) with error 0x17 Error: CouchbaseError: Client-Side timeout exceeded for operation. Inspect network conditions or increase the timeout 160ms [I0] {1299} [INFO] (bootstrap - L:191) Not requesting a config refresh because of throttling parameters. Next refresh possible in 9992ms or 99 errors. See LCB_CNTL_CONFDELAY_THRESH and LCB_CNTL_CONFERRTHRESH to modify the throttling settings 160ms [I0] {1299} [ERROR] (server - L:458) <couchbase.mysubdomain.com:11210> (SRV=0x10100fae0,IX=0) Server timed out. Some commands have failed 160ms [I0] {1299} [DEBUG] (server - L:462) <couchbase.mysubdomain.com:11210> (SRV=0x10100fae0,IX=0) Scheduling next timeout for 0 ms 160ms [I0] {1299} [DEBUG] (server - L:462) <couchbase.mysubdomain.com:11210> (SRV=0x10100fae0,IX=0) Scheduling next timeout for 0 ms

Then it just keeps printing out these two lines continuously:
160ms [I0] {1299} [DEBUG] (server - L:462) <couchbase.mysubdomain.com:11210> (SRV=0x10100fae0,IX=0) Scheduling next timeout for 0 ms 160ms [I0] {1299} [DEBUG] (server - L:462) <couchbase.mysubdomain.com:11210> (SRV=0x10100fae0,IX=0) Scheduling next timeout for 0 ms

I found this strange:
157ms [I0] {1299} [DEBUG] (server - L:507) <couchbase.mysubdomain.com:11210> (SRV=0x10100fae0,IX=0) Setting initial timeout=0ms

Is this the client side timeout? If so, it looks like its not being set for some reason. Or does this mean something else?


#7

It would seem that something is erroneously setting the timeout to 0 – Setting a timeout to 0 will maybe return an error in the future, but currently will basically make the timeout “instantaneous”. Can you ensure that nothing in your code is manually modifying the timeout?


#8

I can confirm that we are not overwriting this. Our code (below) is very simple. There is nothing there that would overwrite it. Are there any global settings / configurations that might be causing this problem? Maybe some sort of compilation flag?

We are wondering about compilation, because we are running the same code on two other macs, and it works (the default timeout shows up in the logs as 2500). However, when we try to run it on two other older macs (2011) with a clean install of OSX Yosemite 10.2.2, it fails. Two new macs (2013 models) both execute the code correctly without any problems. The code is identical. The environment is identical (io.js 1.2.0, OSX Yosemite 10.2.2, couchnode 2.0.6, couchbase 3.0.1).

The code is below for your reference.

var couchbase = require('couchbase');

var dbCluster = new couchbase.Cluster("myhost");
var db = dbCluster.openBucket( "mybucket", function(err) {
// this works fine
    if(err){
        throw err;
    }
});

// this has no effect on the timeout
// we tried both with, and without this line
db.operationTimeout = 5000;

db.upsert("process-ids", json, function(err, result){
    if(err){
       // returns error, even though the operation completed successfully
       return console.log("Error: " + err);
    }
});

#9

libcouchbase, as of 2.4.5, started to use the mach_absolute_time function native to OS X. Does trying with an older version of the library help with this? To be fair I haven’t tried with an older macbook pro. Does this also happen when using the cbc tool?

I’ll try it on my 2009 macbook pro :slight_smile:


#10

Seems to work on my macbook pro 2009. I’m not sure how good your skills are, but trying to eliminate node out of the equation would help. What about a simple example in “Pure C” – does that fail – See https://github.com/couchbase/libcouchbase/blob/master/example/minimal/minimal.c for an example.


#11

ok, figured it out finally and this is pretty strange. we did try cbc as well and it was failing but it was failing with invalid arguments.

turns out that if we use this type of connection string to cluster “couchbase://whatever.mysite.com” it fails but if the connection string is just “whatever.mysite.com” everything is fine. The former one is according to the documentation. It’s strange of course why it works on some macs and doesn’t on others, baffling.

Anyway, with this info, perhaps it’s easier to find this issue.


#12

another quick update, specifying ip in connection works: “couchbase://127.0.0.1”


#13

I suppose one quick way to check if the setting is being overwritten is to read it back. I don’t know what the node-specific API for retrieving the timeout is, but it would help then figuring out (after the timeout) if the issue is simply in something overriding the timeout, of if it’s something corrupting the client’s sense of time :slight_smile: ) – if the issue seems to vary with DNS, then maybe there’s some delay in hostname resolution or similar?


#14

i have clone your Github couchbase/kubernetes Project https://github.com/couchbase/kubernetes and i use it.
But I have a problem. I have an Google Cloud Cluster with 3 VM Wares one Vmware has 4CPU and 7,5GB Ram. I use the Couchbase Commity Edition 4.0.0. When i scale the couchbase-controller to 3 nodes. The sync-gateway works fine but i can’t connect to a bucket over node or java. i get the following Error: Error CouchbaseError: Client-Side timeout exceeded for operation. Inspect network conditions or increase the timeout. When i use one node with no replicas it works. The Firewall rules are set with port 11210, 8091, 8092. i tried to connect to port 11210 but it doesn’t work. Can anyone help me?

this is my code:

var couchbase = require(“couchbase”);
var cluster = new couchbase.Cluster(‘couchbase://xxx.xxx.xxx.xxx:11210’);
var bucket = cluster.openBucket(‘service’, function(err) {
if (err) {
throw err;
}else {
console.log(“Successfully opened bucket”);
bucket.operationTimeout=500*1000
bucket.get(‘1234’ , function(err, result) {
if (err) {
throw err;
}
var doc = result.value;
console.log(doc.name );
});
}

});

Error Message: CouchbaseError: Client-Side timeout exceeded for operation. Inspect network conditions or increase the timeout


#15

experiencing same problem with cbc under Yosemite and libcouchbase 2.6.1

bash-3.2$ cbc cat sample -v -U prod.couch1/ontourcloud -P testPass -Dtimeout=30
0ms [I0] {33637/513} [INFO] (instance - L:351) Version=2.6.1, Changeset=eb09707433013b742c0aa221e564ad73ba8a3708
0ms [I0] {33637/513} [INFO] (instance - L:352) Effective connection string: prod.couch1/ontourcloud?timeout=30&console_log_level=2&. Bucket=ontourcloud
0ms [I0] {33637/513} [INFO] (cccp - L:118) Requesting connection to node prod.couch1:11210 for CCCP configuration
0ms [I0] {33637/513} [INFO] (connection - L:450) prod.couch1:11210 (SOCK=0x7fe04b408d00) Starting. Timeout=2000000us
29ms [I0] {33637/513} [INFO] (connection - L:116) prod.couch1:11210 (SOCK=0x7fe04b408d00) Connected
138ms [I0] {33637/513} [INFO] (lcbio_mgr - L:491) prod.couch1:11210 (HE=0x7fe04b812e00) Placing socket back into the pool. I=0x7fe04b408bb0,C=0x7fe04b408d00
138ms [I0] {33637/513} [INFO] (confmon - L:174) Setting new configuration. Received via CCCP
138ms [I0] {33637/513} [INFO] (connection - L:450) <10.135.21.164:11210> (SOCK=0x7fe04c800000) Starting. Timeout=30000000us


#16

we discovered reason for such behavior - our cluster is organized with intranet api - 10.135.21.164, and client was outside from intranet vpn. After we connect client to intranet vpn, everything resolves.


#17

I had the same issue with CouchBase on AWS. I solved it by opening the following ports to anyone:

22 tcp 0.0.0.0/0
4369 tcp 0.0.0.0/0
4984 tcp 0.0.0.0/0
8080 tcp 0.0.0.0/0
8088 tcp 0.0.0.0/0
8091 tcp 0.0.0.0/0
8092 tcp 0.0.0.0/0
11209 tcp 0.0.0.0/0
11210 tcp 0.0.0.0/0
11211 tcp 0.0.0.0/0
11214 tcp 0.0.0.0/0
11215 tcp 0.0.0.0/0
18091 tcp 0.0.0.0/0
18092 tcp 0.0.0.0/0

For more info see: http://docs.couchbase.com/couchbase-manual-2.5/cb-install/#network-ports


#18

I was experiencing a similar issue. In my case, I was in a loop inserting many records and after a little bit time I saw the “Scheduling next timeout for 0 ms”. This caused an unrecoverable failure in my script. I was able to overcome the issue by throttling the request to be no greater than 500 inserts per second. In my environment I was running Couchbase Server 5.5 Ent. with/ docker on a mac.