May 20, 2013

Maatkit Now Supports Memcached

Have you ever wondered how optimized your Memcached installation is? There is a common misconception that one doesn’t have to think too deeply about Memcached performance, but that is not true. If your setup is inefficient, you could:

  • Burn Memory
  • Waste Network Round-Trips
  • Store Keys That Never Get Retrieved
  • Have a Low Cache Hit Ratio (i.e. query MySQL too much)
  • Suffer a fate too horrible to contemplate.

Percona does a lot of consulting around Memcached, so we try to take a quantitative, scientific approach to measuring memcached performance, just like everything else we do.

memcached is basically a key-value in-memory database, so it works well to analyze its traffic with Maatkit’s mk-query-digest tool. You can now use mk-query-digest to get “query event” information and report on memcached effectiveness. As far as we know, this is the first and only tool of its kind.

The output is very similar to that which would be displayed for MySQL queries. Commands are fingerprinted so that similar things can be aggregated together. The output begins with an overall report:

We can see that 77% of commands (cmds) were get, 17% set, 4% delete and 4 incr (increment) cmds. At present, Memc_error only refers to gets (or, retrieval cmds in general) that were interrupted (some things are TODO). Memc_miss is for any cmd that resulted in a NOT_FOUND result. So in this case, 15% of all cmds tried to do something with a nonexistent key.

The next bit aggregates similar queries into classes and prints out the most expensive ones. Here’s the top one:

Interestingly, apparently 17% of all “get TEST_KEY” were interrupted (Memc_error), probably by the TCP connection being closed client-side.

You’ll notice 100% Memc_get. This is a result of the default –report and –group-by, which is “fingerprint” just like for slow query logs. So the fingerprint for this event is “get TEST_KEY” and since the cmd is “get”, 100% Memc_get. There’s another way to aggregate — by the fingerprinted key, omitting the verb (get/set/etc). To do this, you’d specify key_print as the group-by value. More details are below.

This feature is still in beta. Some things are TODO; the report format could be cleaned up a little, etc. But we’re releasing early and often, and we’re calling on the community to help us out with testing! Here’s how:

  1. Get the latest mk-query-digest
  2. Capture memcached network traffic with tcpdump
  3. Parse memcached network traffic with mk-query-digest
  4. Ponder the results, or consider a different –report option

In code:

Depending on what you’re interested in, you may want to try these other reports:

  • –report key_print: Group events by a fingerprinted version of keys. So “get user_123″ and “set user_456″ are grouped together because the key_print for both is “user_?”. Doing this, per-class results will have various percentages for Memc_get, Memc_set, etc. instead of 100% Memc_cmd like above.
  • –report key: Like key_print but the keys are not fingerprinted so the two examples above are different classes because “user_123″ != “user_456″. This would allow you to see per-key stats. Maybe, for example, how often a certain key is get’ed in comparison to other keys. (I.e. “what’s the most popular get’ed or set’ed key” etc.)
  • –report cmd: Group events by cmd. So “get user_123″ and “get whatever” are grouped together because both are “get” cmds. You may want to do this to see, for example, what percentage of get cmds miss, i.e. result in NOT_FOUND.

These instructions could change in the future — this blog post is not authoritative documentation. The most current documentation is always embedded in the tool itself, and is readable with perldoc! Let us know what you think. Please use the Maatkit mailing list and and post bug reports on Google Code.

About Ryan Lowe

Ryan is a Principal Consultant and team manager at Percona. He has experience with many database technologies in industries such as health care, telecommunications, and social networking.

Comments

  1. Piotr says:

    I have

    root@lb2:~# ./mk-query-digest –type memcached memc_tcpdump.txt
    # mk_query_digest:6381 6920 Use of uninitialized value in string eq at ./mk-query-digest line 5363, chunk 1.
    #
    # mk_query_digest:6381 6920 Use of uninitialized value in string eq at ./mk-query-digest line 5363, chunk 2.
    #

  2. Ryan says:

    Hey Piotr,

    How’d you capture tcpdump info? Also, it doesn’t yet understand IPv6. Send Daniel the tcpdump output. And let’s put bug reports on Google Code:)

  3. Gavin Towey says:

    When I try to use it, it just gives lots of these lines:

    ./mk-query-digest –type memcached memc_tcpdump.txt

    # mk_query_digest:6758 5136 tell() on closed filehandle at ./mk-query-digest line 2019.

  4. DLS says:

    I also get errors:

    # mk_query_digest:6758 29461 Use of uninitialized value in pattern match (m//) at mk-query-digest line 2045, chunk 2972.

    Here’s how I captured tcpdump:

    tcpdump -s 65535 -v -x -n -q -tttt -i any port 11211 > memc_tcpdump.txt

  5. Daniel says:

    For those having issues parsing memcached dumps, I’ll be happy to fix them, but I’ll need a sample of your dump file that’s causing the crash. If your dump file doesn’t have private data, could you please create a new issue at http://code.google.com/p/maatkit/issues/list and upload the dump file? Else, you can email me your dump file, I’ll fix it and keep your data private; the address is my name at percona.com.

    Also, if you haven’t tried the latest version already, try it: wget http://www.maatkit.org/trunk/mk-query-digest
    I fixed some similar issues last week with memc parsing.

  6. CaptTofu says:

    Hi there!

    I’m excited to try this out, but have similar problems shown here in the comments:

    mk_query_digest:6758 23474 Use of uninitialized value $source in pattern match (m//) at /usr/bin/mk-query-digest line 2045, chunk 180.

    Many lines of this – I even tried to make modifications to not apply the regex if not defined, but I’m not getting anywhere with it.

    The tcpdump command options:

    tcpdump -s 65535 -v -x -n -q -tttt -i any port 11211 > memc_tcpdump.txt

    Any suggestions?

    Thanks!

  7. Daniel says:

    CaptTofu, I see you commented on http://code.google.com/p/maatkit/issues/detail?id=544 and that you fixed this by removing the -v option from tcpdump?

    Currently, the tcpdump output must be like:

    2009-07-04 21:33:39.229179 IP 127.0.0.1.35126 > 127.0.0.1.11211: tcp 31
    0×0000: 4500 0053 1d2a 4000 4006 1f79 7f00 0001
    0×0010: 7f00 0001 8936 2bcb d4c3 3924 d4c8 1de4
    0×0020: 8018 0201 fe47 0000 0101 080a 0008 240b
    0×0030: 0008 240b 7365 7420 6d79 5f6b 6579 2030
    0×0040: 2030 2031 300d 0a53 6f6d 6520 7661 6c75
    0×0050: 650d 0a

    So you may need to tweak your tcpdump options to get the output correct. Any extra info will confuse the tcpdump parser and cause these kinds of errors.

  8. Daniel says:

    Due to loss of formatting, the above sample output is missing spaces before each hex dump line.

  9. CaptTofu says:

    Daniel,

    removing the -v helped, but a later run, even without the -v, gave me the error. It was a huge dump file, and strangely, while I was doing this, my amazon instance kicked me out and wouldn’t let me back in (not related I’m sure!) So I have no way of obtaining that file that was giving me problems.

  10. Andrei says:

    Nice post. I want to add that if you run memcached server on a non-11211 port, you need to add –watch-server to mk-query-digest or you will get “Packet is not to or from memcached server” error.

Speak Your Mind

*