Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Memcached gets a dead loop in func assoc_find #271

Closed
jiejieling opened this issue Apr 28, 2017 · 34 comments
Closed

Memcached gets a dead loop in func assoc_find #271

jiejieling opened this issue Apr 28, 2017 · 34 comments

Comments

@jiejieling
Copy link

OS Ver: CentOS 6.5 x64
Kernel Ver: 2.6.32-431.11.7.el6
Memcached Ver: 1.4.24 and 1.4.36

gdb info:
(gdb) info thread
7 Thread 0x7f103e389700 (LWP 29762) logger_thread (arg=) at logger.c:476

  • 6 Thread 0x7f103d988700 (LWP 29763) assoc_find (key=, nkey=, hv=) at assoc.c:93
    5 Thread 0x7f103cf87700 (LWP 29764) 0x00007f103e93a334 in __lll_lock_wait () from /lib64/libpthread.so.0
    4 Thread 0x7f1034586700 (LWP 29765) 0x00007f103e93a334 in __lll_lock_wait () from /lib64/libpthread.so.0
    3 Thread 0x7f1037fff700 (LWP 29766) 0x00007f103e93a334 in __lll_lock_wait () from /lib64/libpthread.so.0
    2 Thread 0x7f10375fe700 (LWP 29767) 0x00007f103e93768c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
    1 Thread 0x7f103f1aa700 (LWP 29761) 0x00007f103e680f33 in epoll_wait () from /lib64/libc.so.6

