LCB_ERROR Generic CouchbaseBucket.php

EdanBrooke · October 2, 2016, 10:38pm

An exception occurred: LCB_ERROR: Generic error in [CouchbaseNative]/CouchbaseBucket.class.php on line 145

_CouchbaseBucket->upsert() in [CouchbaseNative]/CouchbaseBucket.class.php at line 145
CouchbaseBucket->upsert() in /var/www/exfusion.net/html/test.php at line 23

This is when we’re attempting to upsert data to Couchbase. We’re running PHP 7.0
PHPInfo for Couchbase is:

couchbase

couchbase support	enabled
extension version	2.2.2
libcouchbase runtime version	2.6.3 (git: 822615ccbeecb9107bc4c02616b41aed6d9938c0)
libcouchbase headers version	2.6.3 (git: 822615ccbeecb9107bc4c02616b41aed6d9938c0)
Directive	Local Value	Master Value
couchbase.log_level	WARN	WARN

avsej · October 3, 2016, 9:24am

are there any other messages in the log? is there something specific about this particular upsert?

EdanBrooke · October 3, 2016, 1:05pm

No other messages in the log. The code is as follows.

// Own checks / add a key to Couchbase and deliver it.
try {
  $couchResult = $couchbase->bucket->get("store_registry");
} catch (Exception $ex) {
  return false;
}
$couchData = json_decode(json_encode($couchResult->value), true);
$rand = "rankupgd-" . md5(uniqid("stump", true));
$newCode = array(
  "id" => $rand,
  "package" => "RANK_UPGRADE_CODE",
  "raw" => null,
  "valid" => true
);
 $couchData["active_codes"][] = $newCode;
if($couchbase->bucket->upsert("store_registry", array())){
  die("It worked and nobody has to be shot.");
}

Oh, and $couchbase is instantiated as such:

<?php
namespace Exfusion;
use \CouchbaseCluster;
class Couchbase {
  public $cluster;
  public $bucket;
  function __construct() {
    $this->cluster = new CouchbaseCluster(COUCHBASE_HOST);
    $this->bucket = $this->cluster->openBucket(COUCHBASE_BUCKET, COUCHBASE_PASSWORD);
    $COUCHBASE_DEFAULT_DECOPTS = array(
        'jsonassoc' => true
    );
    $this->bucket->setTranscoder(couchbase_default_encoder("couchbase_default_encoder"), function($bytes, $flags, $datatype) {
        if ($flags == 0) {
            $flags = COUCHBASE_CFFMT_JSON;
        } //$flags == 0
        return couchbase_default_decoder($bytes, $flags, $datatype);
    });
  }
}

$couchbase = new Couchbase;

Then the bucket is called with $couchbase->bucket.

Note that in this specific test file I’ve disregarded the actual data I want to upsert and I’m just passing array() - this is after trying passing the actual data with the same result.

EdanBrooke · October 4, 2016, 8:34pm

Anybody got any ideas? We’ve not resolved this as of yet.

avsej · October 4, 2016, 8:47pm

Could you set couchbase.log_level = TRACE and show the logs?
http://developer.couchbase.com/documentation/server/4.5/sdk/php/collecting-information-and-logging.html

EdanBrooke · October 6, 2016, 2:32pm

The log file is created but empty after executing the script. Tried also with TRACE as well as DEBUG.

avsej · October 6, 2016, 2:41pm

Maybe you have error_log disabled in php.ini? http://php.net/error_log

EdanBrooke · October 6, 2016, 2:44pm

Thanks for your help thus far but that’s not the problem

avsej · October 6, 2016, 2:53pm

catch_workers_output = yes

EdanBrooke · October 6, 2016, 2:55pm

Yay, thanks. Error is as follows:

