LCB_ERR_UNSUPPORTED_OPERATION (214) using PHP SDK

maciej.tomaszewski · September 9, 2020, 11:29am

Hi
I’ve got an issue with FTS query function (using PHP SDK v3). The server randomly returns LCB_ERR_UNSUPPORTED_OPERATION (214). Any idea what might be wrong?

Full PHP error below:

NOTICE: PHP message: [critical] Uncaught PHP Exception Couchbase\InvalidStateException: "LCB_ERR_UNSUPPORTED_OPERATION (214)"

It might be a performance issue because the Couchbase instance is running on a relatively small VPS. It doesn’t occur on development environment which has almost the same setup but also has much more hardware resources. Anyway it’s the only symptom, when it’s working it takes less than ms to return set of results.

raju · September 15, 2020, 4:06pm

@maciej.tomaszewski Do you mind to share sample code to reproduce the issue? It will immensely help to debug the issue

maciej.tomaszewski · September 15, 2020, 4:58pm

It seems that amount of hardware resources was the problem. Increasing search service RAM to >512MB solved the issue, at least for now
I don’t care that much since it’s only a testing env. Production doesn’t have that issue.

maciej.tomaszewski · May 20, 2021, 9:04pm

So I encountered the same problem again… increasing the resources doesn’t make any difference this time.
I’m using PHP SDK v3.2.1 with latest C SDK (v3.x) and Couchbase Server CE v6.6.
I’ve managed to run DEBUG mode, find some logs below. I made 3 requests, the middle one returned LCB_ERR_UNSUPPORTED_OPERATION (214). I divided logs into 3 different sections. The middle one is the one related to the failed request. I can see some differences with pool connection between working requests 1st and 3rd one, and the failed one (2nd).

2021-05-20T20:56:24.198439800Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=1, connstr=couchbase://host:8091, bucketname=(null), username=user, lcb=0x55946a2906b0, refs=35. I=0x55946a2906b0
2021-05-20T20:56:24.198472800Z NOTICE: PHP message: [cb,DEBG] (pcbc/cluster L:122) Initialize Cluster. C=0x7fa8f8ad0370 connstr="couchbase://host:8091"
2021-05-20T20:56:24.198479400Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/b"
2021-05-20T20:56:24.198481900Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a5555e0, refs=1. I=0x55946a5555e0
2021-05-20T20:56:24.198484000Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/a"
2021-05-20T20:56:24.198495500Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a531810, refs=1. I=0x55946a531810
2021-05-20T20:56:24.198722500Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/b"
2021-05-20T20:56:24.198760100Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a5555e0, refs=2. I=0x55946a5555e0
2021-05-20T20:56:24.198766700Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/a"
2021-05-20T20:56:24.198769000Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a531810, refs=2. I=0x55946a531810
2021-05-20T20:56:24.198771200Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/a"
2021-05-20T20:56:24.198773200Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a531810, refs=3. I=0x55946a531810
2021-05-20T20:56:24.200633900Z NOTICE: PHP message: [cb,WARN] (lcbio_mgr L:483 I:2061797827) <couchbase:8093> (HE=0x55946a4f3ae0) Pooled socket is dead. Continuing to next one
2021-05-20T20:56:24.200663400Z NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:501 I:2061797827) <couchbase:8093> (HE=0x55946a4f3ae0) Creating new connection because none are available in the pool
2021-05-20T20:56:24.200670000Z NOTICE: PHP message: [cb,INFO] (connection L:485 I:2061797827) <couchbase:8093> (SOCK=27690ccc532aaee6) Starting. Timeout=75000000us
2021-05-20T20:56:24.200930400Z NOTICE: PHP message: [cb,DEBG] (connection L:250 I:2061797827) <couchbase:8093> (SOCK=27690ccc532aaee6) Created new socket with FD=20
2021-05-20T20:56:24.201027600Z NOTICE: PHP message: [cb,INFO] (connection L:153 I:2061797827) <couchbase:8093> (SOCK=27690ccc532aaee6) Connected established
2021-05-20T20:56:24.201039100Z NOTICE: PHP message: [cb,DEBG] (connection L:106 I:2061797827) <couchbase:8093> (SOCK=27690ccc532aaee6) Successfully set TCP_NODELAY
2021-05-20T20:56:24.201042600Z NOTICE: PHP message: [cb,DEBG] (connection L:106 I:2061797827) <couchbase:8093> (SOCK=27690ccc532aaee6) Successfully set TCP_KEEPALIVE
2021-05-20T20:56:24.201045900Z NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:369 I:2061797827) <couchbase:8093> (HE=0x55946a4f3ae0) Received result for I=0x55946a29d8b0,C=(nil); E=0x0
2021-05-20T20:56:24.201048800Z NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:329 I:2061797827) <couchbase:8093> (HE=0x55946a4f3ae0) Assigning R=0x55946a583310 SOCKET=0x55946a57cfc0
2021-05-20T20:56:24.201051300Z NOTICE: PHP message: [cb,DEBG] (ioctx L:94 I:2061797827) <couchbase:8093> (CTX=0x55946a549870,unknown) Pairing with SOCK=27690ccc532aaee6
2021-05-20T20:56:24.238070100Z NOTICE: PHP message: [cb,DEBG] (ioctx L:139 I:2061797827) <couchbase:8093> (CTX=0x55946a549870,mgmt/capi) Destroying context. Pending Writes=0, Entered=true, Socket Refcount=1
2021-05-20T20:56:24.238119800Z NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:554 I:2061797827) <couchbase:8093> (HE=0x55946a4f3ae0) Placing socket back into the pool. I=0x55946a29d8b0,C=0x55946a57cfc0
2021-05-20T20:56:24.246570600Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a531810, refs=2. I=0x55946a531810
2021-05-20T20:56:24.246603400Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a531810, refs=1. I=0x55946a531810
2021-05-20T20:56:24.246610100Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a5555e0, refs=1. I=0x55946a5555e0
2021-05-20T20:56:24.246624500Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a531810, refs=0. I=0x55946a531810
2021-05-20T20:56:24.246627200Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a5555e0, refs=0. I=0x55946a5555e0