In the thread 6(assoc_find):
dead loop in:
(gdb) n
92 while (it) {
(gdb)
93 if ((nkey == it->nkey) && (memcmp(key, ITEM_key(it), nkey) == 0)) {
(gdb)
97 it = it->h_next;

items info:
(gdb) p it
$31 = (item *) 0x7f101a4fd7a0

(gdb) p *it
$30 = {next = 0x7f101a4fd7a0, prev = 0x7f0ffaeee700, h_next = 0x7f101a4fd7a0, time = 166607, exptime = 253007, nbytes = 2378, refcount = 1, nsuffix = 10 '\n',
it_flags = 11 '\v', slabs_clsid = 144 '\220', nkey = 24 '\030', data = 0x7f101a4fd7a0}

it->h_next == it self, so the deap loop coming..

So this is a bug ?

@dormando
Copy link
Member

how are you causing that?

what's the full bt for thread 6? Are the key/nkey/hv values really empty?

@jiejieling
Copy link
Author

jiejieling commented Apr 28, 2017

gdb bt info:

(gdb) bt
#0  assoc_find (key=<value optimized out>, nkey=<value optimized out>, hv=<value optimized out>) at assoc.c:92
#1  0x0000000000413f18 in do_item_get (key=0x7f102826f450 "product_roomtype_100039806", nkey=26, hv=4115851641, c=0x7f10280449f0, do_update=true) at items.c:863
#2  0x0000000000415ebc in item_get (key=0x7f102826f450 "product_roomtype_100039806", nkey=26, c=0x7f10280449f0, do_update=true) at thread.c:522
#3  0x0000000000408b2d in process_get_command (c=0x7f10280449f0, tokens=0x7f103d987b40, ntokens=<value optimized out>, return_cas=true) at memcached.c:3276
#4  0x000000000040c6b3 in process_command (c=0x7f10280449f0, command=<value optimized out>) at memcached.c:4005
#5  0x000000000040d310 in try_read_command (c=0x7f10280449f0) at memcached.c:4368
#6  0x000000000040de80 in drive_machine (c=0x7f10280449f0) at memcached.c:4805
#7  0x00007f103ed62e0c in event_process_active_single_queue (base=0x1f55f30, flags=0) at event.c:1350
#8  event_process_active (base=0x1f55f30, flags=0) at event.c:1420
#9  event_base_loop (base=0x1f55f30, flags=0) at event.c:1621
#10 0x00000000004157eb in worker_libevent (arg=<value optimized out>) at thread.c:351
#11 0x00007f103e933aa1 in start_thread () from /lib64/libpthread.so.0
#12 0x00007f103e68093d in clone () from /lib64/libc.so.6
The mc process hold the CPU 100%, and keep tcp connections in CLOSE_WAIT status

@dormando
Copy link
Member

Are you able to reproduce this state? Have you modified the source in any way?

Never seen this failure. Very interested in finding out how it got into that state.

any chance of getting stats and stats settings output?

@jiejieling
Copy link
Author

jiejieling commented Apr 28, 2017

(gdb) p settings
$33 = {maxbytes = 1073741824, maxconns = 1024, port = 11217, udpport = 11217, inter = 0x1f4e010 "10.6.18.139", verbose = 0, oldest_live = 0, oldest_cas = 0, evict_to_free = 1, socketpath = 0x0, access = 448, factor = 1.25, chunk_size = 48, num_threads = 4, num_threads_per_udp = 4, prefix_delimiter = 58 ':', detail_enabled = 0, reqs_per_event = 20, use_cas = true, binding_protocol = negotiating_prot, backlog = 1024, item_size_max = 1048576, slab_chunk_size_max = 1048576, slab_page_size = 1048576, sasl = false, maxconns_fast = false, lru_crawler = false, lru_maintainer_thread = false, lru_segmented = false, slab_reassign = false, slab_automove = 0, hashpower_init = 0, shutdown_command = false, tail_repair_time = 0, flush_enabled = true, dump_enabled = true, hash_algorithm = 0x419cc5 "jenkins", lru_crawler_sleep = 100, lru_crawler_tocrawl = 0, hot_lru_pct = 32, warm_lru_pct = 32, hot_max_age = 3600, warm_max_factor = 2, crawls_persleep = 1000, inline_ascii_response = true, temp_lru = false, temporary_ttl = 61, idle_timeout = 0, logger_watcher_buf_size = 262144, logger_buf_size = 65536}
(gdb) p stats
$34 = {total_items = 27224498, total_conns = 386158, rejected_conns = 0, malloc_fails = 0, listen_disabled_num = 1, slabs_moved = 0, slab_reassign_rescues = 0, slab_reassign_evictions_nomem = 0, slab_reassign_inline_reclaim = 0, slab_reassign_chunk_rescues = 0, slab_reassign_busy_items = 0, lru_crawler_starts = 0, lru_maintainer_juggles = 0, time_in_listen_disabled_us = 0, log_worker_dropped = 0, log_worker_written = 0, log_watcher_skipped = 0, log_watcher_sent = 0, maxconns_entered = {tv_sec = 1493340886, tv_usec = 551868}}
(gdb) p hashpower
$35 = 19
(gdb) p hash_items
$36 = 648961
(gdb) p expanding
$37 = false

This state has reproduced many times, and we have 30 instances of mc, but only one happens always, I don't have modified souce code.

The process has rejected tcp conection, stats info from gdb

@dormando
Copy link
Member

looks like none of the new features are even enabled, so it's probably not a side effect of any of those...

how is memcached being installed? you're sure it still happens on 1.4.36?

need to think about how to figure this out. There isn't any way that should happen. Are you using binary protocol or ASCII?

Maybe you can add: assert(it->h_next != it); in assoc.c:assoc_insert() right before return 1;. Maybe that will catch it as the problem is created, which could give a more useful backtrace. you have to run the memcached-debug binary to get assert()'s though.

@jiejieling
Copy link
Author

jiejieling commented Apr 28, 2017

About install: I get the release 1.4.36 source code from github, and make && make install to install it.
About protocol: We are using ASCII protocol.

Btw, In the assoc_insert, the expand_bucket needn't a lock ?

int assoc_insert(item *it, const uint32_t hv) {
    unsigned int oldbucket;

//    assert(assoc_find(ITEM_key(it), it->nkey) == 0);  /* shouldn't have duplicately named things defined */

    if (expanding &&
        (oldbucket = (hv & hashmask(hashpower - 1))) >= expand_bucket)
    {
        it->h_next = old_hashtable[oldbucket];
        old_hashtable[oldbucket] = it;
    } else {
        it->h_next = primary_hashtable[hv & hashmask(hashpower)];
        primary_hashtable[hv & hashmask(hashpower)] = it;
    }

    pthread_mutex_lock(&hash_items_counter_lock);
    hash_items++;
    if (! expanding && hash_items > (hashsize(hashpower) * 3) / 2) {
        assoc_start_expand();
    }
    pthread_mutex_unlock(&hash_items_counter_lock);

    MEMCACHED_ASSOC_INSERT(ITEM_key(it), it->nkey, hash_items);
    return 1;
}

@dormando
Copy link
Member

Doesn't need a lock because of how expanding started/stopped. All threads synchronize first.

If you're worried about that, you can give the startup option -o hashpower=N to presize the hash table.

@jiejieling
Copy link
Author

All right, I will try your suggestion about the "assert...", hope its helpful.

@jiejieling
Copy link
Author

Hi guys, I have tried your suggestion, but it is not helpful. There is no info about the 'assert' , I guess the 'assert' has not be executed. And I guess is expansion made the matter, so are there have any other way ?

@dormando
Copy link
Member

dormando commented May 1, 2017

Hey,

Can you confirm you were running the memcached-debug binary for that test? The assert()'s only work with it.

Have you tried adding -o hashpower=N to the instance? The stats output from a running instance will tell you around how big it is. Your crashed instance was 19, so 20-21 might be a good place to start. That will prevent hash expansion from ever happening. You'll need to do this to confirm if it's hash expansion or not.

I'm hesitant to blame the hash expansion because I have tried to blame it for many bugs in the past; but it always turns out to be something else.

@jiejieling
Copy link
Author

Yeah, I have used the memcached-debug binary, and got some stderr info:"memcached-debug: items.c:344: item_free: Assertion `(it->it_flags & 1) == 0' failed", but not the "assert(it->h_next != it)", I don't know what the error mean ?

@jiejieling
Copy link
Author

And when got the error , the mc went away, so I can't to debug it.

@dormando
Copy link
Member

dormando commented May 1, 2017

Sorry, you have to start it within GDB, or enable coredumps.

That assertion is a little scary.. it means an item is being freed to memory while it's still linked into the hash table and linked list. Something like that could cause this same problem. Any chance you could run it under GDB and get the backtrace for this assert?

Also, from any of your live and non-bugged instances in the same pool, I would greatly appreciate the output from all the various stats commands (stats, settings, items, slabs). The prints you did earlier are missing a lot of data.

@jiejieling
Copy link
Author

Hi guys, I have got backtrace about the assertion '(it->it_flags & 1) == 0':

(gdb) bt
#0  0x00007ffff7411625 in raise () from /lib64/libc.so.6
#1  0x00007ffff7412e05 in abort () from /lib64/libc.so.6
#2  0x00007ffff740a74e in __assert_fail_base () from /lib64/libc.so.6
#3  0x00007ffff740a810 in __assert_fail () from /lib64/libc.so.6
#4  0x000000000041bad6 in item_free (it=<value optimized out>) at items.c:344
#5  0x000000000041bb74 in do_item_remove (it=<value optimized out>) at items.c:491
#6  0x000000000041fbf0 in item_remove (item=0x7fffdefed520) at thread.c:560
#7  0x00000000004034c3 in conn_release_items (c=0x7ffff009bfe0) at memcached.c:622
#8  0x0000000000414b28 in drive_machine (c=0x7ffff009bfe0) at memcached.c:4998
#9  0x0000000000415978 in event_handler (fd=<value optimized out>, which=<value optimized out>, arg=0x7ffff009bfe0) at memcached.c:5070
#10 0x00007ffff7ba9e0c in event_process_active_single_queue (base=0x65b790, flags=0) at event.c:1350
#11 event_process_active (base=0x65b790, flags=0) at event.c:1420
#12 event_base_loop (base=0x65b790, flags=0) at event.c:1621
#13 0x000000000041f53b in worker_libevent (arg=0x658db0) at thread.c:351
#14 0x00007ffff777aaa1 in start_thread () from /lib64/libpthread.so.0
#15 0x00007ffff74c793d in clone () from /lib64/libc.so.6

And I started the memcached-debug with argv '-ohashpower=21' , When mc crashed, the hashpower still eq 21, So you are right, is not expansion's matter.

@dormando
Copy link
Member

dormando commented May 2, 2017

thanks!

hmm, not super enlightening. That's the normal code path, now freeing something that's still linked. Any chance I could get a look (you can send them privately) at full stats output from a running instance?

@jiejieling
Copy link
Author

When I got the assertion, the mc-debug process has gone away, I can only get stats by 'gdb p stats'.

(gdb) p stats
$3 = {total_items = 11543533, total_conns = 189185, rejected_conns = 0, malloc_fails = 0, listen_disabled_num = 0, slabs_moved = 0, slab_reassign_rescues = 0,
  slab_reassign_evictions_nomem = 0, slab_reassign_inline_reclaim = 0, slab_reassign_chunk_rescues = 0, slab_reassign_busy_items = 0, lru_crawler_starts = 0,
  lru_maintainer_juggles = 0, time_in_listen_disabled_us = 0, log_worker_dropped = 0, log_worker_written = 0, log_watcher_skipped = 0, log_watcher_sent = 0,
  maxconns_entered = {tv_sec = 0, tv_usec = 0}}

@dormando
Copy link
Member

dormando commented May 3, 2017

you said you have several instances, but only one of them crashes, correct? Can I see the stats output from a different instance? or do they all get different types of traffic?

How long does it take to crash after you start it, btw?

@jiejieling
Copy link
Author

Yes, only one crashed. The crash happened every day.
I don't understand what are you mean the different types of traffic ? All of the instances have different application to use it.

Another good instance stats info:

stats
STAT pid 26575
STAT uptime 25226766
STAT time 1493778309
STAT version 1.4.24
STAT libevent 2.0.21-stable
STAT pointer_size 64
STAT rusage_user 215128.245535
STAT rusage_system 511307.450452
STAT curr_connections 22
STAT total_connections 57038169
STAT connection_structures 600
STAT reserved_fds 20
STAT cmd_get 17072035789
STAT cmd_set 8365734403
STAT cmd_flush 0
STAT cmd_touch 0
STAT get_hits 16697520097
STAT get_misses 374515692
STAT delete_misses 442063
STAT delete_hits 621532
STAT incr_misses 0
STAT incr_hits 0
STAT decr_misses 0
STAT decr_hits 0
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_errors 0
STAT bytes_read 2827899156534
STAT bytes_written 10427369841953
STAT limit_maxbytes 1073741824
STAT accepting_conns 1
STAT listen_disabled_num 0
STAT threads 4
STAT conn_yields 0
STAT hash_power_level 20
STAT hash_bytes 8388608
STAT hash_is_expanding 0
STAT malloc_fails 0
STAT bytes 774232716
STAT curr_items 759832
STAT total_items 4070767107
STAT expired_unfetched 86526982
STAT evicted_unfetched 4557394
STAT evictions 5765914
STAT reclaimed 87661222
STAT crawler_reclaimed 0
STAT crawler_items_checked 0
STAT lrutail_reflocked 1
END

@jiejieling
Copy link
Author

Hey, I have got a full stats before mc crashed today, and hope helpful.

stats settings
STAT maxbytes 1073741824
STAT maxconns 1024
STAT tcpport 11217
STAT udpport 11217
STAT inter 10.6.18.139
STAT verbosity 0
STAT oldest 0
STAT evictions on
STAT domain_socket NULL
STAT umask 700
STAT growth_factor 1.25
STAT chunk_size 48
STAT num_threads 4
STAT num_threads_per_udp 4
STAT stat_key_prefix :
STAT detail_enabled no
STAT reqs_per_event 20
STAT cas_enabled yes
STAT tcp_backlog 1024
STAT binding_protocol auto-negotiate
STAT auth_enabled_sasl no
STAT item_size_max 1048576
STAT maxconns_fast no
STAT hashpower_init 0
STAT slab_reassign no
STAT slab_automove 0
STAT slab_chunk_max 1048576
STAT lru_crawler no
STAT lru_crawler_sleep 100
STAT lru_crawler_tocrawl 0
STAT tail_repair_time 0
STAT flush_enabled yes
STAT dump_enabled yes
STAT hash_algorithm jenkins
STAT lru_maintainer_thread no
STAT lru_segmented no
STAT hot_lru_pct 32
STAT warm_lru_pct 32
STAT hot_max_age 3600
STAT warm_max_factor 2.00
STAT temp_lru no
STAT temporary_ttl 61
STAT idle_timeout 0
STAT watcher_logbuf_size 262144
STAT worker_logbuf_size 65536
STAT track_sizes no
STAT inline_ascii_response yes
END
stats
STAT pid 22387
STAT uptime 77033
STAT time 1493852000
STAT version UNKNOWN
STAT libevent 2.0.21-stable
STAT pointer_size 64
STAT rusage_user 921.305940
STAT rusage_system 3062.494430
STAT curr_connections 254
STAT total_connections 197189
STAT connection_structures 378
STAT reserved_fds 20
STAT cmd_get 60566308
STAT cmd_set 8303263
STAT cmd_flush 0
STAT cmd_touch 0
STAT get_hits 58946873
STAT get_misses 1619435
STAT get_expired 355465
STAT get_flushed 0
STAT delete_misses 2477
STAT delete_hits 175
STAT incr_misses 0
STAT incr_hits 0
STAT decr_misses 0
STAT decr_hits 0
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_errors 0
STAT bytes_read 4336350419
STAT bytes_written 454614762218
STAT limit_maxbytes 1073741824
STAT accepting_conns 1
STAT listen_disabled_num 0
STAT time_in_listen_disabled_us 0
STAT threads 4
STAT conn_yields 0
STAT hash_power_level 19
STAT hash_bytes 4194304
STAT hash_is_expanding 0
STAT malloc_fails 0
STAT log_worker_dropped 0
STAT log_worker_written 0
STAT log_watcher_skipped 0
STAT log_watcher_sent 0
STAT bytes 697676133
STAT curr_items 417341
STAT total_items 8303263
STAT expired_unfetched 241
STAT evicted_unfetched 0
STAT evictions 0
STAT reclaimed 300
STAT crawler_reclaimed 0
STAT crawler_items_checked 0
STAT lrutail_reflocked 0
END
stats items
STAT items:1:number 5960
STAT items:1:age 77099
STAT items:1:evicted 0
STAT items:1:evicted_nonzero 0
STAT items:1:evicted_time 0
STAT items:1:outofmemory 0
STAT items:1:tailrepairs 0
STAT items:1:reclaimed 0
STAT items:1:expired_unfetched 0
STAT items:1:evicted_unfetched 0
STAT items:1:crawler_reclaimed 0
STAT items:1:crawler_items_checked 0
STAT items:1:lrutail_reflocked 0
STAT items:2:number 56075
STAT items:2:age 77109
STAT items:2:evicted 0
STAT items:2:evicted_nonzero 0
STAT items:2:evicted_time 0
STAT items:2:outofmemory 0
STAT items:2:tailrepairs 0
STAT items:2:reclaimed 0
STAT items:2:expired_unfetched 0
STAT items:2:evicted_unfetched 0
STAT items:2:crawler_reclaimed 0
STAT items:2:crawler_items_checked 0
STAT items:2:lrutail_reflocked 0
STAT items:3:number 1792
STAT items:3:age 76536
STAT items:3:evicted 0
STAT items:3:evicted_nonzero 0
STAT items:3:evicted_time 0
STAT items:3:outofmemory 0
STAT items:3:tailrepairs 0
STAT items:3:reclaimed 4
STAT items:3:expired_unfetched 4
STAT items:3:evicted_unfetched 0
STAT items:3:crawler_reclaimed 0
STAT items:3:crawler_items_checked 0
STAT items:3:lrutail_reflocked 0
STAT items:4:number 40691
STAT items:4:age 76538
STAT items:4:evicted 0
STAT items:4:evicted_nonzero 0
STAT items:4:evicted_time 0
STAT items:4:outofmemory 0
STAT items:4:tailrepairs 0
STAT items:4:reclaimed 0
STAT items:4:expired_unfetched 0
STAT items:4:evicted_unfetched 0
STAT items:4:crawler_reclaimed 0
STAT items:4:crawler_items_checked 0
STAT items:4:lrutail_reflocked 0
STAT items:5:number 372
STAT items:5:age 73684
STAT items:5:evicted 0
STAT items:5:evicted_nonzero 0
STAT items:5:evicted_time 0
STAT items:5:outofmemory 0
STAT items:5:tailrepairs 0
STAT items:5:reclaimed 11
STAT items:5:expired_unfetched 10
STAT items:5:evicted_unfetched 0
STAT items:5:crawler_reclaimed 0
STAT items:5:crawler_items_checked 0
STAT items:5:lrutail_reflocked 0
STAT items:6:number 4120
STAT items:6:age 77026
STAT items:6:evicted 0
STAT items:6:evicted_nonzero 0
STAT items:6:evicted_time 0
STAT items:6:outofmemory 0
STAT items:6:tailrepairs 0
STAT items:6:reclaimed 12
STAT items:6:expired_unfetched 10
STAT items:6:evicted_unfetched 0
STAT items:6:crawler_reclaimed 0
STAT items:6:crawler_items_checked 0
STAT items:6:lrutail_reflocked 0
STAT items:7:number 790
STAT items:7:age 73619
STAT items:7:evicted 0
STAT items:7:evicted_nonzero 0
STAT items:7:evicted_time 0
STAT items:7:outofmemory 0
STAT items:7:tailrepairs 0
STAT items:7:reclaimed 24
STAT items:7:expired_unfetched 19
STAT items:7:evicted_unfetched 0
STAT items:7:crawler_reclaimed 0
STAT items:7:crawler_items_checked 0
STAT items:7:lrutail_reflocked 0
STAT items:8:number 7584
STAT items:8:age 76412
STAT items:8:evicted 0
STAT items:8:evicted_nonzero 0
STAT items:8:evicted_time 0
STAT items:8:outofmemory 0
STAT items:8:tailrepairs 0
STAT items:8:reclaimed 14
STAT items:8:expired_unfetched 6
STAT items:8:evicted_unfetched 0
STAT items:8:crawler_reclaimed 0
STAT items:8:crawler_items_checked 0
STAT items:8:lrutail_reflocked 0
STAT items:9:number 35040
STAT items:9:age 77097
STAT items:9:evicted 0
STAT items:9:evicted_nonzero 0
STAT items:9:evicted_time 0
STAT items:9:outofmemory 0
STAT items:9:tailrepairs 0
STAT items:9:reclaimed 0
STAT items:9:expired_unfetched 0
STAT items:9:evicted_unfetched 0
STAT items:9:crawler_reclaimed 0
STAT items:9:crawler_items_checked 0
STAT items:9:lrutail_reflocked 0
STAT items:10:number 149753
STAT items:10:age 75673
STAT items:10:evicted 0
STAT items:10:evicted_nonzero 0
STAT items:10:evicted_time 0
STAT items:10:outofmemory 0
STAT items:10:tailrepairs 0
STAT items:10:reclaimed 9
STAT items:10:expired_unfetched 6
STAT items:10:evicted_unfetched 0
STAT items:10:crawler_reclaimed 0
STAT items:10:crawler_items_checked 0
STAT items:10:lrutail_reflocked 0
STAT items:11:number 3618
STAT items:11:age 74973
STAT items:11:evicted 0
STAT items:11:evicted_nonzero 0
STAT items:11:evicted_time 0
STAT items:11:outofmemory 0
STAT items:11:tailrepairs 0
STAT items:11:reclaimed 17
STAT items:11:expired_unfetched 3
STAT items:11:evicted_unfetched 0
STAT items:11:crawler_reclaimed 0
STAT items:11:crawler_items_checked 0
STAT items:11:lrutail_reflocked 0
STAT items:12:number 2761
STAT items:12:age 76293
STAT items:12:evicted 0
STAT items:12:evicted_nonzero 0
STAT items:12:evicted_time 0
STAT items:12:outofmemory 0
STAT items:12:tailrepairs 0
STAT items:12:reclaimed 6
STAT items:12:expired_unfetched 0
STAT items:12:evicted_unfetched 0
STAT items:12:crawler_reclaimed 0
STAT items:12:crawler_items_checked 0
STAT items:12:lrutail_reflocked 0
STAT items:13:number 3179
STAT items:13:age 74973
STAT items:13:evicted 0
STAT items:13:evicted_nonzero 0
STAT items:13:evicted_time 0
STAT items:13:outofmemory 0
STAT items:13:tailrepairs 0
STAT items:13:reclaimed 15
STAT items:13:expired_unfetched 13
STAT items:13:evicted_unfetched 0
STAT items:13:crawler_reclaimed 0
STAT items:13:crawler_items_checked 0
STAT items:13:lrutail_reflocked 0
STAT items:14:number 10083
STAT items:14:age 76939
STAT items:14:evicted 0
STAT items:14:evicted_nonzero 0
STAT items:14:evicted_time 0
STAT items:14:outofmemory 0
STAT items:14:tailrepairs 0
STAT items:14:reclaimed 1
STAT items:14:expired_unfetched 1
STAT items:14:evicted_unfetched 0
STAT items:14:crawler_reclaimed 0
STAT items:14:crawler_items_checked 0
STAT items:14:lrutail_reflocked 0
STAT items:15:number 8947
STAT items:15:age 75567
STAT items:15:evicted 0
STAT items:15:evicted_nonzero 0
STAT items:15:evicted_time 0
STAT items:15:outofmemory 0
STAT items:15:tailrepairs 0
STAT items:15:reclaimed 5
STAT items:15:expired_unfetched 2
STAT items:15:evicted_unfetched 0
STAT items:15:crawler_reclaimed 0
STAT items:15:crawler_items_checked 0
STAT items:15:lrutail_reflocked 0
STAT items:16:number 7411
STAT items:16:age 76906
STAT items:16:evicted 0
STAT items:16:evicted_nonzero 0
STAT items:16:evicted_time 0
STAT items:16:outofmemory 0
STAT items:16:tailrepairs 0
STAT items:16:reclaimed 1
STAT items:16:expired_unfetched 1
STAT items:16:evicted_unfetched 0
STAT items:16:crawler_reclaimed 0
STAT items:16:crawler_items_checked 0
STAT items:16:lrutail_reflocked 0
STAT items:17:number 15109
STAT items:17:age 77076
STAT items:17:evicted 0
STAT items:17:evicted_nonzero 0
STAT items:17:evicted_time 0
STAT items:17:outofmemory 0
STAT items:17:tailrepairs 0
STAT items:17:reclaimed 0
STAT items:17:expired_unfetched 0
STAT items:17:evicted_unfetched 0
STAT items:17:crawler_reclaimed 0
STAT items:17:crawler_items_checked 0
STAT items:17:lrutail_reflocked 0
STAT items:18:number 14053
STAT items:18:age 73126
STAT items:18:evicted 0
STAT items:18:evicted_nonzero 0
STAT items:18:evicted_time 0
STAT items:18:outofmemory 0
STAT items:18:tailrepairs 0
STAT items:18:reclaimed 26
STAT items:18:expired_unfetched 26
STAT items:18:evicted_unfetched 0
STAT items:18:crawler_reclaimed 0
STAT items:18:crawler_items_checked 0
STAT items:18:lrutail_reflocked 0
STAT items:19:number 12892
STAT items:19:age 71391
STAT items:19:evicted 0
STAT items:19:evicted_nonzero 0
STAT items:19:evicted_time 0
STAT items:19:outofmemory 0
STAT items:19:tailrepairs 0
STAT items:19:reclaimed 38
STAT items:19:expired_unfetched 38
STAT items:19:evicted_unfetched 0
STAT items:19:crawler_reclaimed 0
STAT items:19:crawler_items_checked 0
STAT items:19:lrutail_reflocked 0
STAT items:20:number 11620
STAT items:20:age 70166
STAT items:20:evicted 0
STAT items:20:evicted_nonzero 0
STAT items:20:evicted_time 0
STAT items:20:outofmemory 0
STAT items:20:tailrepairs 0
STAT items:20:reclaimed 18
STAT items:20:expired_unfetched 18
STAT items:20:evicted_unfetched 0
STAT items:20:crawler_reclaimed 0
STAT items:20:crawler_items_checked 0
STAT items:20:lrutail_reflocked 0
STAT items:21:number 10583
STAT items:21:age 73688
STAT items:21:evicted 0
STAT items:21:evicted_nonzero 0
STAT items:21:evicted_time 0
STAT items:21:outofmemory 0
STAT items:21:tailrepairs 0
STAT items:21:reclaimed 3
STAT items:21:expired_unfetched 3
STAT items:21:evicted_unfetched 0
STAT items:21:crawler_reclaimed 0
STAT items:21:crawler_items_checked 0
STAT items:21:lrutail_reflocked 0
STAT items:22:number 9256
STAT items:22:age 75950
STAT items:22:evicted 0
STAT items:22:evicted_nonzero 0
STAT items:22:evicted_time 0
STAT items:22:outofmemory 0
STAT items:22:tailrepairs 0
STAT items:22:reclaimed 0
STAT items:22:expired_unfetched 0
STAT items:22:evicted_unfetched 0
STAT items:22:crawler_reclaimed 0
STAT items:22:crawler_items_checked 0
STAT items:22:lrutail_reflocked 0
STAT items:23:number 5867
STAT items:23:age 48044
STAT items:23:evicted 0
STAT items:23:evicted_nonzero 0
STAT items:23:evicted_time 0
STAT items:23:outofmemory 0
STAT items:23:tailrepairs 0
STAT items:23:reclaimed 87
STAT items:23:expired_unfetched 72
STAT items:23:evicted_unfetched 0
STAT items:23:crawler_reclaimed 0
STAT items:23:crawler_items_checked 0
STAT items:23:lrutail_reflocked 0
STAT items:24:number 144
STAT items:24:age 74127
STAT items:24:evicted 0
STAT items:24:evicted_nonzero 0
STAT items:24:evicted_time 0
STAT items:24:outofmemory 0
STAT items:24:tailrepairs 0
STAT items:24:reclaimed 0
STAT items:24:expired_unfetched 0
STAT items:24:evicted_unfetched 0
STAT items:24:crawler_reclaimed 0
STAT items:24:crawler_items_checked 0
STAT items:24:lrutail_reflocked 0
STAT items:25:number 8
STAT items:25:age 15290
STAT items:25:evicted 0
STAT items:25:evicted_nonzero 0
STAT items:25:evicted_time 0
STAT items:25:outofmemory 0
STAT items:25:tailrepairs 0
STAT items:25:reclaimed 2
STAT items:25:expired_unfetched 2
STAT items:25:evicted_unfetched 0
STAT items:25:crawler_reclaimed 0
STAT items:25:crawler_items_checked 0
STAT items:25:lrutail_reflocked 0
STAT items:26:number 1
STAT items:26:age 10
STAT items:26:evicted 0
STAT items:26:evicted_nonzero 0
STAT items:26:evicted_time 0
STAT items:26:outofmemory 0
STAT items:26:tailrepairs 0
STAT items:26:reclaimed 0
STAT items:26:expired_unfetched 0
STAT items:26:evicted_unfetched 0
STAT items:26:crawler_reclaimed 0
STAT items:26:crawler_items_checked 0
STAT items:26:lrutail_reflocked 0
STAT items:27:number 2
STAT items:27:age 7410
STAT items:27:evicted 0
STAT items:27:evicted_nonzero 0
STAT items:27:evicted_time 0
STAT items:27:outofmemory 0
STAT items:27:tailrepairs 0
STAT items:27:reclaimed 0
STAT items:27:expired_unfetched 0
STAT items:27:evicted_unfetched 0
STAT items:27:crawler_reclaimed 0
STAT items:27:crawler_items_checked 0
STAT items:27:lrutail_reflocked 0
STAT items:28:number 1
STAT items:28:age 48650
STAT items:28:evicted 0
STAT items:28:evicted_nonzero 0
STAT items:28:evicted_time 0
STAT items:28:outofmemory 0
STAT items:28:tailrepairs 0
STAT items:28:reclaimed 1
STAT items:28:expired_unfetched 1
STAT items:28:evicted_unfetched 0
STAT items:28:crawler_reclaimed 0
STAT items:28:crawler_items_checked 0
STAT items:28:lrutail_reflocked 0
STAT items:29:number 1
STAT items:29:age 39
STAT items:29:evicted 0
STAT items:29:evicted_nonzero 0
STAT items:29:evicted_time 0
STAT items:29:outofmemory 0
STAT items:29:tailrepairs 0
STAT items:29:reclaimed 6
STAT items:29:expired_unfetched 6
STAT items:29:evicted_unfetched 0
STAT items:29:crawler_reclaimed 0
STAT items:29:crawler_items_checked 0
STAT items:29:lrutail_reflocked 0
END
stats slabs
STAT 1:chunk_size 96
STAT 1:chunks_per_page 10922
STAT 1:total_pages 1
STAT 1:total_chunks 10922
STAT 1:used_chunks 5961
STAT 1:free_chunks 4961
STAT 1:free_chunks_end 0
STAT 1:mem_requested 563634
STAT 1:get_hits 81214
STAT 1:cmd_set 426311
STAT 1:delete_hits 2
STAT 1:incr_hits 0
STAT 1:decr_hits 0
STAT 1:cas_hits 0
STAT 1:cas_badval 0
STAT 1:touch_hits 0
STAT 2:chunk_size 120
STAT 2:chunks_per_page 8738
STAT 2:total_pages 7
STAT 2:total_chunks 61166
STAT 2:used_chunks 56075
STAT 2:free_chunks 5091
STAT 2:free_chunks_end 0
STAT 2:mem_requested 6235884
STAT 2:get_hits 8707988
STAT 2:cmd_set 6507312
STAT 2:delete_hits 5
STAT 2:incr_hits 0
STAT 2:decr_hits 0
STAT 2:cas_hits 0
STAT 2:cas_badval 0
STAT 2:touch_hits 0
STAT 3:chunk_size 152
STAT 3:chunks_per_page 6898
STAT 3:total_pages 1
STAT 3:total_chunks 6898
STAT 3:used_chunks 1792
STAT 3:free_chunks 5106
STAT 3:free_chunks_end 0
STAT 3:mem_requested 240687
STAT 3:get_hits 207038
STAT 3:cmd_set 3070
STAT 3:delete_hits 3
STAT 3:incr_hits 0
STAT 3:decr_hits 0
STAT 3:cas_hits 0
STAT 3:cas_badval 0
STAT 3:touch_hits 0
STAT 4:chunk_size 192
STAT 4:chunks_per_page 5461
STAT 4:total_pages 8
STAT 4:total_chunks 43688
STAT 4:used_chunks 40731
STAT 4:free_chunks 2957
STAT 4:free_chunks_end 0
STAT 4:mem_requested 6634972
STAT 4:get_hits 68720
STAT 4:cmd_set 64822
STAT 4:delete_hits 19
STAT 4:incr_hits 0
STAT 4:decr_hits 0
STAT 4:cas_hits 0
STAT 4:cas_badval 0
STAT 4:touch_hits 0
STAT 5:chunk_size 240
STAT 5:chunks_per_page 4369
STAT 5:total_pages 1
STAT 5:total_chunks 4369
STAT 5:used_chunks 372
STAT 5:free_chunks 3997
STAT 5:free_chunks_end 0
STAT 5:mem_requested 78639
STAT 5:get_hits 422171
STAT 5:cmd_set 44082
STAT 5:delete_hits 12
STAT 5:incr_hits 0
STAT 5:decr_hits 0
STAT 5:cas_hits 0
STAT 5:cas_badval 0
STAT 5:touch_hits 0
STAT 6:chunk_size 304
STAT 6:chunks_per_page 3449
STAT 6:total_pages 2
STAT 6:total_chunks 6898
STAT 6:used_chunks 4120
STAT 6:free_chunks 2778
STAT 6:free_chunks_end 0
STAT 6:mem_requested 1104344
STAT 6:get_hits 240576
STAT 6:cmd_set 73203
STAT 6:delete_hits 0
STAT 6:incr_hits 0
STAT 6:decr_hits 0
STAT 6:cas_hits 0
STAT 6:cas_badval 0
STAT 6:touch_hits 0
STAT 7:chunk_size 384
STAT 7:chunks_per_page 2730
STAT 7:total_pages 1
STAT 7:total_chunks 2730
STAT 7:used_chunks 790
STAT 7:free_chunks 1940
STAT 7:free_chunks_end 0
STAT 7:mem_requested 278381
STAT 7:get_hits 93750
STAT 7:cmd_set 51505
STAT 7:delete_hits 2
STAT 7:incr_hits 0
STAT 7:decr_hits 0
STAT 7:cas_hits 0
STAT 7:cas_badval 0
STAT 7:touch_hits 0
STAT 8:chunk_size 480
STAT 8:chunks_per_page 2184
STAT 8:total_pages 4
STAT 8:total_chunks 8736
STAT 8:used_chunks 7585
STAT 8:free_chunks 1151
STAT 8:free_chunks_end 0
STAT 8:mem_requested 3401292
STAT 8:get_hits 459700
STAT 8:cmd_set 82342
STAT 8:delete_hits 18
STAT 8:incr_hits 0
STAT 8:decr_hits 0
STAT 8:cas_hits 0
STAT 8:cas_badval 0
STAT 8:touch_hits 0
STAT 9:chunk_size 600
STAT 9:chunks_per_page 1747
STAT 9:total_pages 21
STAT 9:total_chunks 36687
STAT 9:used_chunks 35050
STAT 9:free_chunks 1637
STAT 9:free_chunks_end 0
STAT 9:mem_requested 19181575
STAT 9:get_hits 2871036
STAT 9:cmd_set 38204
STAT 9:delete_hits 6
STAT 9:incr_hits 0
STAT 9:decr_hits 0
STAT 9:cas_hits 0
STAT 9:cas_badval 0
STAT 9:touch_hits 0
STAT 10:chunk_size 752
STAT 10:chunks_per_page 1394
STAT 10:total_pages 108
STAT 10:total_chunks 150552
STAT 10:used_chunks 149803
STAT 10:free_chunks 749
STAT 10:free_chunks_end 0
STAT 10:mem_requested 99792048
STAT 10:get_hits 268634
STAT 10:cmd_set 247156
STAT 10:delete_hits 29
STAT 10:incr_hits 0
STAT 10:decr_hits 0
STAT 10:cas_hits 0
STAT 10:cas_badval 0
STAT 10:touch_hits 0
STAT 11:chunk_size 944
STAT 11:chunks_per_page 1110
STAT 11:total_pages 4
STAT 11:total_chunks 4440
STAT 11:used_chunks 3618
STAT 11:free_chunks 822
STAT 11:free_chunks_end 0
STAT 11:mem_requested 2939389
STAT 11:get_hits 446056
STAT 11:cmd_set 180339
STAT 11:delete_hits 8
STAT 11:incr_hits 0
STAT 11:decr_hits 0
STAT 11:cas_hits 0
STAT 11:cas_badval 0
STAT 11:touch_hits 0
STAT 12:chunk_size 1184
STAT 12:chunks_per_page 885
STAT 12:total_pages 4
STAT 12:total_chunks 3540
STAT 12:used_chunks 2761
STAT 12:free_chunks 779
STAT 12:free_chunks_end 0
STAT 12:mem_requested 3004504
STAT 12:get_hits 309665
STAT 12:cmd_set 83899
STAT 12:delete_hits 24
STAT 12:incr_hits 0
STAT 12:decr_hits 0
STAT 12:cas_hits 0
STAT 12:cas_badval 0
STAT 12:touch_hits 0
STAT 13:chunk_size 1480
STAT 13:chunks_per_page 708
STAT 13:total_pages 5
STAT 13:total_chunks 3540
STAT 13:used_chunks 3179
STAT 13:free_chunks 361
STAT 13:free_chunks_end 0
STAT 13:mem_requested 4259717
STAT 13:get_hits 28370749
STAT 13:cmd_set 68969
STAT 13:delete_hits 13
STAT 13:incr_hits 0
STAT 13:decr_hits 0
STAT 13:cas_hits 0
STAT 13:cas_badval 0
STAT 13:touch_hits 0
STAT 14:chunk_size 1856
STAT 14:chunks_per_page 564
STAT 14:total_pages 18
STAT 14:total_chunks 10152
STAT 14:used_chunks 10086
STAT 14:free_chunks 66
STAT 14:free_chunks_end 0
STAT 14:mem_requested 16986931
STAT 14:get_hits 3157171
STAT 14:cmd_set 132225
STAT 14:delete_hits 10
STAT 14:incr_hits 0
STAT 14:decr_hits 0
STAT 14:cas_hits 0
STAT 14:cas_badval 0
STAT 14:touch_hits 0
STAT 15:chunk_size 2320
STAT 15:chunks_per_page 451
STAT 15:total_pages 20
STAT 15:total_chunks 9020
STAT 15:used_chunks 8951
STAT 15:free_chunks 69
STAT 15:free_chunks_end 0
STAT 15:mem_requested 18321641
STAT 15:get_hits 1597351
STAT 15:cmd_set 61748
STAT 15:delete_hits 14
STAT 15:incr_hits 0
STAT 15:decr_hits 0
STAT 15:cas_hits 0
STAT 15:cas_badval 0
STAT 15:touch_hits 0
STAT 16:chunk_size 2904
STAT 16:chunks_per_page 361
STAT 16:total_pages 21
STAT 16:total_chunks 7581
STAT 16:used_chunks 7412
STAT 16:free_chunks 169
STAT 16:free_chunks_end 0
STAT 16:mem_requested 19580435
STAT 16:get_hits 1373608
STAT 16:cmd_set 53399
STAT 16:delete_hits 3
STAT 16:incr_hits 0
STAT 16:decr_hits 0
STAT 16:cas_hits 0
STAT 16:cas_badval 0
STAT 16:touch_hits 0
STAT 17:chunk_size 3632
STAT 17:chunks_per_page 288
STAT 17:total_pages 53
STAT 17:total_chunks 15264
STAT 17:used_chunks 15124
STAT 17:free_chunks 140
STAT 17:free_chunks_end 0
STAT 17:mem_requested 49645401
STAT 17:get_hits 550586
STAT 17:cmd_set 53871
STAT 17:delete_hits 0
STAT 17:incr_hits 0
STAT 17:decr_hits 0
STAT 17:cas_hits 0
STAT 17:cas_badval 0
STAT 17:touch_hits 0
STAT 18:chunk_size 4544
STAT 18:chunks_per_page 230
STAT 18:total_pages 62
STAT 18:total_chunks 14260
STAT 18:used_chunks 14056
STAT 18:free_chunks 204
STAT 18:free_chunks_end 0
STAT 18:mem_requested 56777676
STAT 18:get_hits 301596
STAT 18:cmd_set 51062
STAT 18:delete_hits 0
STAT 18:incr_hits 0
STAT 18:decr_hits 0
STAT 18:cas_hits 0
STAT 18:cas_badval 0
STAT 18:touch_hits 0
STAT 19:chunk_size 5680
STAT 19:chunks_per_page 184
STAT 19:total_pages 71
STAT 19:total_chunks 13064
STAT 19:used_chunks 12898
STAT 19:free_chunks 166
STAT 19:free_chunks_end 0
STAT 19:mem_requested 65472338
STAT 19:get_hits 241400
STAT 19:cmd_set 36218
STAT 19:delete_hits 1
STAT 19:incr_hits 0
STAT 19:decr_hits 0
STAT 19:cas_hits 0
STAT 19:cas_badval 0
STAT 19:touch_hits 0
STAT 20:chunk_size 7104
STAT 20:chunks_per_page 147
STAT 20:total_pages 80
STAT 20:total_chunks 11760
STAT 20:used_chunks 11628
STAT 20:free_chunks 132
STAT 20:free_chunks_end 0
STAT 20:mem_requested 73974308
STAT 20:get_hits 361496
STAT 20:cmd_set 33450
STAT 20:delete_hits 0
STAT 20:incr_hits 0
STAT 20:decr_hits 0
STAT 20:cas_hits 0
STAT 20:cas_badval 0
STAT 20:touch_hits 0
STAT 21:chunk_size 8880
STAT 21:chunks_per_page 118
STAT 21:total_pages 90
STAT 21:total_chunks 10620
STAT 21:used_chunks 10586
STAT 21:free_chunks 34
STAT 21:free_chunks_end 0
STAT 21:mem_requested 84182384
STAT 21:get_hits 86110
STAT 21:cmd_set 26348
STAT 21:delete_hits 0
STAT 21:incr_hits 0
STAT 21:decr_hits 0
STAT 21:cas_hits 0
STAT 21:cas_badval 0
STAT 21:touch_hits 0
STAT 22:chunk_size 11104
STAT 22:chunks_per_page 94
STAT 22:total_pages 99
STAT 22:total_chunks 9306
STAT 22:used_chunks 9259
STAT 22:free_chunks 47
STAT 22:free_chunks_end 0
STAT 22:mem_requested 92278715
STAT 22:get_hits 12551
STAT 22:cmd_set 17658
STAT 22:delete_hits 0
STAT 22:incr_hits 0
STAT 22:decr_hits 0
STAT 22:cas_hits 0
STAT 22:cas_badval 0
STAT 22:touch_hits 0
STAT 23:chunk_size 13880
STAT 23:chunks_per_page 75
STAT 23:total_pages 79
STAT 23:total_chunks 5925
STAT 23:used_chunks 5866
STAT 23:free_chunks 59
STAT 23:free_chunks_end 0
STAT 23:mem_requested 71067496
STAT 23:get_hits 4995
STAT 23:cmd_set 9498
STAT 23:delete_hits 4
STAT 23:incr_hits 0
STAT 23:decr_hits 0
STAT 23:cas_hits 0
STAT 23:cas_badval 0
STAT 23:touch_hits 0
STAT 24:chunk_size 17352
STAT 24:chunks_per_page 60
STAT 24:total_pages 3
STAT 24:total_chunks 180
STAT 24:used_chunks 144
STAT 24:free_chunks 36
STAT 24:free_chunks_end 0
STAT 24:mem_requested 2063001
STAT 24:get_hits 755
STAT 24:cmd_set 814
STAT 24:delete_hits 0
STAT 24:incr_hits 0
STAT 24:decr_hits 0
STAT 24:cas_hits 0
STAT 24:cas_badval 0
STAT 24:touch_hits 0
STAT 25:chunk_size 21696
STAT 25:chunks_per_page 48
STAT 25:total_pages 1
STAT 25:total_chunks 48
STAT 25:used_chunks 8
STAT 25:free_chunks 40
STAT 25:free_chunks_end 0
STAT 25:mem_requested 154438
STAT 25:get_hits 6955
STAT 25:cmd_set 232
STAT 25:delete_hits 2
STAT 25:incr_hits 0
STAT 25:decr_hits 0
STAT 25:cas_hits 0
STAT 25:cas_badval 0
STAT 25:touch_hits 0
STAT 26:chunk_size 27120
STAT 26:chunks_per_page 38
STAT 26:total_pages 1
STAT 26:total_chunks 38
STAT 26:used_chunks 1
STAT 26:free_chunks 37
STAT 26:free_chunks_end 0
STAT 26:mem_requested 25006
STAT 26:get_hits 46
STAT 26:cmd_set 47
STAT 26:delete_hits 0
STAT 26:incr_hits 0
STAT 26:decr_hits 0
STAT 26:cas_hits 0
STAT 26:cas_badval 0
STAT 26:touch_hits 0
STAT 27:chunk_size 33904
STAT 27:chunks_per_page 30
STAT 27:total_pages 1
STAT 27:total_chunks 30
STAT 27:used_chunks 2
STAT 27:free_chunks 28
STAT 27:free_chunks_end 0
STAT 27:mem_requested 58824
STAT 27:get_hits 106
STAT 27:cmd_set 31
STAT 27:delete_hits 0
STAT 27:incr_hits 0
STAT 27:decr_hits 0
STAT 27:cas_hits 0
STAT 27:cas_badval 0
STAT 27:touch_hits 0
STAT 28:chunk_size 42384
STAT 28:chunks_per_page 24
STAT 28:total_pages 1
STAT 28:total_chunks 24
STAT 28:used_chunks 1
STAT 28:free_chunks 23
STAT 28:free_chunks_end 0
STAT 28:mem_requested 37611
STAT 28:get_hits 0
STAT 28:cmd_set 4
STAT 28:delete_hits 0
STAT 28:incr_hits 0
STAT 28:decr_hits 0
STAT 28:cas_hits 0
STAT 28:cas_badval 0
STAT 28:touch_hits 0
STAT 29:chunk_size 52984
STAT 29:chunks_per_page 19
STAT 29:total_pages 1
STAT 29:total_chunks 19
STAT 29:used_chunks 1
STAT 29:free_chunks 18
STAT 29:free_chunks_end 0
STAT 29:mem_requested 44259
STAT 29:get_hits 8965029
STAT 29:cmd_set 202
STAT 29:delete_hits 0
STAT 29:incr_hits 0
STAT 29:decr_hits 0
STAT 29:cas_hits 0
STAT 29:cas_badval 0
STAT 29:touch_hits 0
STAT active_slabs 29
STAT total_malloced 802942768
END

@jiejieling
Copy link
Author

And are there any other way for me to debug the crash ?

@dormando
Copy link
Member

dormando commented May 4, 2017

Thanks! that is helpful. Sorry, I've been a little busy so I don't have a lot of great ideas yet.

The area of code is very narrow though, since you are using so few features. The stats output helps a lot.

I'd like to try two sort of crazy things just to rule them out:

  1. in items.c:do_item_get:865 (in 1.4.36):
    right before refcount_incr(it), add:
    assert(it->refcount < 60000);

so it looks like:

    item *it = assoc_find(key, nkey, hv);
    if (it != NULL) {
        assert(it->refcount < 60000);
        refcount_incr(it);

this is to rule out the refcount overflowing, hitting 0, and then the item getting frreed while linked.

  1. start with -o hash_algorithm=murmur3

this changes the key distribution in the hash table, in case that's a bug (very far fetched).

Since your connection count is low, my only guess for a refcount overflow would be if you are accidentally generating massive multigets for the same key. We can protect better against that by forcing a miss instead of upping the refcount, I just haven't written it yet since it's never been reported before.

but, have to prove the theory first.

if I come up with any other ideas for things for you to test I'll let you know.

@jiejieling
Copy link
Author

Thanks very much !
I get your point, and I will try it right way.

@jiejieling
Copy link
Author

Hey, you are right !!
I have got the new assertion 'memcached-debug: items.c:865: do_item_get: Assertion `it->refcount < 60000' failed', and the next ? change refcount short type to int ?

@dormando
Copy link
Member

dormando commented May 5, 2017

Hah, nice. No, you should really look at your app and find out why that's happening. Since your connection count is very low, you're likely fetching the same key over and over again, and either not reading the response or asking for many at once, ie; "get key1 key1 key1 key1". First and foremost that's not doing you any favors, so figure out how you're getting into that state.

In 1.4.36, you have access to "watch fetchers", which gives you some view into it.

I'll try up a patch to force a miss if refcount is too high. probably not until the weekend though. (it's a little more complicated than just doing that)

@jiejieling
Copy link
Author

Hey dormando, you are right again !!
I have found any codes like 'get key1 key1 key1 key1...' in our app.
I will rebuild our app to fix it, thank you so so much !!

BTW, I have temporary modified the code in item.c to prevent refcount out memory:

     if (it != NULL) {
    	if (it->refcount >= USHRT_MAX)
    		it = NULL;
    	else
    		refcount_incr(it);

@dormando
Copy link
Member

dormando commented May 5, 2017

good luck!

Your change can still cause some really bad problems. Something safer would be to check down in the expire code in do_item_get: treat it as expired (unlink) if refcount is > USHRT_MAX-10, which leaves some headroom for other functions which increase the refcount on their own.

It's not safe for some functions to get a miss, just the get protocol commands

@jiejieling
Copy link
Author

I got it, our app has recovered oneself now.
Waiting for your patch.

Thanks !

@dormando
Copy link
Member

dormando commented May 6, 2017

awesome! I really appreciate you sticking around to work through it.

@dormando
Copy link
Member

dormando commented May 8, 2017

didn't get to this over the weekend; should happen sometime during the week or next weekend.

@jiejieling
Copy link
Author

Ok

@dormando
Copy link
Member

a8c4a82

fix is here. gone into the 'next' branch for the next release.

thanks again for your report and patience! It's not obvious when this is kicking in unfortunately.

@anarcat
Copy link

anarcat commented Mar 29, 2018

is there a reproducer for this issue? we're trying to see if older releases of memcached (1.4.13, in Debian LTS/wheezy) are affected by this and it would be useful to have a regression test.

thanks!

@dormando
Copy link
Member

@anarcat
Copy link

anarcat commented Mar 29, 2018

great, thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants