PHP SDK opens 8091 port for each $sdk->get('id')

Hello,

I asked a question on How to use an existing couchbase connection? thread, but I think this deserves a new thread as it is not related to the thread directly.

The problem

Using $sdk->get(‘id’) opens 8091 port.

Test Code

test.php

$cluster = new CouchbaseCluster("couchbase://server");
$bucket = $c->openBucket("abucket");

$bucket->get('doc1');
$bucket->get('doc1');

Output

strace -e trace=connect php ./test.php

connect(3, {sa_family=AF_LOCAL, sun_path="/tmp/.newrelic.sock"}, 22) = 0
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
connect(4, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.xxx.x.2")}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.xx.164")}, 16) = 0
connect(4, {sa_family=AF_UNSPEC, sa_data="\0\0\0\0\0\0\0\0\0\0\0\0\0\0"}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xx.xx.11")}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.xx.11")}, 16) = -1 EINPROGRESS (Operation now in progress)
connect(4, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.xx.11")}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.xxx.x.2")}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(8091), sin_addr=inet_addr("10.xxx.xx.11")}, 16) = 0
connect(4, {sa_family=AF_UNSPEC, sa_data="\0\0\0\0\0\0\0\0\0\0\0\0\0\0"}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(8091), sin_addr=inet_addr("10.xxx.xx.164")}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(8091), sin_addr=inet_addr("10.xxx.xx.11")}, 16) = -1 EINPROGRESS (Operation now in progress)
connect(4, {sa_family=AF_INET, sin_port=htons(8091), sin_addr=inet_addr("10.xxx.xx.11")}, 16) = 0
connect(5, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.xx.35")}, 16) = -1 EINPROGRESS (Operation now in progress)
connect(5, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.xx.35")}, 16) = 0

Server Setup

In the test code, couchbase://server is pointing to our load balancer, which is a query service.

According to the original thread (How to use an existing couchbase connection?), it looks like I’m using HTTP to bootstrap the client.

how do I fix this issue? I’ve doubled check that I’m not setting LCB_NO_CCCP=1.

Could you export LCB_LOGLEVEL=5, re-run the script and post results here?

Thank you for the reply!

Here’s the new result.

connect(3, {sa_family=AF_LOCAL, sun_path="/tmp/.newrelic.sock"}, 22) = 0
0ms [I0] {27745} [INFO] (instance - L:347) Version=2.6.0, Changeset=1bd30c6168cb7b5d4961910ead2a6bb84b5b30f3
0ms [I0] {27745} [INFO] (instance - L:348) Effective connection string: mycouchbaseserver.rest/catalog. Bucket=catalog
1ms [I0] {27745} [DEBUG] (instance - L:66) Adding host mycouchbaseserver.rest:8091 to initial HTTP bootstrap list
1ms [I0] {27745} [DEBUG] (instance - L:66) Adding host mycouchbaseserver.rest:11210 to initial CCCP bootstrap list
2ms [I0] {27745} [DEBUG] (confmon - L:89) Preparing providers (this may be called multiple times)
2ms [I0] {27745} [DEBUG] (confmon - L:99) Provider FILE is DISABLED
2ms [I0] {27745} [DEBUG] (confmon - L:96) Provider CCCP is ENABLED
3ms [I0] {27745} [DEBUG] (confmon - L:96) Provider HTTP is ENABLED
3ms [I0] {27745} [DEBUG] (confmon - L:99) Provider MCRAW is DISABLED
3ms [I0] {27745} [TRACE] (confmon - L:292) Start refresh requested
4ms [I0] {27745} [TRACE] (confmon - L:271) Current provider is CCCP
4ms [I0] {27745} [INFO] (cccp - L:118) Requesting connection to node mycouchbaseserver.rest:11210 for CCCP configuration
5ms [I0] {27745} [DEBUG] (lcbio_mgr - L:416) <mycouchbaseserver.rest:11210> (HE=0x2589880) Creating new connection because none are available in the pool
5ms [I0] {27745} [DEBUG] (lcbio_mgr - L:321) <mycouchbaseserver.rest:11210> (HE=0x2589880) Starting connection on I=0x2589db0
6ms [I0] {27745} [INFO] (connection - L:450) <mycouchbaseserver.rest:11210> (SOCK=0x2589ec0) Starting. Timeout=2000000us
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
connect(4, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.xxx.8.2")}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.10.164")}, 16) = 0
connect(4, {sa_family=AF_UNSPEC, sa_data="\0\0\0\0\0\0\0\0\0\0\0\0\0\0"}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.10.11")}, 16) = 0
25ms [I0] {27745} [TRACE] (connection - L:267) <mycouchbaseserver.rest:11210> (SOCK=0x2589ec0) Got event handler for new connection
connect(4, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.10.11")}, 16) = -1 EINPROGRESS (Operation now in progress)
25ms [I0] {27745} [TRACE] (connection - L:314) <mycouchbaseserver.rest:11210> (SOCK=0x2589ec0) Scheduling asynchronous watch for socket.
26ms [I0] {27745} [TRACE] (connection - L:267) <mycouchbaseserver.rest:11210> (SOCK=0x2589ec0) Got event handler for new connection
connect(4, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.10.11")}, 16) = 0
27ms [I0] {27745} [INFO] (connection - L:116) <mycouchbaseserver.rest:11210> (SOCK=0x2589ec0) Connected
27ms [I0] {27745} [DEBUG] (connection - L:123) <mycouchbaseserver.rest:11210> (SOCK=0x2589ec0) Successfuly set TCP_NODELAY
27ms [I0] {27745} [DEBUG] (lcbio_mgr - L:271) <mycouchbaseserver.rest:11210> (HE=0x2589880) Received result for I=0x2589db0,C=0x2589ec0; E=0x0
28ms [I0] {27745} [DEBUG] (lcbio_mgr - L:223) <mycouchbaseserver.rest:11210> (HE=0x2589880) Assigning R=0x2589830 SOCKET=0x2589ec0
28ms [I0] {27745} [DEBUG] (ioctx - L:101) <mycouchbaseserver.rest:11210> (CTX=0x258bc00,unknown) Pairing with SOCK=0x2589ec0
31ms [I0] {27745} [DEBUG] (negotiation - L:368) <mycouchbaseserver.rest:11210> (SASLREQ=0x2589d70) Found feature 0x3 (TCP NODELAY)
32ms [I0] {27745} [DEBUG] (ioctx - L:151) <mycouchbaseserver.rest:11210> (CTX=0x258bc00,sasl) Destroying. PND=0,ENT=1,SORC=1
32ms [I0] {27745} [DEBUG] (ioctx - L:101) <mycouchbaseserver.rest:11210> (CTX=0x25940c0,unknown) Pairing with SOCK=0x2589ec0
33ms [I0] {27745} [INFO] (lcbio - L:112) Translating errno=0, lcb=0x2d to NETWORK_ERROR
34ms [I0] {27745} [ERROR] (cccp - L:133) <mycouchbaseserver.rest:11210> Got I/O Error=0x10
34ms [I0] {27745} [DEBUG] (ioctx - L:151) <mycouchbaseserver.rest:11210> (CTX=0x25940c0,bc_cccp) Destroying. PND=0,ENT=0,SORC=1
35ms [I0] {27745} [INFO] (confmon - L:202) Provider 'CCCP' failed
35ms [I0] {27745} [DEBUG] (confmon - L:236) Will try next provider in 0us
36ms [I0] {27745} [TRACE] (confmon - L:271) Current provider is HTTP
37ms [I0] {27745} [TRACE] (htconfig - L:388) Starting HTTP Configuration Provider 0x2587090
37ms [I0] {27745} [INFO] (connection - L:450) <mycouchbaseserver.rest:8091> (SOCK=0x258be00) Starting. Timeout=2000000us
connect(4, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.xxx.8.2")}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(8091), sin_addr=inet_addr("10.xxx.10.11")}, 16) = 0
connect(4, {sa_family=AF_UNSPEC, sa_data="\0\0\0\0\0\0\0\0\0\0\0\0\0\0"}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(8091), sin_addr=inet_addr("10.xxx.10.164")}, 16) = 0
39ms [I0] {27745} [TRACE] (connection - L:267) <mycouchbaseserver.rest:8091> (SOCK=0x258be00) Got event handler for new connection
connect(4, {sa_family=AF_INET, sin_port=htons(8091), sin_addr=inet_addr("10.xxx.10.11")}, 16) = -1 EINPROGRESS (Operation now in progress)
40ms [I0] {27745} [TRACE] (connection - L:314) <mycouchbaseserver.rest:8091> (SOCK=0x258be00) Scheduling asynchronous watch for socket.
40ms [I0] {27745} [TRACE] (connection - L:267) <mycouchbaseserver.rest:8091> (SOCK=0x258be00) Got event handler for new connection
connect(4, {sa_family=AF_INET, sin_port=htons(8091), sin_addr=inet_addr("10.xxx.10.11")}, 16) = 0
41ms [I0] {27745} [INFO] (connection - L:116) <mycouchbaseserver.rest:8091> (SOCK=0x258be00) Connected
41ms [I0] {27745} [DEBUG] (connection - L:123) <mycouchbaseserver.rest:8091> (SOCK=0x258be00) Successfuly set TCP_NODELAY
42ms [I0] {27745} [DEBUG] (htconfig - L:339) Successfuly connected to REST API mycouchbaseserver.rest:8091
42ms [I0] {27745} [DEBUG] (ioctx - L:101) <mycouchbaseserver.rest:8091> (CTX=0x258a3e0,unknown) Pairing with SOCK=0x258be00
44ms [I0] {27745} [TRACE] (htconfig - L:235) <mycouchbaseserver.rest:8091> Received 224 bytes on HTTP stream
45ms [I0] {27745} [TRACE] (htconfig - L:235) <mycouchbaseserver.rest:8091> Received 10189 bytes on HTTP stream
46ms [I0] {27745} [DEBUG] (htconfig - L:252) <mycouchbaseserver.rest:8091> Generation 0 -> 1
46ms [I0] {27745} [INFO] (confmon - L:174) Setting new configuration. Received via HTTP
46ms [I0] {27745} [DEBUG] (cccp - L:344) Node 8 has no data service
47ms [I0] {27745} [DEBUG] (cccp - L:344) Node 9 has no data service
47ms [I0] {27745} [DEBUG] (cccp - L:344) Node 10 has no data service
48ms [I0] {27745} [DEBUG] (cccp - L:344) Node 11 has no data service
48ms [I0] {27745} [DEBUG] (cccp - L:344) Node 12 has no data service
48ms [I0] {27745} [DEBUG] (cccp - L:344) Node 13 has no data service
49ms [I0] {27745} [DEBUG] (bootstrap - L:55) Instance configured!
49ms [I0] {27745} [DEBUG] (lcbio_mgr - L:416) <10.xxx.10.35:11210> (HE=0x25ae910) Creating new connection because none are available in the pool
50ms [I0] {27745} [DEBUG] (lcbio_mgr - L:321) <10.xxx.10.35:11210> (HE=0x25ae910) Starting connection on I=0x2588840
50ms [I0] {27745} [INFO] (connection - L:450) <10.xxx.10.35:11210> (SOCK=0x2588960) Starting. Timeout=2500000us
51ms [I0] {27745} [TRACE] (connection - L:267) <10.xxx.10.35:11210> (SOCK=0x2588960) Got event handler for new connection
connect(5, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.10.35")}, 16) = -1 EINPROGRESS (Operation now in progress)
51ms [I0] {27745} [TRACE] (connection - L:314) <10.xxx.10.35:11210> (SOCK=0x2588960) Scheduling asynchronous watch for socket.
52ms [I0] {27745} [TRACE] (connection - L:267) <10.xxx.10.35:11210> (SOCK=0x2588960) Got event handler for new connection
connect(5, {sa_family=AF_INET, sin_port=htons(11210), sin_addr=inet_addr("10.xxx.10.35")}, 16) = 0
52ms [I0] {27745} [INFO] (connection - L:116) <10.xxx.10.35:11210> (SOCK=0x2588960) Connected
53ms [I0] {27745} [DEBUG] (connection - L:123) <10.xxx.10.35:11210> (SOCK=0x2588960) Successfuly set TCP_NODELAY
53ms [I0] {27745} [DEBUG] (lcbio_mgr - L:271) <10.xxx.10.35:11210> (HE=0x25ae910) Received result for I=0x2588840,C=0x2588960; E=0x0
53ms [I0] {27745} [DEBUG] (lcbio_mgr - L:223) <10.xxx.10.35:11210> (HE=0x25ae910) Assigning R=0x25893b0 SOCKET=0x2588960
54ms [I0] {27745} [TRACE] (server - L:532) <10.xxx.10.35:11210> (SRV=0x25a6c10) Session not yet negotiated. Negotiating
54ms [I0] {27745} [DEBUG] (ioctx - L:101) <10.xxx.10.35:11210> (CTX=0x2588ad0,unknown) Pairing with SOCK=0x2588960
56ms [I0] {27745} [DEBUG] (negotiation - L:368) <10.xxx.10.35:11210> (SASLREQ=0x2588800) Found feature 0x3 (TCP NODELAY)
56ms [I0] {27745} [DEBUG] (ioctx - L:151) <10.xxx.10.35:11210> (CTX=0x2588ad0,sasl) Destroying. PND=0,ENT=1,SORC=1
57ms [I0] {27745} [DEBUG] (ioctx - L:101) <10.xxx.10.35:11210> (CTX=0x25af6b0,unknown) Pairing with SOCK=0x2588960
57ms [I0] {27745} [DEBUG] (server - L:553) <10.xxx.10.35:11210> (SRV=0x25a6c10,IX=7) Setting initial timeout=2492ms
+++ exited with 0 +++

OKAY :slight_smile: We found it.

It looks like we can’t point our load balancer to a query service. As soon as we switched to a data service, CCCP started working.