Stats and tests for 'refhang' problem

Add "reflocked" counter to "stats" and "stats items". Not sure if this is a
good name for that or not.

Add tests to verify a fully 'locked' LRU correctly reports oom

Author: elfchief

items.c

@@ -29,6 +29,7 @@ typedef struct {
     uint64_t expired_unfetched;
     uint64_t evicted_unfetched;
     uint64_t crawler_reclaimed;
+    uint64_t reflocked;
 } itemstats_t;
 
 static item *heads[LARGEST_ID];
@@ -138,6 +139,7 @@ item *do_item_alloc(char *key, const size_t nkey, const int flags,
             tries_reflocked--;
             tries++;
             refcount_decr(&search->refcount);
+            itemstats[id].reflocked++;
             /* Old rare bug could cause a refcount leak. We haven't seen
              * it in years, but we leave this code in to prevent failures
              * just in case */
@@ -475,6 +477,7 @@ void do_item_stats_totals(ADD_STAT add_stats, void *c) {
         totals.evicted += itemstats[i].evicted;
         totals.reclaimed += itemstats[i].reclaimed;
         totals.crawler_reclaimed += itemstats[i].crawler_reclaimed;
+        totals.reflocked += itemstats[i].reflocked;
     }
     APPEND_STAT("expired_unfetched", "%llu",
                 (unsigned long long)totals.expired_unfetched);
@@ -486,6 +489,8 @@ void do_item_stats_totals(ADD_STAT add_stats, void *c) {
                 (unsigned long long)totals.reclaimed);
     APPEND_STAT("crawler_reclaimed", "%llu",
                 (unsigned long long)totals.crawler_reclaimed);
+    APPEND_STAT("reflocked", "%llu",
+                (unsigned long long)totals.reflocked);
 }
 
 void do_item_stats(ADD_STAT add_stats, void *c) {
@@ -520,6 +525,8 @@ void do_item_stats(ADD_STAT add_stats, void *c) {
                                 "%llu", (unsigned long long)itemstats[i].evicted_unfetched);
             APPEND_NUM_FMT_STAT(fmt, i, "crawler_reclaimed",
                                 "%llu", (unsigned long long)itemstats[i].crawler_reclaimed);
+            APPEND_NUM_FMT_STAT(fmt, i, "reflocked",
+                                "%llu", (unsigned long long)itemstats[i].reflocked);
         }
     }
 

t/refhang.t

@@ -3,7 +3,7 @@
 use strict;
 use warnings;
 
-use Test::More tests => 240;
+use Test::More tests => 266;
 
 use FindBin qw($Bin);
 use lib "$Bin/lib";
@@ -12,22 +12,30 @@ use MemcachedTest;
 # start up a server with 10 maximum connections
 my $server = new_memcached("-m 6");
 my $sock = $server->sock;
-my $hangsock = $server->new_sock;;
+my $hangsock = $server->new_sock;
+my $hangsock2 = $server->new_sock;
 my $value = "B"x66560;
 my $key = 0;
 
 # These aren't set to expire.
 my $mget = '';
+my $mget_all = '';
 for ($key = 0; $key < 120; $key++) {
     $mget .= "key$key " if $key < 115;
+    $mget_all .= "key$key ";
     print $sock "set key$key 0 0 66560\r\n$value\r\n";
     is(scalar <$sock>, "STORED\r\n", "stored key$key");
 }
 chop $mget;
 
 my $stats  = mem_stats($sock, "items");
-my $evicted = $stats->{"items:31:evicted"};
-isnt($evicted, "0", "check evicted");
+isnt($stats->{"items:31:evicted"}, "0", "check evicted");
+
+my $reflocked = $stats->{"items:31:reflocked"};
+is($reflocked, "0", "check no slab reflocked");
+
+$stats = mem_stats($sock);
+is($stats->{"reflocked"}, "0", "check no total reflocked");
 
 # Don't intend to read the results, need to fill the socket.
 # TODO: This test would be smarter if we cranked down the socket buffers
