tokens in memcache have no/improper expiration
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
OpenStack Identity (keystone) |
Opinion
|
Low
|
Unassigned | ||
oslo.cache |
New
|
Undecided
|
Unassigned |
Bug Description
tokens stored in memcache have no (improper) expiration data when set.
Found on stable/mikata and stable/liberty using cachepool backend and the non-pooled backend.
When you store in memcache you can optionally pass in a time at which the value is no good, a ttl. Keystone should be doing this for it's local token cache but it doesn't look like it is.
Here is a dump of some slabs that have tokens in them, last field is expiration time:
stats cachedump 11 10
ITEM 8302fc81f2ffb55
ITEM 2ffe5d0821302a8
ITEM eb6e6f7e9118133
ITEM ee076b853dd5e59
Lets see if these are really tokens:
get 8302fc81f2ffb55
VALUE 8302fc81f2ffb55
cdogpile.cache.api
CachedValue
p0
((dp1
S'access'
p2
(dp3
S'token'
p4
(dp5
S'issued_at'
p6
S'2016-
p7
sS'expires'
p8
S'2016-
p9
sS'id'
p10
V<fernet token value here>
Yep thats a Fernet token.
Dumping older and older stuff, I can find cached tokens that are 24 hours old in here, 22 hours past our valid token deadline.
So lets compare that to some tokens that keystone_authtoken middleware is caching for control services:
stats cachedump 21 100
ITEM tokens/
ITEM tokens/
ITEM tokens/
ITEM tokens/
ITEM tokens/
All have valid and different expiration times so it's respecting my settings.
So what's that timestamp in the earlier list? Well it's 4/13/2016, 3:42:45 PM GMT-6:00 DST. That happens to be the last time memcache restarted and so I assume it's just filler.
What's the impact?
I've not figured out if there is one yet for sure. I have a token valid time of 2 hours and I had set cache time to the same. I did try to dig out an old token but it would not validate so I don't think there's a security issue. I suspect the main issue is that my keystone memcache always runs completely 100% full. We max memcache at 20% of RAM on a box, and that's a lot (20% of 256G). I suspect with no valid expiration time memcache is lazily evicting old tokens when it runs out of ram rather than replacing expired ones and not allocating more RAM.
[PROD] mfisch@
Name: memcached
State: S (sleeping)
Tgid: 3937
Ngid: 3937
Pid: 3937
PPid: 1
TracerPid: 0
Uid: 65534 65534 65534 65534
Gid: 65534 65534 65534 65534
FDSize: 1024
Groups: 0
VmPeak: 54500552 kB
VmSize: 54500552 kB <-- that's a lot of twinkies
I feel this merits deeper investigation.
tags: | added: fernet |
Changed in keystone: | |
assignee: | nobody → David Stanek (dstanek) |
Changed in keystone: | |
assignee: | David Stanek (dstanek) → nobody |
Changed in keystone: | |
assignee: | nobody → David Stanek (dstanek) |
tags: |
added: caching removed: fernet |
I'll look into this a little deeper, but from the information provided it doesn't sound like there is an issue. The 'stats cachedump' command will often, and maybe even likely, show things that are expired. memcache won't actually delete the item from memory until you access it again and it decides that it's expired or if it's trying to make room for new entries. In the new entries case I'm not sure if you'd see if as an eviction because the data wasn't forced out.
You can tell if an item has no expiration pretty easily if it's expiration is equal to 'time - uptime' where time and uptime can be found in the stats output.