[PECL-DEV] [memcache/PECL] Performance problems with set & data over 8KB

[Antony Dovgal]

Probably this is somehow related to the problem I've met in the past:
http://cvs.php.net/viewcvs.cgi/pecl/memcache/memcache.c?r1=1.8&r2=1.9

The problem is that two subsequent writes to memcached daemon are MUCH more slower than one writing the same data in one chunk.

This was the reason why I had to patch PECL/memcache 2 years ago and make it write the data and the delimiter ("\r\n") in one call.
I don't remember details of the conversation I had with Brad and Anatoly, but I still don't know the reasons of this behavior.



On 23.04.2006 21:31, Mikael Johansson wrote:
> A very strange problem indeed, however it does not appear to be caused by
> the memcache extension itself but rather something to do with the chunksize
> of PHPs stream io functions.
> 
> The problem seem to occur when running against localhost (over the lo
> interface), not when using an internetworked server. Strace show that the
> threshold is 8192 bytes and incidentally that's also the default stream
> chunksize (CHUNK_SIZE defined in main/streams.c)
> 
>  send(3, "set 09335d56360072a4302bdd514a4a"..., 8192, 0) = 8192
> 
> versus
> 
>  send(3, "set 09335d56360072a4302bdd514a4a"..., 8192, 0) = 8192
>  send(3, "\n", 1, 0)                     = 1
> 
> Setting the chunksize to something larger such as 16k (using
> php_stream_set_chunk_size(mmc->stream, 16382); in _mmc_open) just raises the
> threshold to 16k.
> 
> Stranger still is that the problem occur within specific message size
> intervals
> 
> 7168 bytes: 8680 set/s
> 8192 bytes: 25 set/s
> ..
> 23552 bytes: 25 set/s
> 24576 bytes: 3989 set/s
> ..
> 31744 bytes: 3287 set/s
> 32768 bytes: 578 set/s
> ..
> 36864 bytes: 385 set/s
> 37888 bytes: 2957 set/s
> ..
> 43008 bytes: 2542 set/s
> 44032 bytes: 853 set/s
> ..
> 48128 bytes: 204 set/s
> 49152 bytes: 2202 set/s
> ..
> 56320 bytes: 1666 set/s
> 57344 bytes: 143 set/s
> ..
> 65536 bytes: 231 set/s
> 66560 bytes: 1360 set/s
> 
> There's definitely a pattern here, my best guess at the time is some strange
> interaction between PHPs chunksize and the kernels send buffer or shared
> memory buffer size (loopback uses shared memory?)
> 
> Using Linux 2.6.12-13mdk, PHP 4.4.2 on a P4 1.8ghz. Clearing out all
> iptables rules has no effect, fiddling with values in /proc/sys/net/ipv4 has
> not effect as far as I can tell (though I haven't tried all the settings)
> 
> I really am at a loss here; any ideas?
> 
> //Mikael
> 
> ----- Original Message ----- 
> From: "Jean-François Bustarret" <jfbubus at gmail.com>
> To: <memcached at lists.danga.com>; <pecl-dev at lists.php.net>
> Sent: Friday, March 31, 2006 10:06 AM
> Subject: [PECL-DEV] [memcache/PECL] Performance problems with set & data
> over 8KB
> 
> 
> I have major scalabity problems (very high load with 100 or 200 memcache
> read/writes per sec) using memcached (PECL 2.0.0/PHP 5.0.5 client).
> 
> It looks like I have a problem writing data over 8KB...Here is a test script
> :
> 
> <?php
> 
> $memcache_obj = memcache_connect("localhost", 11211);
> 
> for ($step=6; $step < 10; $step++) {
>         $key=md5(uniqid(rand()));
>         $value = str_repeat(md5(uniqid(rand())), $step*1024/32);
>         printf("\n%d KB : ", strlen($value)/1024);
> 
>         $start = microtime(true);
>         for($i=0;$i < 1000 ; $i++)
>                 $memcache_obj->set($key, $value, 0, 0);
>         $end = microtime(true);
>         printf(" %d set/s", 1000/($end-$start));
>         $start = microtime(true);
>         for($i=0;$i < 1000 ; $i++)
>                 $var = $memcache_obj->get($key);
>         $end = microtime(true);
>         printf(" %d get/s", 1000/($end-$start));
> }
> ?>
> The results are :
> 
> 6 KB :  14197 set/s 15549 get/s
> 7 KB :  13367 set/s 15287 get/s
> 8 KB :  24 set/s 13332 get/s
> 9 KB :  24 set/s 13198 get/s
> 
> With a 1 byte increment, the results are :
> [...]
> 8143 B :  13590 set/s 13089 get/s
> 8144 B :  24 set/s 13279 get/s
> [...]
> 
> Doing a strace -r T shows this :
> [...]
>      0.039552 recv(3, "STORED\r\n", 8192, 0) = 8 <0.000045>
>      0.000143 send(3, "set d7e283883d2316ba14484df6d73c"..., 8192, 0) = 8192
> <0.000088>
>      0.000178 send(3, "baf9272ea0a2ad667cdc45df3c767674"..., 49, 0) = 49 <
> 0.000046>
>      0.000129 poll([{fd=3, events=POLLIN|POLLERR|POLLHUP, revents=POLLIN}],
> 1, 1000) = 1 <0.039473>
>      0.039562 recv(3, "STORED\r\n", 8192, 0) = 8 <0.000045>
> [...]
> 
> On the memcache daemon, the strace is :
> [...]
>      0.000108 write(7, "STORED\r\n", 8) = 8 <0.000046>
>      0.000126 setsockopt(7, SOL_TCP, TCP_CORK, [0], 4) = 0 <0.000096>
>      0.000168 read(7, "set e3888bfaae66969d52b1a37b8745"..., 16384) = 8192 <
> 0.000047>
>      0.000128 read(7, 0x805a3d0, 8192)  = -1 EAGAIN (Resource temporarily
> unavailable) <0.000043>
>      0.000135 setsockopt(7, SOL_TCP, TCP_CORK, [1], 4) = 0 <0.000045>
>      0.000133 read(7, 0xb779901d, 1073) = -1 EAGAIN (Resource temporarily
> unavailable) <0.000044>
>      0.000112 gettimeofday({1143792299, 307963}, NULL) = 0 <0.000043>
>      0.000113 gettimeofday({1143792299, 308075}, NULL) = 0 <0.000043>
>      0.000114 epoll_wait(0x4, 0x8050280, 0x400, 0x989) = 1 <0.038448>
>      0.038519 gettimeofday({1143792299, 346709}, NULL) = 0 <0.000044>
>      0.000115 read(7, "26f8ea48f7b44f912142e6cba0026063"..., 1073) = 1073 <
> 0.000051>
>      0.000133 time(NULL)                = 1143792299 <0.000043>
>      0.000108 time(NULL)                = 1143792299 <0.000043>
> [...]
> 
> Does someone have a clue ?
> --
> Jean-François Bustarret
> http://www.jeuxdecartes.net
> 
> 
> 


-- 
Wbr, 
Antony Dovgal