memcached(8) loosing fd events...
John McCaskey
johnm at klir.com
Fri Aug 19 08:45:51 PDT 2005
I believe we've been experiencing this. We actually pulled
memcached/libmemcache/php-mcache out of production last week because
sometimes the server seemed to just hang on requests. I always thought
it was libmemcache's fault but after many hours and many attempted fixes
that did nothing I gave up on it and we just removed it for the moment.
John A. McCaskey
Software Development Engineer
Klir Technologies, Inc.
johnm at klir.com
-----Original Message-----
From: memcached-bounces at lists.danga.com
[mailto:memcached-bounces at lists.danga.com] On Behalf Of Sean Chittenden
Sent: Friday, August 19, 2005 4:11 AM
To: memcached at lists.danga.com
Subject: memcached(8) loosing fd events...
I'm not sure if this is an event(3) problem, a memcached(8) issue, or
even a FreeBSD kqueue(2) problem, but, I'm feeling rather vindicated
at the moment.
http://people.FreeBSD.org/~seanc/libmemcache/libmemcache-1.4.0.b2.tar.bz
2
In prep for 1.4, I've been putting together some additional regression
tests and have been hunting down various protocol state
synchronization issues, etc. After a few weeks of love with gdb(1)
and many bug fixes, in the end I very well could be chasing a wild
goose. After reaching the ultimate state of desperation and
frustration with gdb(1), I decided to attach ktrace(1) to the process
and sure enough:
85827 lt-benchmark RET read 8
85827 lt-benchmark CALL write(0x3,0x8050000,0x22)
85827 lt-benchmark GIO fd 3 wrote 34 bytes
"set bench_key 0 0 10\r
EEEEEEEEEE\r
"
85827 lt-benchmark RET write 34/0x22
85827 lt-benchmark CALL read(0x3,0x804f000,0x1000)
85827 lt-benchmark RET read -1 errno 35 Resource temporarily
unavailable
85827 lt-benchmark CALL read(0x3,0x804f000,0x1000)
85827 lt-benchmark RET read -1 errno 35 Resource temporarily
unavailable
85827 lt-benchmark CALL read(0x3,0x804f000,0x1000)
85827 lt-benchmark RET read -1 errno 35 Resource temporarily
unavailable
85827 lt-benchmark CALL read(0x3,0x804f000,0x1000)
85827 lt-benchmark RET read -1 errno 4 Interrupted system call
85827 lt-benchmark PSIG SIGINT SIG_DFL
The client fires off the command, and the server never responds. I
haven't been able to reproduce this when memcached(8) is being
ktrace(1)'ed, otherwise I'd present a complementary version from the
server side. So, my theories are this so far:
*) event(3) fails to execute the callback when an event is triggered.
*) there's a code path in memcached(8) that causes a fd event to not
be re-registered or for the client's fd state to not be set to
conn_write. I've been able to reproduce this with all of the major
commands (get, set, and add) with a high degree of regularity.
This is my favorite hypothesis since this would explain why the
server ceases to have this problem when I renice it to +20.
*) if I renice memcached(8) to +20, the problem goes away. Maybe this
is a kqueue(2) race condition. Possible, but *highly* unlikely
given kqueue(2)'s workload in other daemons.
If I slam the server with thousands of ops per second (ie, 50+% CPU),
occasionally I've been able to see the server refuse to handle
connections from other fd's. It just doesn't read(2) in any data from
the client. I'm guessing that if an fd has an op, but it isn't
serviced by memcached(8) fast enough because memcached(8) is busy,
memcached(8) doesn't re-register the fd and any events on the fd are
lost.
Reniced:
Value size: 10
Num tests: 100000
Test Ops per second Total Time Time per Request
set 9905.273885 10.095632 0.000101
get 10083.104951 9.917580 0.000099
add 9645.432921 10.367601 0.000104
delete 11536.565548 8.668091 0.000087
Without, I can't even complete the set iterations. I haven't dug into
this yet, but, if someone has a bright idea or a suspicion, I'm all
ears. I'm also running into an interesting bit where my long_val test
is causing the connection to reset:
88933 lt-long_val CALL write(0x3,0x804d000,0xefe)
88933 lt-long_val GIO fd 3 wrote 3838 bytes
"set key-1-3811 0 0 3811\r
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE\r
"
88933 lt-long_val RET write 3838/0xefe
88933 lt-long_val CALL read(0x3,0x804c000,0x1000)
88933 lt-long_val GIO fd 3 read 8 bytes
"STORED\r
"
88933 lt-long_val RET read 8
88933 lt-long_val CALL write(0x3,0x804d000,0x10)
[end of ktrace(1) output, client returns connection reset when I try to
read(2) from the fd]
Under nominal or busy load conditions, I don't know that anyone
would've noticed this since a network/scheduler will slow things down
to the point that the server isn't vulnerable to these problems, but
over localhost on an idle box... all bets are off.
--
Sean Chittenden
More information about the memcached
mailing list