2021-05-20T20:56:25.210755900Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=1, connstr=couchbase://host:8091, bucketname=(null), username=user, lcb=0x55946a426d60, refs=34. I=0x55946a426d60
2021-05-20T20:56:25.210789100Z NOTICE: PHP message: [cb,DEBG] (pcbc/cluster L:122) Initialize Cluster. C=0x7fa8f8ad0370 connstr="couchbase://host:8091"
2021-05-20T20:56:25.210795700Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/b"
2021-05-20T20:56:25.210798400Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a554d60, refs=1. I=0x55946a554d60
2021-05-20T20:56:25.210800500Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/a"
2021-05-20T20:56:25.210802600Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a543170, refs=1. I=0x55946a543170
2021-05-20T20:56:25.211092000Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/b"
2021-05-20T20:56:25.211135100Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a554d60, refs=2. I=0x55946a554d60
2021-05-20T20:56:25.211142800Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/a"
2021-05-20T20:56:25.211145700Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a543170, refs=2. I=0x55946a543170
2021-05-20T20:56:25.211148200Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/a"
2021-05-20T20:56:25.211164000Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a543170, refs=3. I=0x55946a543170
2021-05-20T20:56:25.224976300Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a543170, refs=2. I=0x55946a543170
2021-05-20T20:56:25.225002700Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a543170, refs=1. I=0x55946a543170
2021-05-20T20:56:25.225009200Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a554d60, refs=1. I=0x55946a554d60
2021-05-20T20:56:25.225011500Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a543170, refs=0. I=0x55946a543170
2021-05-20T20:56:25.225013600Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a554d60, refs=0. I=0x55946a554d60



