Fetched values incorrectly interpreted as long when using igbinary serialization

[orcinus]

Experiencing basically the same thing as issue #202.
No clue why @ddrager closed that one and what the "configuration issue" was (we have a pretty clear-cut configuration).

In our case, a particular igbinary serialized array keeps getting incorrectly interpreted as a long, and fails with "Memcached::get(): could not read long value, too big".

@ddrager's theory on why this is happening seems solid / matches what we're seeing. We get the error for one particular client site, for one particular key, with one particular set of values. When the value stored changes, it's fine.

If there's anything i can do to help debug this, let me know.
I'm not sure what the value that causes this is (as i obviously can't get it from the cache, and when i get notified about the error, it's usually already too late and it's been overwritten).

The contents of the array stored looks something like this:

[ 'checksum' => string (32) "ca693020b1379ace7d7fa7f9f61c7678",
'value' => array (6)
['0' => string (9) "cctca2017"
'id' => string (9) "cctca2017"
'1' => string (10) "2017-02-16"
'events_start' => string (10) "2017-02-16"
'2' => string (10) "2017-02-16"
'events_end' => string (10) "2017-02-16"]]

Serialization is, as i've mentioned, using igbinary. This does not appear to occur when using internal PHP serializer.

[orcinus]

Oh, and before anyone asks - we're not mixing Memcache and Memcached, and we've flushed and restarted MC when switching over to igbinary.

[orcinus]

As a temporary fix, we're appending a fixed string at the beginning of every value we store (before serialization). E.g.

"padding" => "abcabcabcabc"

... as the first element of the array. This appears to have completely eliminated the issue for now, which is a good indication that the original issue is exactly as @ddrager originally assumed - if the first characters of a binary happen to match one of your data type signatures, php-memcached incorrectly decodes it as the wrong data type.

[orcinus]

(I hope i don't have to explain how silly the fact we're forced to use this as a "fix" is.)

[sodabrew]

Great hunch there! In other cases like compression we use the flags to indicate the data type. I will double check the code but flags should be the way to identify igbinary data encodings.

[sodabrew]

Yes, flags is the mechanism that's used. There's no inspection of the content to try and match it to a serialization type.

Could you provide a concise reproduction case? Something like:

$m = new Memcached();
$m->addServer ("127.0.0.1", 11211);
$m->setOption(Memcached::OPT_SERIALIZER, Memcached::SERIALIZER_IGBINARY);

$m->set('foo', $value);
$data = $m->get('foo');

assert($data == $value) ...

[sodabrew]

What version of php-memcached are you using? What version of igbinary?

[orcinus]

I can't offer you an exact repro case, because this happens randomly, for a "lucky" binary sequence that happens to get interpreted as a long. I can't "get" that sequence for obvious reasons (it fails). Perhaps the only way to do it would be to immediately exec a shell script that gets the raw data from MC when the exception pops up, but i'm hesitant to do something like that on a live production server (it happens too sporadically to trigger it in a dev environment).

That said, it goes something like this:

$m = new Memcached();
$m->setOption(Memcached::OPT_SERIALIZER, Memcached::SERIALIZER_IGBINARY);
$m->setOption(Memcached::OPT_NO_BLOCK, TRUE);
$m->addServer ("192.168.x.x", 11211);

$data = ['0' => "cctca2017",  'id' => "cctca2017",
         '1' => "2017-02-16", 'events_start' => "2017-02-16",
         '2' =>"2017-02-16",  'events_end' => "2017-02-16"];

$key = "bootstrap:cctca2017:Journal-init";

// We're saving an md5-hashed copy of the key alongside the data for verification purposes.
// Long story, but we had some data integrity issues way back that were eventually resolved,
// but we left this "feature" in because it's currently not hurting anything anyway. Safe to
// ignore in the context of the reported issue, but mentioning it for completeness' sake.

$checksum = md5($key);
$data = ["checksum" => $checksum, "value" => $data];

$m->set($key, $value);
$data = $m->get($key);

// Nothing to assert here, the above get() results in an exception as follows:
// "Memcached::get(): could not read long value, too big"

We were using php-memcached 2.1.0 at the time i've originally reported the issue, we're at 2.2.0 right now. Ever since i've added that padding value, the issue hasn't been recurring at all.

Not sure about the igbinary version, i'll check with my devops colleague tomorrow.

[orcinus]

We're on igbinary 2.0.1.

[sodabrew]

Since is happening php-memcached 2.2.0, I'm tagging it for a 2.3.0 fix.

But, frankly, unless this is reported to also happen with php-memcached 3.x with PHP 7.x, it's a low priority for me.

[chrisminett]

We've run into the same issue described in the OP - "Memcached::get(): could not read long value, too big" when reading a value which was originally stored as an associative array.

We never saw this on our dev environments (php-memcached 2.1.0 w/ igbinary via MacPorts), but saw it on our QA/UAT systems which are using php-memcached 2.2.0 without igbinary. A simple restart of the Memcache server solved it, so we thought we'd be safe.

When rolling out to production environment (same versions as UAT), we updated all app code first and saw this warning as we expected. Once all app code was updated to use php-memcached, we restarted each of our Memcache servers. Everything seemed fine at first, but then the warning came back. At this point, no code should have been using php-memcache.

@sodabrew's comment about flags seems to make sense for what we're seeing. The problem occurs for us when the stored value has flag:1 (long) rather than the expected flag:4 (serialized). We can see this with the value, using Harun Yayli's memcache.php utility.

We can see that on one of our older systems that's still using php-memcache, the array values there are stored with flag:1. So it seems that somewhere, somehow, even after restarting our Memcache servers, these problem values were written back via php-memcache rather than php-memcached. Either that, or it's a really intermittent bug where the wrong flag value is assigned during set() !

We've restarted each Memcache server again, and hoping that we don't see the warnings appear again.