Patch: Collect per-object-type stats
Steven Grimm
sgrimm at facebook.com
Fri Mar 2 03:12:15 UTC 2007
This is a patch we're running to collect more precise statistics on the
objects in our caches. In addition to a cachewide "hit" and "miss"
count, this tracks get/set/hit/miss stats based on key prefixes, where a
"prefix" is delimited by a character of your choice. So, for example, if
you use the default delimiter of ":", then "user:12345" and "user:34567"
are considered to both be of type "user". Stats collection does have a
(small) CPU impact, so it may be turned on and off at runtime. In the
multithreaded version of the code, there is usually enough CPU time to
spare; we leave it turned on.
Tracking stats with per-object-type granularity is valuable because
different object types may have very different behavior that's
impossible to discern from global stats; for example, the hit ratio on
some of our objects is substantially lower than on others.
This is a patch against the multithreaded branch since that's what we're
running. It should work with minimal modification on the single-threaded
source base -- pretty much just remove the lock/unlock calls. Note that
the MT branch can still be compiled without thread support, so you don't
have to actually use multiple threads to use this patch as is.
Comments welcome, as always. If I don't hear any objections I'll commit
this to the multithreaded branch in a little while.
-Steve
-------------- next part --------------
Index: stats.c
===================================================================
--- stats.c (revision 0)
+++ stats.c (revision 0)
@@ -0,0 +1,359 @@
+/* -*- Mode: C; tab-width: 4; c-basic-offset: 4; indent-tabs-mode: nil -*- */
+/*
+ * Detailed statistics management. For simple stats like total number of
+ * "get" requests, we use inline code in memcached.c and friends, but when
+ * stats detail mode is activated, the code here records more information.
+ *
+ * Author:
+ * Steven Grimm <sgrimm at facebook.com>
+ *
+ * $Id$
+ */
+#include "memcached.h"
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+
+/*
+ * Stats are tracked on the basis of key prefixes. This is a simple
+ * fixed-size hash of prefixes; we run the prefixes through the same
+ * CRC function used by the cache hashtable.
+ */
+typedef struct _prefix_stats PREFIX_STATS;
+struct _prefix_stats {
+ char *prefix;
+ int prefix_len;
+ unsigned long long num_gets;
+ unsigned long long num_sets;
+ unsigned long long num_deletes;
+ unsigned long long num_hits;
+ PREFIX_STATS *next;
+};
+
+#define PREFIX_HASH_SIZE 256
+static PREFIX_STATS *prefix_stats[PREFIX_HASH_SIZE];
+static int num_prefixes = 0;
+static int total_prefix_size = 0;
+
+void stats_prefix_init() {
+ memset(prefix_stats, 0, sizeof(prefix_stats));
+}
+
+/*
+ * Cleans up all our previously collected stats. NOTE: the stats lock is
+ * assumed to be held when this is called.
+ */
+void stats_prefix_clear() {
+ int i;
+ PREFIX_STATS *cur, *next;
+
+ for (i = 0; i < PREFIX_HASH_SIZE; i++) {
+ for (cur = prefix_stats[i]; cur != NULL; cur = next) {
+ next = cur->next;
+ free(cur->prefix);
+ free(cur);
+ }
+ prefix_stats[i] = NULL;
+ }
+ num_prefixes = 0;
+ total_prefix_size = 0;
+}
+
+/*
+ * Returns the stats structure for a prefix, creating it if it's not already
+ * in the list.
+ */
+static PREFIX_STATS *stats_prefix_find(char *key) {
+ PREFIX_STATS *pfs;
+ int hashval;
+ int length;
+
+ for (length = 0; key[length] != '\0'; length++)
+ if (key[length] == settings.prefix_delimiter)
+ break;
+
+ hashval = hash(key, length, 0) % PREFIX_HASH_SIZE;
+
+ for (pfs = prefix_stats[hashval]; NULL != pfs; pfs = pfs->next) {
+ if (! strncmp(pfs->prefix, key, length))
+ return pfs;
+ }
+
+ pfs = calloc(sizeof(PREFIX_STATS), 1);
+ if (NULL == pfs) {
+ perror("Can't allocate space for stats structure: calloc");
+ return NULL;
+ }
+
+ pfs->prefix = malloc(length + 1);
+ if (NULL == pfs->prefix) {
+ perror("Can't allocate space for copy of prefix: malloc");
+ free(pfs);
+ return NULL;
+ }
+
+ strncpy(pfs->prefix, key, length);
+ pfs->prefix[length] = '\0'; // because strncpy() sucks
+ pfs->prefix_len = length;
+
+ pfs->next = prefix_stats[hashval];
+ prefix_stats[hashval] = pfs;
+
+ num_prefixes++;
+ total_prefix_size += length;
+
+ return pfs;
+}
+
+/*
+ * Records a "get" of a key.
+ */
+void stats_prefix_record_get(char *key, int is_hit) {
+ PREFIX_STATS *pfs;
+
+ STATS_LOCK();
+ pfs = stats_prefix_find(key);
+ if (NULL != pfs) {
+ pfs->num_gets++;
+ if (is_hit) {
+ pfs->num_hits++;
+ }
+ }
+ STATS_UNLOCK();
+}
+
+/*
+ * Records a "delete" of a key.
+ */
+void stats_prefix_record_delete(char *key) {
+ PREFIX_STATS *pfs;
+
+ STATS_LOCK();
+ pfs = stats_prefix_find(key);
+ if (NULL != pfs) {
+ pfs->num_deletes++;
+ }
+ STATS_UNLOCK();
+}
+
+/*
+ * Records a "set" of a key.
+ */
+void stats_prefix_record_set(char *key) {
+ PREFIX_STATS *pfs;
+
+ STATS_LOCK();
+ pfs = stats_prefix_find(key);
+ if (NULL != pfs) {
+ pfs->num_sets++;
+ }
+ STATS_UNLOCK();
+}
+
+/*
+ * Returns stats in textual form suitable for writing to a client.
+ */
+char *stats_prefix_dump(int *length) {
+ char *format = "PREFIX %s get %llu hit %llu set %llu del %llu\r\n";
+ PREFIX_STATS *pfs;
+ char *buf;
+ int i, pos;
+ int size;
+
+ /*
+ * Figure out how big the buffer needs to be. This is the sum of the
+ * lengths of the prefixes themselves, plus the size of one copy of
+ * the per-prefix output with 20-digit values for all the counts,
+ * plus space for the "END" at the end.
+ */
+ STATS_LOCK();
+ size = strlen(format) + total_prefix_size +
+ num_prefixes * (strlen(format) - 2 /* %s */
+ + 4 * (20 - 4)) /* %llu replaced by 20-digit num */
+ + sizeof("END\r\n");
+ buf = malloc(size);
+ if (NULL == buf) {
+ perror("Can't allocate stats response: malloc");
+ STATS_UNLOCK();
+ return NULL;
+ }
+
+ pos = 0;
+ for (i = 0; i < PREFIX_HASH_SIZE; i++) {
+ for (pfs = prefix_stats[i]; NULL != pfs; pfs = pfs->next) {
+ pos += sprintf(buf + pos, format,
+ pfs->prefix, pfs->num_gets, pfs->num_hits,
+ pfs->num_sets, pfs->num_deletes);
+ }
+ }
+
+ STATS_UNLOCK();
+ strcpy(buf + pos, "END\r\n");
+
+ *length = pos + 5;
+ return buf;
+}
+
+
+#ifdef UNIT_TEST
+
+/****************************************************************************
+ To run unit tests, compile with $(CC) -DUNIT_TEST stats.c assoc.o
+ (need assoc.o to get the hash() function).
+****************************************************************************/
+
+struct settings settings;
+
+static char *current_test = "";
+static int test_count = 0;
+static int fail_count = 0;
+
+static void fail(char *what) { printf("\tFAIL: %s\n", what); fflush(stdout); fail_count++; }
+static void test_equals_int(char *what, int a, int b) { test_count++; if (a != b) fail(what); }
+static void test_equals_ptr(char *what, void *a, void *b) { test_count++; if (a != b) fail(what); }
+static void test_equals_str(char *what, const char *a, const char *b) { test_count++; if (strcmp(a, b)) fail(what); }
+static void test_equals_ull(char *what, unsigned long long a, unsigned long long b) { test_count++; if (a != b) fail(what); }
+static void test_notequals_ptr(char *what, void *a, void *b) { test_count++; if (a == b) fail(what); }
+static void test_notnull_ptr(char *what, void *a) { test_count++; if (NULL == a) fail(what); }
+
+static void test_prefix_find() {
+ PREFIX_STATS *pfs1, *pfs2;
+
+ pfs1 = stats_prefix_find("abc");
+ test_notnull_ptr("initial prefix find", pfs1);
+ test_equals_ull("request counts", 0ULL,
+ pfs1->num_gets + pfs1->num_sets + pfs1->num_deletes + pfs1->num_hits);
+ pfs2 = stats_prefix_find("abc");
+ test_equals_ptr("find of same prefix", pfs1, pfs2);
+ pfs2 = stats_prefix_find("abc:");
+ test_equals_ptr("find of same prefix, ignoring delimiter", pfs1, pfs2);
+ pfs2 = stats_prefix_find("abc:d");
+ test_equals_ptr("find of same prefix, ignoring extra chars", pfs1, pfs2);
+ pfs2 = stats_prefix_find("xyz123");
+ test_notequals_ptr("find of different prefix", pfs1, pfs2);
+ pfs2 = stats_prefix_find("ab:");
+ test_notequals_ptr("find of shorter prefix", pfs1, pfs2);
+}
+
+static void test_prefix_record_get() {
+ PREFIX_STATS *pfs;
+
+ stats_prefix_record_get("abc:123", 0);
+ pfs = stats_prefix_find("abc:123");
+ test_equals_ull("get count after get #1", 1, pfs->num_gets);
+ test_equals_ull("hit count after get #1", 0, pfs->num_hits);
+ stats_prefix_record_get("abc:456", 0);
+ test_equals_ull("get count after get #2", 2, pfs->num_gets);
+ test_equals_ull("hit count after get #2", 0, pfs->num_hits);
+ stats_prefix_record_get("abc:456", 1);
+ test_equals_ull("get count after get #3", 3, pfs->num_gets);
+ test_equals_ull("hit count after get #3", 1, pfs->num_hits);
+ stats_prefix_record_get("def:", 1);
+ test_equals_ull("get count after get #4", 3, pfs->num_gets);
+ test_equals_ull("hit count after get #4", 1, pfs->num_hits);
+}
+
+static void test_prefix_record_delete() {
+ PREFIX_STATS *pfs;
+
+ stats_prefix_record_delete("abc:123");
+ pfs = stats_prefix_find("abc:123");
+ test_equals_ull("get count after delete #1", 0, pfs->num_gets);
+ test_equals_ull("hit count after delete #1", 0, pfs->num_hits);
+ test_equals_ull("delete count after delete #1", 1, pfs->num_deletes);
+ test_equals_ull("set count after delete #1", 0, pfs->num_sets);
+ stats_prefix_record_delete("def:");
+ test_equals_ull("delete count after delete #2", 1, pfs->num_deletes);
+}
+
+static void test_prefix_record_set() {
+ PREFIX_STATS *pfs;
+
+ stats_prefix_record_set("abc:123");
+ pfs = stats_prefix_find("abc:123");
+ test_equals_ull("get count after set #1", 0, pfs->num_gets);
+ test_equals_ull("hit count after set #1", 0, pfs->num_hits);
+ test_equals_ull("delete count after set #1", 0, pfs->num_deletes);
+ test_equals_ull("set count after set #1", 1, pfs->num_sets);
+ stats_prefix_record_delete("def:");
+ test_equals_ull("set count after set #2", 1, pfs->num_sets);
+}
+
+static void test_prefix_dump() {
+ int hashval = hash("abc", 3, 0) % PREFIX_HASH_SIZE;
+ char tmp[500];
+ char *expected;
+ int keynum;
+ int length;
+
+ test_equals_str("empty stats", "END\r\n", stats_prefix_dump(&length));
+ test_equals_int("empty stats length", 5, length);
+ stats_prefix_record_set("abc:123");
+ expected = "PREFIX abc get 0 hit 0 set 1 del 0\r\nEND\r\n";
+ test_equals_str("stats after set", expected, stats_prefix_dump(&length));
+ test_equals_int("stats length after set", strlen(expected), length);
+ stats_prefix_record_get("abc:123", 0);
+ expected = "PREFIX abc get 1 hit 0 set 1 del 0\r\nEND\r\n";
+ test_equals_str("stats after get #1", expected, stats_prefix_dump(&length));
+ test_equals_int("stats length after get #1", strlen(expected), length);
+ stats_prefix_record_get("abc:123", 1);
+ expected = "PREFIX abc get 2 hit 1 set 1 del 0\r\nEND\r\n";
+ test_equals_str("stats after get #2", expected, stats_prefix_dump(&length));
+ test_equals_int("stats length after get #2", strlen(expected), length);
+ stats_prefix_record_delete("abc:123");
+ expected = "PREFIX abc get 2 hit 1 set 1 del 1\r\nEND\r\n";
+ test_equals_str("stats after del #1", expected, stats_prefix_dump(&length));
+ test_equals_int("stats length after del #1", strlen(expected), length);
+
+ /* The order of results might change if we switch hash functions. */
+ stats_prefix_record_delete("def:123");
+ expected = "PREFIX abc get 2 hit 1 set 1 del 1\r\n"
+ "PREFIX def get 0 hit 0 set 0 del 1\r\n"
+ "END\r\n";
+ test_equals_str("stats after del #2", expected, stats_prefix_dump(&length));
+ test_equals_int("stats length after del #2", strlen(expected), length);
+
+ /* Find a key that hashes to the same bucket as "abc" */
+ for (keynum = 0; keynum < PREFIX_HASH_SIZE * 100; keynum++) {
+ sprintf(tmp, "%d", keynum);
+ if (hashval == hash(tmp, strlen(tmp), 0) % PREFIX_HASH_SIZE) {
+ break;
+ }
+ }
+ stats_prefix_record_set(tmp);
+ sprintf(tmp, "PREFIX %d get 0 hit 0 set 1 del 0\r\n"
+ "PREFIX abc get 2 hit 1 set 1 del 1\r\n"
+ "PREFIX def get 0 hit 0 set 0 del 1\r\n"
+ "END\r\n", keynum);
+ test_equals_str("stats with two stats in one bucket",
+ tmp, stats_prefix_dump(&length));
+ test_equals_int("stats length with two stats in one bucket",
+ strlen(tmp), length);
+}
+
+static void run_test(char *what, void (*func)(void)) {
+ current_test = what;
+ test_count = fail_count = 0;
+ puts(what);
+ fflush(stdout);
+
+ stats_prefix_clear();
+ (func)();
+ printf("\t%d / %d pass\n", (test_count - fail_count), test_count);
+}
+
+/* In case we're compiled in thread mode */
+void mt_stats_lock() { }
+void mt_stats_unlock() { }
+
+main(int argc, char **argv) {
+ stats_prefix_init();
+ settings.prefix_delimiter = ':';
+ run_test("stats_prefix_find", test_prefix_find);
+ run_test("stats_prefix_record_get", test_prefix_record_get);
+ run_test("stats_prefix_record_delete", test_prefix_record_delete);
+ run_test("stats_prefix_record_set", test_prefix_record_set);
+ run_test("stats_prefix_dump", test_prefix_dump);
+}
+
+#endif
Index: memcached.c
===================================================================
--- memcached.c (revision 460)
+++ memcached.c (working copy)
@@ -98,6 +98,7 @@
like 'settings.oldest_live' which act as booleans as well as
values are now false in boolean context... */
stats.started = time(0) - 2;
+ stats_prefix_init();
}
void stats_reset(void) {
@@ -105,6 +106,7 @@
stats.total_items = stats.total_conns = 0;
stats.get_cmds = stats.set_cmds = stats.get_hits = stats.get_misses = 0;
stats.bytes_read = stats.bytes_written = 0;
+ stats_prefix_clear();
STATS_UNLOCK();
}
@@ -126,6 +128,8 @@
#else
settings.num_threads = 1;
#endif
+ settings.prefix_delimiter = ':';
+ settings.detail_enabled = 0;
}
/*
@@ -718,6 +722,34 @@
return ntokens;
}
+inline void process_stats_detail(conn *c, const char *command) {
+ if (strcmp(command, "on") == 0) {
+ settings.detail_enabled = 1;
+ out_string(c, "OK");
+ }
+ else if (strcmp(command, "off") == 0) {
+ settings.detail_enabled = 0;
+ out_string(c, "OK");
+ }
+ else if (strcmp(command, "dump") == 0) {
+ int len;
+ char *stats = stats_prefix_dump(&len);
+ if (NULL != stats) {
+ c->write_and_free = stats;
+ c->wcurr = stats;
+ c->wbytes = len;
+ conn_set_state(c, conn_write);
+ c->write_and_go = conn_read;
+ }
+ else {
+ out_string(c, "SERVER_ERROR");
+ }
+ }
+ else {
+ out_string(c, "CLIENT_ERROR usage: stats detail on|off|dump");
+ }
+}
+
void process_stat(conn *c, token_t* tokens, size_t ntokens) {
rel_time_t now = current_time;
char* command;
@@ -892,6 +924,14 @@
return;
}
+ if (strcmp(subcommand, "detail")==0) {
+ if (ntokens < 4)
+ process_stats_detail(c, ""); /* outputs the error message */
+ else
+ process_stats_detail(c, tokens[2].value);
+ return;
+ }
+
if (strcmp(subcommand, "sizes")==0) {
int bytes = 0;
char *buf = item_stats_sizes(&bytes);
@@ -946,6 +986,9 @@
stats.get_cmds++;
STATS_UNLOCK();
it = item_get(key, nkey);
+ if (settings.detail_enabled) {
+ stats_prefix_record_get(key, NULL != it);
+ }
if (it) {
if (i >= c->isize) {
item **new_list = realloc(c->ilist, sizeof(item *)*c->isize*2);
@@ -1040,7 +1083,11 @@
out_string(c, "CLIENT_ERROR bad command line format");
return;
}
-
+
+ if (settings.detail_enabled) {
+ stats_prefix_record_set(key);
+ }
+
if (settings.managed) {
int bucket = c->bucket;
if (bucket == -1) {
@@ -1206,6 +1253,10 @@
}
}
+ if (settings.detail_enabled) {
+ stats_prefix_record_delete(key);
+ }
+
it = item_get(key, nkey);
if (it) {
if (exptime == 0) {
@@ -2297,7 +2348,7 @@
setbuf(stderr, NULL);
/* process arguments */
- while ((c = getopt(argc, argv, "bp:s:U:m:Mc:khirvdl:u:P:f:t:")) != -1) {
+ while ((c = getopt(argc, argv, "bp:s:U:m:Mc:khirvdl:u:P:f:t:D:")) != -1) {
switch (c) {
case 'U':
settings.udpport = atoi(optarg);
@@ -2373,6 +2424,14 @@
return 1;
}
break;
+ case 'D':
+ if (! optarg || ! optarg[0]) {
+ fprintf(stderr, "No delimiter specified\n");
+ return 1;
+ }
+ settings.prefix_delimiter = optarg[0];
+ settings.detail_enabled = 1;
+ break;
default:
fprintf(stderr, "Illegal argument \"%c\"\n", c);
return 1;
Index: memcached.h
===================================================================
--- memcached.h (revision 460)
+++ memcached.h (working copy)
@@ -60,6 +60,8 @@
double factor; /* chunk size growth factor */
int chunk_size;
int num_threads; /* number of libevent threads to run */
+ char prefix_delimiter; /* character that marks a key prefix (for stats) */
+ int detail_enabled; /* nonzero if we're collecting detailed stats */
};
extern struct stats stats;
@@ -267,6 +269,12 @@
/* stats */
void stats_reset(void);
void stats_init(void);
+void stats_prefix_init(void);
+void stats_prefix_clear(void);
+void stats_prefix_record_get(char *key, int is_hit);
+void stats_prefix_record_delete(char *key);
+void stats_prefix_record_set(char *key);
+char *stats_prefix_dump(int *length);
/* defaults */
void settings_init(void);
/* associative array */
@@ -275,6 +283,7 @@
int assoc_insert(item *item);
void assoc_delete(const char *key, size_t nkey);
void do_assoc_move_next_bucket(void);
+uint32_t hash(const void *key, size_t len, uint32_t startval);
void item_init(void);
item *do_item_alloc(char *key, size_t nkey, int flags, rel_time_t exptime, int nbytes);
Index: t/stats-detail.t
===================================================================
--- t/stats-detail.t (revision 0)
+++ t/stats-detail.t (revision 0)
@@ -0,0 +1,63 @@
+#!/usr/bin/perl
+
+use strict;
+use Test::More tests => 24;
+use FindBin qw($Bin);
+use lib "$Bin/lib";
+use MemcachedTest;
+
+my $server = new_memcached();
+my $sock = $server->sock;
+my $expire;
+
+print $sock "stats detail dump\r\n";
+is(scalar <$sock>, "END\r\n", "verified empty stats at start");
+
+print $sock "stats detail on\r\n";
+is(scalar <$sock>, "OK\r\n", "detail collection turned on");
+
+print $sock "set foo:123 0 0 6\r\nfooval\r\n";
+is(scalar <$sock>, "STORED\r\n", "stored foo");
+
+print $sock "stats detail dump\r\n";
+is(scalar <$sock>, "PREFIX foo get 0 hit 0 set 1 del 0\r\n", "details after set");
+is(scalar <$sock>, "END\r\n", "end of details");
+
+mem_get_is($sock, "foo:123", "fooval");
+print $sock "stats detail dump\r\n";
+is(scalar <$sock>, "PREFIX foo get 1 hit 1 set 1 del 0\r\n", "details after get with hit");
+is(scalar <$sock>, "END\r\n", "end of details");
+
+mem_get_is($sock, "foo:124", undef);
+
+print $sock "stats detail dump\r\n";
+is(scalar <$sock>, "PREFIX foo get 2 hit 1 set 1 del 0\r\n", "details after get without hit");
+is(scalar <$sock>, "END\r\n", "end of details");
+
+print $sock "delete foo:125 0\r\n";
+is(scalar <$sock>, "NOT_FOUND\r\n", "sent delete command");
+
+print $sock "stats detail dump\r\n";
+is(scalar <$sock>, "PREFIX foo get 2 hit 1 set 1 del 1\r\n", "details after delete");
+is(scalar <$sock>, "END\r\n", "end of details");
+
+print $sock "stats reset\r\n";
+is(scalar <$sock>, "RESET\r\n", "stats cleared");
+
+print $sock "stats detail dump\r\n";
+is(scalar <$sock>, "END\r\n", "empty stats after clear");
+
+mem_get_is($sock, "foo:123", "fooval");
+print $sock "stats detail dump\r\n";
+is(scalar <$sock>, "PREFIX foo get 1 hit 1 set 0 del 0\r\n", "details after clear and get");
+is(scalar <$sock>, "END\r\n", "end of details");
+
+print $sock "stats detail off\r\n";
+is(scalar <$sock>, "OK\r\n", "detail collection turned off");
+
+mem_get_is($sock, "foo:124", undef);
+
+mem_get_is($sock, "foo:123", "fooval");
+print $sock "stats detail dump\r\n";
+is(scalar <$sock>, "PREFIX foo get 1 hit 1 set 0 del 0\r\n", "details after stats turned off");
+is(scalar <$sock>, "END\r\n", "end of details");
Index: doc/memcached.1
===================================================================
--- doc/memcached.1 (revision 460)
+++ doc/memcached.1 (working copy)
@@ -90,6 +90,12 @@
meaningful if memcached was compiled with thread support enabled. It is
typically not useful to set this higher than the number of CPU cores on the
memcached server.
+.TP
+.B \-D <char>
+Use <char> as the delimiter between key prefixes and IDs. This is used for
+per-prefix stats reporting. The default is ":" (colon). If this option is
+specified, stats collection is turned on automatically; if not, then it may
+be turned on by sending the "stats detail on" command to the server.
.br
.SH LICENSE
The memcached daemon is copyright Danga Interactive and is distributed under
Index: Makefile.am
===================================================================
--- Makefile.am (revision 460)
+++ Makefile.am (working copy)
@@ -1,6 +1,6 @@
bin_PROGRAMS = memcached memcached-debug
-memcached_SOURCES = memcached.c slabs.c items.c memcached.h assoc.c thread.c
+memcached_SOURCES = memcached.c slabs.c items.c memcached.h assoc.c thread.c stats.c
memcached_debug_SOURCES = $(memcached_SOURCES)
memcached_CPPFLAGS = -DNDEBUG
memcached_LDADD = @LIBOBJS@
More information about the memcached
mailing list