[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,INFO] (pcbc/bucket L:182) New lcb_t instance has been initialized. I=0x55b67f265090"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:89 I:0) Preparing providers (this may be called multiple times)"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:99 I:0) Provider FILE is DISABLED"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:96 I:0) Provider CCCP is ENABLED"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:96 I:0) Provider HTTP is ENABLED"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:99 I:0) Provider MCRAW is DISABLED"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,TRAC] (confmon L:292 I:0) Start refresh requested"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,TRAC] (confmon L:271 I:0) Current provider is CCCP"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,INFO] (cccp L:118 I:0) Requesting connection to node datastore.exfusion.net:11210 for CCCP configuration"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:416 I:0) <datastore.exfusion.net:11210> (HE=0x55b67f268580) Creating new connection because none are available in the pool"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:321 I:0) <datastore.exfusion.net:11210> (HE=0x55b67f268580) Starting connection on I=0x55b67f268a10"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,INFO] (connection L:450 I:0) <datastore.exfusion.net:11210> (SOCK=0x55b67f268b50) Starting. Timeout=2000000us"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,TRAC] (connection L:267 I:0) <datastore.exfusion.net:11210> (SOCK=0x55b67f268b50) Got event handler for new connection"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,TRAC] (connection L:314 I:0) <datastore.exfusion.net:11210> (SOCK=0x55b67f268b50) Scheduling asynchronous watch for socket."
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,TRAC] (connection L:267 I:0) <datastore.exfusion.net:11210> (SOCK=0x55b67f268b50) Got event handler for new connection"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,INFO] (connection L:116 I:0) <datastore.exfusion.net:11210> (SOCK=0x55b67f268b50) Connected "
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (connection L:123 I:0) <datastore.exfusion.net:11210> (SOCK=0x55b67f268b50) Successfuly set TCP_NODELAY"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:271 I:0) <datastore.exfusion.net:11210> (HE=0x55b67f268580) Received result for I=0x55b67f268a10,C=0x55b67f268b50; E=0x0"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:223 I:0) <datastore.exfusion.net:11210> (HE=0x55b67f268580) Assigning R=0x55b67f268530 SOCKET=0x55b67f268b50"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (ioctx L:101 I:0) <datastore.exfusion.net:11210> (CTX=0x55b67f269b70,unknown) Pairing with SOCK=0x55b67f268b50"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (negotiation L:368 I:0) <datastore.exfusion.net:11210> (SASLREQ=0x55b67f2684a0) Found feature 0x3 (TCP NODELAY)"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (ioctx L:151 I:0) <datastore.exfusion.net:11210> (CTX=0x55b67f269b70,sasl) Destroying. PND=0,ENT=1,SORC=1"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (ioctx L:101 I:0) <datastore.exfusion.net:11210> (CTX=0x55b67f271fb0,unknown) Pairing with SOCK=0x55b67f268b50"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (ioctx L:151 I:0) <datastore.exfusion.net:11210> (CTX=0x55b67f271fb0,bc_cccp) Destroying. PND=0,ENT=1,SORC=1"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,INFO] (lcbio_mgr L:491 I:0) <datastore.exfusion.net:11210> (HE=0x55b67f268580) Placing socket back into the pool. I=0x55b67f268a10,C=0x55b67f268b50"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,INFO] (confmon L:174 I:0) Setting new configuration. Received via CCCP"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (bootstrap L:55 I:0) Instance configured!"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:89 I:0) Preparing providers (this may be called multiple times)"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:99 I:0) Provider FILE is DISABLED"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:96 I:0) Provider CCCP is ENABLED"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:99 I:0) Provider HTTP is DISABLED"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (confmon L:99 I:0) Provider MCRAW is DISABLED"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,INFO] (pcbc/bucket L:243) lcb_t instance has been connected. I=0x55b67f265090"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,INFO] (lcbio_mgr L:407 I:0) <datastore.exfusion.net:11210> (HE=0x55b67f268580) Found ready connection in pool. Reusing socket and not creating new connection"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (lcbio_mgr L:223 I:0) <datastore.exfusion.net:11210> (HE=0x55b67f268580) Assigning R=0x55b67f299100 SOCKET=0x55b67f268b50"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (ioctx L:101 I:0) <datastore.exfusion.net:11210> (CTX=0x55b67f299180,unknown) Pairing with SOCK=0x55b67f268b50"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,DEBG] (server L:552 I:0) <datastore.exfusion.net:11210> (SRV=0x55b67f276010,IX=0) Setting initial timeout=2498ms"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,EROR] (pcbc/store L:229) Failed to encode value for before storing. I=0x55b67f265090"
[06-Oct-2016 14:54:10] WARNING: [pool www] child 21136 said into stderr: "NOTICE: PHP message: [cb,EROR] (pcbc/store L:262) Failed to schedule upsert commands (0 out of 1 sent). I=0x55b67f265090"

