Environment
~~~~~~~~~~~
* Keystone deployed in containers, running on uWSGI (per openstack-ansible defaults)
* Keystone baseline (as provided by OSA 16.0.2): 6a67918f9d5f39564af8eacc57b80cba98242683 # HEAD of "stable/pike" as of 28.09.2017
* openstack-ansible version: 16.0.2
* Target OS: Ubuntu 16.04 Xenial
* keystone.conf: http://paste.openstack.org/show/643865/ ([cache] backend = dogpile.cache.memcached)
Symptom
~~~~~~~
Running keystone against multiple memcached backends (as per OSA standard deployment pattern) results in caching being completely defeated - meaning Keystone's performance is as if caching was disabled.
Switching `backend_argument = url:<cache1ip>,<cache2ip>,<cache3ip>:11211` to `url:<cache1ip>:11211` restores caching (and performance).
Analysis
~~~~~~~~
Having turned on oslo.cache debugging with the following settings:
`
[DEFAULT]
debug = True
default_log_levels = amqp=WARN,amqplib=WARN,boto=WARN,qpid=WARN,sqlalchemy=WARN,suds=INFO,oslo.messaging=INFO,oslo_messaging=INFO,iso8601=WARN,requests.packages.urllib3.connectionpool=WARN,urllib3.connectionpool=WARN,websocket=WARN,requests.packages.urllib3.util.retry=WARN,urllib3.util.retry=WARN,keystonemiddleware=WARN,routes.middleware=WARN,stevedore=WARN,taskflow=WARN,keystoneauth=WARN,oslo.cache=DEBUG,dogpile.core.dogpile=INFO
[cache]
debug_cache_backend = True
`
It becomes obvious that every attempt to retrieve a cached value fails. This appears to be because a different key is generated (through hashing?) despite the paylod (eg: token) being identical.
Evidence
~~~~~~~~
The following log excerpts demonstrate the issue:
* http://paste.openstack.org/show/643886/
* http://paste.openstack.org/show/643887/
This is generated through two subsequent attempts to validate the same token (payload shown on the last line of both logs is the same), 3 seconds apart, within the same keystone uWSGI worker process, through the same client invokation:
curl -X GET -H "X-Auth-Token: $ADMIN_TOKEN" -H "X-Subject-Token: $SUBJECT_TOKEN" http://${HOST}:35357/v3/auth/tokens -w "\n\n%{time_total}\n\n"
Yet the cache keys for both requests are different ('5bd08aa07bf8b4bcafeac88469769a4554297df6' vs '27eb98ba5a77f3701547be6ed06f3301e124e853'). Because the keys are different, the 2nd request (for the same token) doesn't hit the cache and the (same) token is stored a 2nd time in the cache with the 2nd key.
I'm able to recreate this with 3 memcached instances, but only with the following configuration:
backend_argument = url:192.
If I rework that configuration option into using memcache_servers I don't see the issue:
memcache_servers = 192.168.
I can confirm memcache_servers works as expected by looping a token validation call and seeing traffic get routed to each instance in the ring of memcached servers.
The backend_argument doesn't seem to be working as expected. Looks like you can work around it with memcache_servers for the time being.