2021-05-20T20:56:31.807871700Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=1, connstr=couchbase://host:8091, bucketname=(null), username=user, lcb=0x55946a42a5b0, refs=46. I=0x55946a42a5b0
2021-05-20T20:56:31.807909800Z NOTICE: PHP message: [cb,DEBG] (pcbc/cluster L:122) Initialize Cluster. C=0x7fa8f8ad0370 connstr="couchbase://host:8091"
2021-05-20T20:56:31.807916400Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/b"
2021-05-20T20:56:31.807919000Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a53a2e0, refs=1. I=0x55946a53a2e0
2021-05-20T20:56:31.807921100Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/a"
2021-05-20T20:56:31.807923100Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a516490, refs=1. I=0x55946a516490
2021-05-20T20:56:31.808365800Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/b"
2021-05-20T20:56:31.808403400Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a53a2e0, refs=2. I=0x55946a53a2e0
2021-05-20T20:56:31.808410100Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/a"
2021-05-20T20:56:31.808413000Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a516490, refs=2. I=0x55946a516490
2021-05-20T20:56:31.808415400Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:173) Rewrite connection string from "couchbase://host:8091" to "couchbase://host:8091/a"
2021-05-20T20:56:31.808427200Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:324) cachehit: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a516490, refs=3. I=0x55946a516490
2021-05-20T20:56:31.810507300Z NOTICE: PHP message: [cb,WARN] (lcbio_mgr L:483 I:122606560) <couchbase:8093> (HE=0x55946a52ccb0) Pooled socket is dead. Continuing to next one
2021-05-20T20:56:31.810535700Z NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:501 I:122606560) <couchbase:8093> (HE=0x55946a52ccb0) Creating new connection because none are available in the pool
2021-05-20T20:56:31.810542300Z NOTICE: PHP message: [cb,INFO] (connection L:485 I:122606560) <couchbase:8093> (SOCK=2e29203e5eab1d69) Starting. Timeout=75000000us
2021-05-20T20:56:31.810813400Z NOTICE: PHP message: [cb,DEBG] (connection L:250 I:122606560) <couchbase:8093> (SOCK=2e29203e5eab1d69) Created new socket with FD=19
2021-05-20T20:56:31.810892400Z NOTICE: PHP message: [cb,INFO] (connection L:153 I:122606560) <couchbase:8093> (SOCK=2e29203e5eab1d69) Connected established
2021-05-20T20:56:31.810921600Z NOTICE: PHP message: [cb,DEBG] (connection L:106 I:122606560) <couchbase:8093> (SOCK=2e29203e5eab1d69) Successfully set TCP_NODELAY
2021-05-20T20:56:31.810928200Z NOTICE: PHP message: [cb,DEBG] (connection L:106 I:122606560) <couchbase:8093> (SOCK=2e29203e5eab1d69) Successfully set TCP_KEEPALIVE
2021-05-20T20:56:31.810930800Z NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:369 I:122606560) <couchbase:8093> (HE=0x55946a52ccb0) Received result for I=0x55946a52e3a0,C=(nil); E=0x0
2021-05-20T20:56:31.810932900Z NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:329 I:122606560) <couchbase:8093> (HE=0x55946a52ccb0) Assigning R=0x55946a5518e0 SOCKET=0x55946a506980
2021-05-20T20:56:31.810935200Z NOTICE: PHP message: [cb,DEBG] (ioctx L:94 I:122606560) <couchbase:8093> (CTX=0x55946a4f18d0,unknown) Pairing with SOCK=2e29203e5eab1d69
2021-05-20T20:56:31.849544300Z NOTICE: PHP message: [cb,DEBG] (ioctx L:139 I:122606560) <couchbase:8093> (CTX=0x55946a4f18d0,mgmt/capi) Destroying context. Pending Writes=0, Entered=true, Socket Refcount=1
2021-05-20T20:56:31.849585000Z NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:554 I:122606560) <couchbase:8093> (HE=0x55946a52ccb0) Placing socket back into the pool. I=0x55946a52e3a0,C=0x55946a506980
2021-05-20T20:56:31.858725000Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a516490, refs=2. I=0x55946a516490
2021-05-20T20:56:31.858755500Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a516490, refs=1. I=0x55946a516490
2021-05-20T20:56:31.858762000Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a53a2e0, refs=1. I=0x55946a53a2e0
2021-05-20T20:56:31.858764700Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/a, bucketname=a, username=user, lcb=0x55946a516490, refs=0. I=0x55946a516490
2021-05-20T20:56:31.858767100Z NOTICE: PHP message: [cb,DEBG] (pcbc/pool L:225) cachedel: type=0, connstr=couchbase://host:8091/b, bucketname=b, username=user, lcb=0x55946a53a2e0, refs=0. I=0x55946a53a2e0

