Local context cache seems to work improperly

[Dina Belova]

== Abstract ==

I'm profiling Keystone using OSprofiler tool and the appropriate Keystone+OSprofiler integration changes - https://review.openstack.org/#/q/status:open+project:openstack/keystone+branch:master+topic:osprofiler-support-in-keystone - currently on review. The idea was to analyse how does Keystone use DB/Cache layers.

== Expected ==

The local context cache added during Mitaka should cache key-value pairs per every keystone request and grab cached value from it where possible in memoize instead of hitting to Memcache.

== Observed ==

During the nova-boot request keystone API is hit 3 times including all python clients work. If we'll take a look, for instance, on the get_domain function, it's called twice per one API call, and both times it's going to the Memcache without local cache usage.

Memcache points can appear in the trace only if memcache is *really* used, not just try to grab value from it. Also /opt/stack/keystone/keystone/common/cache/_context_cache.py file was modified to check if https://github.com/openstack/keystone/blob/master/keystone/common/cache/_context_cache.py#L78-L80 were called == local cache used. Nothing?

[Dina Belova (dbelova)]

JSON OSprofiler output for nova-boot

[Morgan Fainberg (mdrnstm)]

Confirmed. Looks like we seeing the largest benefit when memcache was not actively used. This was due to a fault in my testing. Unfortunately, this is difficult (at best) to unit test.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/304486

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/mitaka
Review: https://review.openstack.org/304487

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/304486
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=9b9bc7767fad36da1c764add842f85efdc48807b
Submitter: Jenkins
Branch: master

commit 9b9bc7767fad36da1c764add842f85efdc48807b
Author: Morgan Fainberg <email address hidden>
Date: Tue Apr 12 02:13:16 2016 -0700

    Set the values for the request_local_cache

    Instead of only using the request_local_cache when an explicit set
    occurs, make sure we always set the value for the request_local_cache
    when we have to reach for the proxied backend.

    The Context Local cache was being used previously when we were seeing
    a mix of cache misses and hits. This change ensures we now always
    set the value(s) as expected:

    Change-Id: I4857cfe1e62d54c3c89a0206ffc895c4cf681ce5
    Closes-Bug: #1567403

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/304487
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=0fcc14666f8ce67a3dc27bfdc8a755d92ce290a5
Submitter: Jenkins
Branch: stable/mitaka

commit 0fcc14666f8ce67a3dc27bfdc8a755d92ce290a5
Author: Morgan Fainberg <email address hidden>
Date: Tue Apr 12 02:13:16 2016 -0700

    Set the values for the request_local_cache

    Instead of only using the request_local_cache when an explicit set
    occurs, make sure we always set the value for the request_local_cache
    when we have to reach for the proxied backend.

    The Context Local cache was being used previously when we were seeing
    a mix of cache misses and hits. This change ensures we now always
    set the value(s) as expected:

    Change-Id: I4857cfe1e62d54c3c89a0206ffc895c4cf681ce5
    Closes-Bug: #1567403
    (cherry picked from commit 9b9bc7767fad36da1c764add842f85efdc48807b)

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/keystone 9.0.1 release.

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/keystone 10.0.0.0b1 development milestone.