possible bug in PHP API 1.0.8

[Justin Matlock]

Sorry for the extra-long email -- I just wanted to explain my thinking here,
and go into excessive detail so someone can prove me wrong. :)

I'm using the latest CVS snapshot of memcached, and the 1.0.8 PHP API, and
the latest PHP 4.3.3 CVS tree, under Linux 2.4.21, Apache 2.0.47.  It was
all working great on my devel box, but when I moved it over to production, I
started getting a ton of "_load_items(): Bytes read is greater than
requested data size." errors.  But the thing is:  the development box and
production box are using the exact same memcached server.  They run the same
OS, the same PHP version, the same *everything*.  They're even the same
hardware (one serial number apart).  The *only* difference is the production
box is on the same subnet as the memcached server -- the development one is
on a different one.  Of course, I start doing a lot more testing on the
development box, and I notice I was getting them over there too, just not as
many.

So I modified the script to give me more information (patch follows):

=================
1063,1064c1063,1064
<                                       $this->_debug("_load_items(): Bytes
read is greater than requested data size.");
<
---
>                                       $this->_debug("_load_items(): Bytes
read ($bytes_read) is greater than requested data size ($len).");
>                                       $this->_debug("_load_items(): I
received \"".urlencode($buf)."\"");
=================

Here's what I'm getting in my logs (I modified the debug handler to use my
custom logging routines) -- add 7 for the "\r\nEND\r\n".  So we're getting
back 2 characters instead of 1:

(Data is "0")
[03Aug12 154857] (INFO) #/profile/# <10.1.0.11> (u:1) _load_items(): Bytes
read (9) is greater than requested data size (1).
[03Aug12 154857] (INFO) #/profile/# <10.1.0.11> (u:1) _load_items(): I
received "%0A2%0D%0AEND%0D%0A"

(Data is "-1")
[03Aug12 154926] (INFO) #/profile/# <10.1.0.11> (u:1) _load_items(): Bytes
read (10) is greater than requested data size (2).
[03Aug12 154926] (INFO) #/profile/# <10.1.0.11> (u:1) _load_items(): I
received "%0A-1%0D%0AEND%0D%0A"

(Data is a whole lot more than "0"  :) ):
[03Aug12 154926] (INFO) #/profile/# <10.1.0.11> (u:1) _load_items(): Bytes
read (165) is greater than requested data size (157).
[03Aug12 154926] (INFO) #/profile/# <10.1.0.11> (u:1) _load_items(): I
received "%0Aa%3A1%3A%7Bi%3A0%3Ba%3A5%3A%7Bs%3A7%3A%(for clarity, I cut off
the end)

The thing that sucks is I can't replicate this reliably.  I can hit reload
over and over, and it will only happen 1 out of every 10 or so times, on
random data coming back.  It's not just numerics, not text...

I sniffed the connection, and here's one that barfed coming back from the
server:

VALUE profile_1_7028277b0e9405414ea71de0bdde789f_rank 0 2\r\n-1\r\nEND\r\n

Looks okay to me; it follows the protocol, and there are two characters in
the response.  Memcached isn't the culprit.  So on to the API...

The problem appears to be with this line:
$line = substr($line, strpos($line, "\r\n")+1, strlen($line));

I added some more logging lines before and after it to see what the 'pre'
and 'post' parsing results were.

By only doing +1, you're just stripping off the \r.  It's always letting a
\n through, even though it should be stripping it off.  The strange thing to
me is sometimes it only lets a \n through, but sometimes it lets
"\n0\r\nEND\r\n" through (this is when it breaks).  I'm still trying to
track down why this is happening...

In summary; I changed that +1 to a +2, and it always strips off the
remaining \n.  From there, it works great.  I just pushed about 300 pages,
and all came back without errors...

Final patch:
==============
999c999
<                                       $line = substr($line, strpos($line,
"\r\n")+1, strlen($line));
---
>                                       $line = substr($line, strpos($line,
"\r\n")+2, strlen($line));
===============

"It works for me".  :)

Justin

----- Original Message ----- 
From: "Ryan Gilfether" <ryan@gilfether.com>
To: <memcached@lists.danga.com>
Sent: Monday, August 11, 2003 12:37 AM
Subject: Re: PHP API 1.0.7


> yes, you're right, I didnt notice that a newline got included at the end
> of the file. I'll be sure to remove it in future releases. Thanks for
> pointing it out.
>
> Ryan
>
> Lisa Marie Seelye wrote:
> > On Sat, 2003-08-09 at 13:08, Ryan Gilfether wrote:
> >
> >>A new version of the PHP API has been completed, verson 1.0.7.
> >>I've had some requests for adding PHPDocs style comments to the API.
> >>Along with that 3 new function have been added
> >>error() - returns an error code for the last error genterated
> >>error_string() - returns a string with a description of the error
> >>error_clear() - clears the last error
> >>
> >>Ryan
> >
> >
> > Not to be incredibly anal, but the .php file should not have any
> > newlines after the closing ?> tag -- this tends to mess with headers
> > should it be included after headers have been sent. :(
> >
> >
>
> -- 
> Ryan Gilfether
> Software Engineer
> http://www.gilfether.com
>
>