I believe that the lines of interest are:

NOTICE: PHP message: [cb,EROR] (pcbc/store L:229) Failed to encode value for before storing. I=0x55b67f265090
NOTICE: PHP message: [cb,EROR] (pcbc/store L:262) Failed to schedule upsert commands (0 out of 1 sent). I=0x55b67f265090

avsej · October 6, 2016, 3:31pm

couple notes:

do you really upsert empty array?
do you use custom encoder?
do you know that empty PHP array gives [] and not {} in JSON? To get JSON object, you have to specify new stdClass()

EdanBrooke · October 6, 2016, 3:34pm

Yes!

    $COUCHBASE_DEFAULT_DECOPTS = array(
        'jsonassoc' => true
    );
    $this->bucket->setTranscoder(couchbase_default_encoder("couchbase_default_encoder"), function($bytes, $flags, $datatype) {
        if ($flags == 0) {
            $flags = COUCHBASE_CFFMT_JSON;
        } //$flags == 0
        return couchbase_default_decoder($bytes, $flags, $datatype);
    });

This is what we’re using in an attempt to fix a flags issue that you helped us with another time.
Removing that has solved our upsert issue but of course means that the issue with flags is there again. Any ideas? Thank you

avsej · October 6, 2016, 3:41pm

you setting encoder incorrectly, it should be

$COUCHBASE_DEFAULT_DECOPTS = array(
    'jsonassoc' => true
);
$bucket->setTranscoder(
    "couchbase_default_encoder",
    function($bytes, $flags, $datatype) {
        if ($flags == 0) {
            $flags = COUCHBASE_CFFMT_JSON;
        } //$flags == 0
        return couchbase_default_decoder($bytes, $flags, $datatype);
    }
);

This is invocation of the encoder, but you have to pass name of the function or function object. What you are passing is the result of encoder invocation:

$res = couchbase_default_encoder("couchbase_default_encoder");
var_dump($res);

The output of the script above is:

array(3) {
  [0]=>
  string(25) "couchbase_default_encoder"
  [1]=>
  int(67108864)
  [2]=>
  int(0)
}

avsej · October 6, 2016, 3:42pm

oh, btw in 2.2.3 “the flag issue” should be fixed by default. give it a try

EdanBrooke · October 6, 2016, 3:43pm

Will do! Thanks, you’ve been very helpful and it all seems to be working now.

avsej · October 6, 2016, 3:45pm

did you try 2.2.3 release?

EdanBrooke · October 6, 2016, 3:45pm

During this issue I’ve re-installed Couchbase C libraries and PHP extension two or three times. Would that’ve done it, I assume?

EDIT: Yes.

couchbase
couchbase support	enabled
extension version	2.2.3
libcouchbase runtime version	2.6.3 (git: 822615ccbeecb9107bc4c02616b41aed6d9938c0)
libcouchbase headers version	2.6.3 (git: 822615ccbeecb9107bc4c02616b41aed6d9938c0)

Should I remove the custom transcoder?

avsej · October 6, 2016, 3:55pm

yes, it will try to use json decoder if flags are zero