We're using Newrelic to measure our Python/Django application performance. Newrelic is reporting that across our system "Memcached" is taking an average of 12ms to respond to commands.
Drilling down into the top dozen or so web views (by # of requests) I can see that some Memcache get take up to 30ms; I can't find a single use of Memcache get that returns in less than 10ms.
More details on the system architecture:
Currently we have four application servers each of which has a memcached member. All four memcached members participate in a memcache cluster.
We're running on a cloud hosting provider and all traffic is running across the "internal" network (via "internal" IPs)
When I ping from one application server to another the responses are in ~0.5ms
Isn't 10ms a slow response time for Memcached?
As far as I understand if you think "Memcache is too slow" then "you're doing it wrong". So am I doing it wrong?
Here's the output of the memcache-top command:
memcache-top v0.7 (default port: 11211, color: on, refresh: 3 seconds)
INSTANCE USAGE HIT % CONN TIME EVICT/s GETS/s SETS/s READ/s WRITE/s
cache1:11211 37.1% 62.7% 10 5.3ms 0.0 73 9 3958 84.6K
cache2:11211 42.4% 60.8% 11 4.4ms 0.0 46 12 3848 62.2K
cache3:11211 37.5% 66.5% 12 4.2ms 0.0 75 17 6056 170.4K
AVERAGE: 39.0% 63.3% 11 4.6ms 0.0 64 13 4620 105.7K
TOTAL: 0.1GB/ 0.4GB 33 13.9ms 0.0 193 38 13.5K 317.2K
(ctrl-c to quit.)
** Here is the output of the top command on one machine: **
(Roughly the same on all cluster machines. As you can see there is very low CPU utilization, because these machines only run memcache.)
top - 21:48:56 up 1 day, 4:56, 1 user, load average: 0.01, 0.06, 0.05
Tasks: 70 total, 1 running, 69 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.0%us, 0.0%sy, 0.0%ni, 99.7%id, 0.0%wa, 0.0%hi, 0.0%si, 0.3%st
Mem: 501392k total, 424940k used, 76452k free, 66416k buffers
Swap: 499996k total, 13064k used, 486932k free, 181168k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
6519 nobody 20 0 384m 74m 880 S 1.0 15.3 18:22.97 memcached
3 root 20 0 0 0 0 S 0.3 0.0 0:38.03 ksoftirqd/0
1 root 20 0 24332 1552 776 S 0.0 0.3 0:00.56 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
4 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0
5 root 20 0 0 0 0 S 0.0 0.0 0:00.02 kworker/u:0
6 root RT 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
7 root RT 0 0 0 0 S 0.0 0.0 0:00.62 watchdog/0
8 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 cpuset
9 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 khelper
...output truncated...