Evictions before expires.

[Bill Moseley]

We store some items with a 60 minute expires, yet are seeing a few log entires in our app that indicate that they are missing from Memcached much sooner (like 10 to 15 minutes).

We are also running a quite old version of Memcached: 1.4.4.

Are there any stats that would tell me if items are being evicted before their expires time?

What else should I look at to understand why they might be removed from the cache?

Do evictions only happen when a new page cannot be created?   That is limit_maxbytes - bytes is not enough for a new page for the given slab size?    Is expires time considered with LRU?

Thanks,

At the high level I'm seeing this:

About 100 evictions/second,  1K sets/sec and 200K reads/sec.

STAT limit_maxbytes 8,589,934,592

STAT bytes 7,438,136,137

STAT curr_items 51,229,586

STAT total_items 878,415,745

STAT evictions 267,995,993

--

Bill Moseley
mos...@hank.org

[Denis Samoylov]

if item expired it will not be counted as evicted.  So you need to look into "stats items" (https://dev.mysql.com/doc/mysql-ha-scalability/en/ha-memcached-stats-items.html) and look for evictions. If you have evictions this means that you do not have enough memory (or memory was allocated in other slabs: memcached does not free slabs by default, so if you for example allocated all memory for 4K slab and do not use it anymore, e.g. everything is expired in 4K slab - you wont be able to allocate memory for 1MB slab)

[Bill Moseley]

Thank you Denis for the explanation.

On Wed, Dec 9, 2015 at 9:15 PM, Denis Samoylov <samo...@gmail.com> wrote:

if item expired it will not be counted as evicted.

I'm not clear on how items with expires time are removed.  After their expires time has past are they just considered as available space in that slab?  

I'm confused about "evicted_nonzero" as I see two descriptions:

"Number of times an item which had an explicit expire time set had to be evicted from the LRU before it expired."

https://github.com/memcached/memcached/blob/master/doc/protocol.txt#L704

Or

"The time of the last evicted non-zero entry"

https://dev.mysql.com/doc/mysql-ha-scalability/en/ha-memcached-stats-items.html

 

  So you need to look into "stats items" (https://dev.mysql.com/doc/mysql-ha-scalability/en/ha-memcached-stats-items.html) and look for evictions. If you have evictions this means that you do not have enough memory (or memory was allocated in other slabs: memcached does not free slabs by default, so if you for example allocated all memory for 4K slab and do not use it anymore, e.g. everything is expired in 4K slab - you wont be able to allocate memory for 1MB slab)

Well, I have lots of evictions (see below), but the server has been up for a long time.   

But, doesn't this mean I have almost a GB of unallocated memory that can be used to allocate new pages for slabs?

STAT limit_maxbytes 8,589,934,592

STAT bytes 7,438,136,137

If that's so, why would anything be evicted?    Wouldn't Memcached allocate that memory as pages to full slab classes first?

And once a page is allocated to a slab it is never released from that slab.

Here's the non-zero values from "stats items".   The "evicted_nonzero" shows I'm evicting a lot of keys before they expired -- although I don't know the rate.   Seems like a cache flush would be good.

STAT items:1:number 3778

STAT items:1:age 11829556

STAT items:2:number 47446517

STAT items:2:age 11734712

STAT items:2:evicted 3650

STAT items:2:evicted_time 300048

STAT items:3:number 2136100

STAT items:3:age 11318274

STAT items:3:evicted 1111

STAT items:3:evicted_time 723804

STAT items:4:number 633476

STAT items:4:age 12003825

STAT items:4:evicted 54471719

STAT items:4:evicted_nonzero 54471719

STAT items:4:evicted_time 28454

STAT items:5:number 1267004

STAT items:5:age 12001656

STAT items:5:evicted 644320

STAT items:5:evicted_nonzero 644319

STAT items:5:evicted_time 30609

STAT items:6:number 24140

STAT items:6:age 10669748

STAT items:6:evicted 2962192

STAT items:6:evicted_nonzero 2949912

STAT items:6:evicted_time 1362778

STAT items:7:number 5459

STAT items:7:age 12029692

STAT items:7:evicted 6057558

STAT items:7:evicted_nonzero 6057558

STAT items:7:evicted_time 2589

STAT items:8:number 342866

STAT items:8:age 11184370

STAT items:8:evicted 45767

STAT items:8:evicted_time 847838

STAT items:9:number 1746

STAT items:9:age 12029668

STAT items:9:evicted 2026223

STAT items:9:evicted_nonzero 2026223

STAT items:9:evicted_time 2612

STAT items:10:number 5576

STAT items:10:age 12029153

STAT items:10:evicted 4268899

STAT items:10:evicted_nonzero 4268899

STAT items:10:evicted_time 3126

STAT items:11:number 3328

STAT items:11:age 12030195

STAT items:11:evicted 4107140

STAT items:11:evicted_nonzero 4107140

STAT items:11:evicted_time 2084

STAT items:12:number 11403

STAT items:12:age 12020938

STAT items:12:evicted 28072

STAT items:12:evicted_nonzero 28071

STAT items:12:evicted_time 10792

STAT items:13:number 213106

STAT items:13:age 12021699

STAT items:13:evicted 12499603

STAT items:13:evicted_nonzero 12499603

STAT items:13:evicted_time 10586

STAT items:14:number 8504

STAT items:14:age 12023367

STAT items:15:number 128175

STAT items:15:age 12026614

STAT items:15:evicted 76488055

STAT items:15:evicted_nonzero 76488040

STAT items:15:evicted_time 5689

STAT items:16:number 9385

STAT items:16:age 12030698

STAT items:16:evicted 39021091

STAT items:16:evicted_nonzero 39021079

STAT items:16:evicted_time 1581

STAT items:17:number 4319

STAT items:17:age 12030087

STAT items:17:evicted 13452454

STAT items:17:evicted_nonzero 13452438

STAT items:17:evicted_time 2193

STAT items:18:number 1374

STAT items:18:age 12029789

STAT items:18:evicted 5698741

STAT items:18:evicted_nonzero 5698734

STAT items:18:evicted_time 2475

STAT items:19:number 1103

STAT items:19:age 12028727

STAT items:19:evicted 2628417

STAT items:19:evicted_nonzero 2628410

STAT items:19:evicted_time 3548

STAT items:20:number 3377

STAT items:20:age 12029580

STAT items:20:evicted 6719357

STAT items:20:evicted_nonzero 6719317

STAT items:20:evicted_time 2690

STAT items:21:number 3301

STAT items:21:age 12029410

STAT items:21:evicted 7805240

STAT items:21:evicted_nonzero 7805216

STAT items:21:evicted_time 2867

STAT items:22:number 4886

STAT items:22:age 12029511

STAT items:22:evicted 7876885

STAT items:22:evicted_nonzero 7876881

STAT items:22:evicted_time 2765

STAT items:23:number 2999

STAT items:23:age 12030278

STAT items:23:evicted 6451060

STAT items:23:evicted_nonzero 6451053

STAT items:23:evicted_time 2002

STAT items:24:number 1257

STAT items:24:age 12031221

STAT items:24:evicted 5636498

STAT items:24:evicted_nonzero 5636493

STAT items:24:evicted_time 1058

STAT items:25:number 767

STAT items:25:age 12031501

STAT items:25:evicted 4295219

STAT items:25:evicted_nonzero 4295216

STAT items:25:evicted_time 783

STAT items:26:number 607

STAT items:26:age 12031389

STAT items:26:evicted 2926550

STAT items:26:evicted_nonzero 2926548

STAT items:26:evicted_time 890

STAT items:27:number 538

STAT items:27:age 12031340

STAT items:27:evicted 1855678

STAT items:27:evicted_nonzero 1855676

STAT items:27:evicted_time 938

STAT items:28:number 405

STAT items:28:age 12031000

STAT items:28:evicted 1323273

STAT items:28:evicted_nonzero 1323266

STAT items:28:evicted_time 1277

STAT items:29:number 417

STAT items:29:age 12029537

STAT items:29:evicted 603418

STAT items:29:evicted_nonzero 603385

STAT items:29:evicted_time 2741

STAT items:30:number 222

STAT items:30:age 12029937

STAT items:30:evicted 466043

STAT items:30:evicted_nonzero 466043

STAT items:30:evicted_time 2302

STAT items:31:number 205

STAT items:31:age 12027283

STAT items:31:evicted 158082

STAT items:31:evicted_nonzero 158082

STAT items:31:evicted_time 3535

STAT items:32:number 150

STAT items:32:age 12028665

STAT items:32:evicted 93647

STAT items:32:evicted_nonzero 93647

STAT items:32:evicted_time 3509

STAT items:33:number 86

STAT items:33:age 12029029

STAT items:33:evicted 152651

STAT items:33:evicted_nonzero 152651

STAT items:33:evicted_time 3222

STAT items:34:number 95

STAT items:34:age 12028676

STAT items:34:evicted 37551

STAT items:34:evicted_nonzero 37551

STAT items:34:evicted_time 3471

STAT items:35:number 47

STAT items:35:age 12028704

STAT items:35:evicted 7965

STAT items:35:evicted_nonzero 7965

STAT items:35:evicted_time 3599

STAT items:36:number 266

STAT items:36:age 12028693

STAT items:36:evicted 20217

STAT items:36:evicted_nonzero 20217

STAT items:36:evicted_time 3598

STAT items:37:number 10

STAT items:37:age 12028607

STAT items:37:evicted 11913

STAT items:37:evicted_nonzero 11913

STAT items:37:evicted_time 3564

STAT items:38:number 6

STAT items:38:age 12029231

STAT items:38:evicted 3178

STAT items:38:evicted_nonzero 3178

STAT items:38:evicted_time 3571

STAT items:39:number 20

STAT items:39:age 12029280

STAT items:40:number 78

STAT items:40:age 12028799

STAT items:40:evicted 69

STAT items:40:evicted_nonzero 69

STAT items:40:evicted_time 3446

STAT items:41:number 25

STAT items:41:age 12029015

STAT items:41:evicted 5911

STAT items:41:evicted_nonzero 5911

STAT items:41:evicted_time 3592

STAT items:42:number 42

STAT items:42:age 12028792

STAT items:42:evicted 8039

STAT items:42:evicted_nonzero 8039

STAT items:42:evicted_time 3475

 

--

Bill Moseley
mos...@hank.org

[dormando]

Hey,

The protocol.txt is canonical for memcached proper. the mysql
documentation are based on a fork.

The stats are pretty confusing, I apologize. Your problem is likely slab
calcification. You need to look at 'stats slabs' and not strictly 'stats
items'.

There're a few stats counters under 'stats slabs' that will tell you how
much memory has actually been allocated:
STAT active_slabs 0
STAT total_malloced 0

The 'bytes' value is the total actual bytes stored, which doesn't account
for overhead in the slab allocator (typically 10-20% loss).

This was improved significantly by the 1.4.25 release, which the release
notes (and associated PR) discuss:
https://github.com/memcached/memcached/wiki/ReleaseNotes1425#new-features

You'll see the evidence of this in long running instances if the size of
items changes over time. IE: lots of evictions against slab class 3, which
has 5 pages assigned. Meanwhile slab class 2 has 5000 pages and never
evicts.

1.4.4 isn't supported, so if you continue to have trouble I highly
recommend trying the new code (and start options) first.

-Dormando

> --
>
> ---
> You received this message because you are subscribed to the Google Groups "memcached" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to memcached+...@googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.
>
>

[Bill Moseley]

Well, sure sounds like an upgrade is in order (and well over due).   From my brief reading 1.4.25 sounds like items can get shuffled inside of a slab class and free up pages and those get put back into the free pool of pages for reallocation.   And a lot more.  Nice.

Sorry, I'm still trying to understand how evictions are reported with respect to items that have an expires.   Are they considered just deleted (free space) after the expires time?

I suspect what we are interested in monitoring at a high level is the rate of keys evicted before their expires time.   Would monitoring the change of the sum of all "evicted_nonzero" be the way to monitor?

Keys without an expires time we expect to get evicted.

Thanks,

--

Bill Moseley
mos...@hank.org

[dormando]

Hey,

expired items are lazily reclaimed. This means when they're fetched (found
expired, then memory moved to free pool), or if they are sitting at the
bottom of the LRU when a new item is being stored.

They can hold up space in some cases. For example:

- store a 0 exp time item.
- store 10 1s exp time items.
- now, say we are out of memory.
- wait a few seconds.
- store an item: the 0 exp time item is at the bottom of the LRU. the
system looks at the tail item, finds it can't reclaim it, is out of
memory, and thus evicts it. Despite there being 10 expired items in the
middle of the slab class.

This isn't too common though. Your issue is much more likely related to
slab calcification.

On the chance it wasn't, it's another thing I imrpoved ages ago, with
1.4.18: https://code.google.com/p/memcached/wiki/ReleaseNotes1418

The LRU crawler will periodically sweep through the LRU classes, pulling
expired items back into the free pool. This feature was improved over a
couple releases, and then again with .23 (stabilized in .24):
https://code.google.com/p/memcached/wiki/ReleaseNotes1423
... wherein the slab class is now split to protect against "scanning".

The recommended start lines noted in the .25 release enable all the new
features, and for many users could vastly improve their memory
efficiency.

With all of these new features, it's important to tune your TTL's
relatively well. The LRU maintainer thread can still improve hit ratios if
none of your items ever expire but page rebalancing and LRU reclaiming
only work if they're tuned well.