@@ -36,6 +44,33 @@ print $hangsock "get $mget\r\n";
 #sleep 8;
 # Now we try a bunch of sets again, and see if they start coming back as OOM's
 for ($key = 121; $key < 240; $key++) {
+    $mget_all .= "key$key ";
     print $sock "set key$key 0 0 66560\r\n$value\r\n";
     is(scalar <$sock>, "STORED\r\n", "stored key$key");
 }
+
+$stats = mem_stats($sock, "items");
+is($stats->{"items:31:outofmemory"}, "0", "check no oom");
+isnt($stats->{"items:31:reflocked"}, "0", "count reflocked");
+
+$stats = mem_stats($sock);
+isnt($stats->{"reflocked"}, "0", "count total reflocked");
+
+# Clear out all that 'hung' traffic
+while(<$hangsock> !~ /END/) { };
+
+# Make sure we get a oom when the entire world is refcounted
+print $hangsock "get $mget_all\r\n";
+
+# Get all our keys in a different order to make sure some of the cache isn't
+# free just because it made it to the tcp buffer
+my $revkeys = join(" ", reverse(split(" ", $mget_all)));
+print $hangsock2 "get $revkeys\r\n";
+
+for ($key = 240; $key < 260; $key++) {
+    print $sock "set key$key 0 0 66560\r\n$value\r\n";
+    is(scalar <$sock>, "SERVER_ERROR out of memory storing object\r\n", "oom fully reflocked");
+}
+
+$stats = mem_stats($sock, "items");
+isnt($stats->{"items:31:outofmemory"}, "0", "count reflocked oom");

t/stats.t

@@ -23,9 +23,11 @@ my $sock = $server->sock;
 ## STAT curr_connections 10
 ## STAT total_connections 11
 ## STAT connection_structures 11
+## STAT reserved_fds 20
 ## STAT cmd_get 0
 ## STAT cmd_set 0
 ## STAT cmd_flush 0
+## STAT cmd_touch 0
 ## STAT get_hits 0
 ## STAT get_misses 0
 ## STAT delete_misses 0
@@ -37,6 +39,8 @@ my $sock = $server->sock;
 ## STAT cas_misses 0
 ## STAT cas_hits 0
 ## STAT cas_badval 0
+## STAT touch_hits 0
+## STAT touch_misses 0
 ## STAT auth_cmds 0
 ## STAT auth_unknowns 0
 ## STAT bytes_read 7
@@ -46,24 +50,31 @@ my $sock = $server->sock;
 ## STAT listen_disabled_num 0
 ## STAT threads 4
 ## STAT conn_yields 0
+## STAT hash_power_level 16
+## STAT hash_bytes 524288
+## STAT hash_is_expanding 0
+## STAT malloc_fails 0
 ## STAT bytes 0
 ## STAT curr_items 0
 ## STAT total_items 0
+## STAT expired_unfetched 0
+## STAT evicted_unfetched 0
 ## STAT evictions 0
 ## STAT reclaimed 0
-
+## STAT crawler_reclaimed 0
+## STAT reflocked 0
 # note that auth stats are tested in auth specfic tests
 
 
 my $stats = mem_stats($sock);
 
 # Test number of keys
-is(scalar(keys(%$stats)), 50, "50 stats values");
+is(scalar(keys(%$stats)), 51, "51 stats values");
 
 # Test initial state
 foreach my $key (qw(curr_items total_items bytes cmd_get cmd_set get_hits evictions get_misses
                  bytes_written delete_hits delete_misses incr_hits incr_misses decr_hits
-                 decr_misses listen_disabled_num)) {
+                 decr_misses listen_disabled_num reflocked)) {
     is($stats->{$key}, 0, "initial $key is zero");
 }
 is($stats->{accepting_conns}, 1, "initial accepting_conns is one");
@@ -188,6 +199,7 @@ is(0, $stats->{'cas_hits'});
 is(0, $stats->{'cas_badval'});
 is(0, $stats->{'evictions'});
 is(0, $stats->{'reclaimed'});
+is(0, $stats->{'reflocked'});
 
 print $sock "flush_all\r\n";
 is(scalar <$sock>, "OK\r\n", "flushed");