Please let me know what might be the problem and feel free to ask for more details. I can provide any data you need @raju
This is most likely not a PHP SDK issue but I noticed your answer @avsej in a different but similar thread posted few months ago as well.

maciej.tomaszewski · May 20, 2021, 10:39pm

I skipped installation of following packages: libcouchbase3-libev and libcouchbase3-libevent.
Can it be the reason?

maciej.tomaszewski · May 23, 2021, 9:24pm

Bump! Still having the problem. I don’t know what might be the reason but what I noticed is that depending on the hardware it appears sooner or later. With 16GB and 4 cores CPU I get this error ~every 5-10 requests. Logs as mentioned above. Is there any solution to this problem?

AV25242 · May 25, 2021, 12:43am

@avsej can you please assist ?

maciej.tomaszewski · May 26, 2021, 10:50am

I believe it’s a C SDK or even CB Server issue. Can anyone have a look?

maciej.tomaszewski · May 31, 2021, 8:51am

Anybody, any idea?

raju · June 3, 2021, 4:59pm

@maciej.tomaszewski Can you please share the sample code? Is the issue still with issuing a FTS query? Lot of messages here but could not find code sample. Thank you

maciej.tomaszewski · June 3, 2021, 6:09pm

Well there is not much code involved. Connection is made through

$options = new ClusterOptions();
$options->credentials($this->user, $this->pass);
$this->cluster = new Cluster("couchbase://{$this->host}:{$this->port}", $options);

And then I run the query with following code

$opts = new QueryOptions();
$res = $this->cluster->query('
    SELECT SEARCH_META() AS meta
    FROM `in` i 
    WHERE SEARCH(i, {
        "query": {
            "disjuncts": [' . $aQuery . $bQuery . ']
        }
    }, {"index": "in_default"})
    ORDER BY meta.score DESC LIMIT 20
', $opts);

Worth mentioning is that it’s like 1 of 10 requests that are failing. The rest 9 are ok so I don’t think it’s a query or the syntax problem. Looks like temporary failure on the Couchbase Server side, or the SDK connection issue. I’m not sure. You can check logs above. I shared logs of 3 requests - 2 OK and 1 FAILED. Check out the differences between those.

aruns1987 · June 4, 2021, 5:05am

@maciej.tomaszewski I tried to repro this on my local but no luck so far. Here are the details on my repro:

PHP SDK version 3.1.2 (LCB SDK version 3.1.3)
CB version 6.6.2

Code:

<?php
$connectionString = "couchbase://localhost";
$options = new \Couchbase\ClusterOptions();
$options->credentials("Administrator", "password");
$cluster = new \Couchbase\Cluster($connectionString, $options);

$opts = new \Couchbase\QueryOptions();
$res = $cluster->query('
    SELECT SEARCH_META() AS meta
    FROM `travel-sample` i
    WHERE SEARCH(i, {
        "query": {
            "disjuncts": [
              {"field":"country", "match": "France"},
              {"field":"type", "match": "airline"}
            ]
        }
    }, {"index": "in_default"})
    ORDER BY meta.score DESC LIMIT 20
', $opts);

echo '<pre>'; print_r($res); echo '</pre>';
?>

Logs:
php_test.log.zip (8.5 KB)

I executed the script multiple times back to back but still no luck. The following details might help with debugging this better:

Are you able to collect logs from CB server when this happens and upload that? That way, we will be correlate what is going on in the server during that time
Are you executing the query in a loop? It will also help to know more details on your fts index and what kind of dataset you are using. I have written the disjunct queries based on our travel-sample here. If you are able to share the complete code you are running (leaving out sensitive data), that will be more helpful as well.

Best,
Arun