yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1570158] [NEW] memcache pool reap issue (stable/liberty)

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Fischer <matt@xxxxxxxxxxxxxxx>
Date: Thu, 14 Apr 2016 02:12:36 -0000
Reply-to: Bug 1570158 <1570158@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

There seems to be a code error in the memcache pool cleanup. I'm seeing
this on stable/liberty (built as of 2 weeks ago). I don't have a
specific reproducer for this, it just seems to happen. Looking at the
code I don't really understand how this can happen.

2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi [req-30e23a7d-754d-4a89-904f-1804a20029f2 - - - - -] deque index out of range
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi Traceback (most recent call last):
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/wsgi.py", line 248, in __call__
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     result = method(context, **params)
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/controller.py", line 138, in inner
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     context['subject_token_id']))
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/token/provider.py", line 188, in validate_token
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     token = self._validate_token(unique_id)
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1053, in decorate
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     should_cache_fn)
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 657, in get_or_create
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     async_creator) as value:
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 158, in __enter__
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     return self._enter()
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 91, in _enter
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     value = value_fn()
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 610, in get_value
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     value = self.backend.get(key)
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/cache/backends/memcached.py", line 161, in get
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     value = self.client.get(key)
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/cache/backends/memcache_pool.py", line 36, in _run_method
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     return getattr(client, __name)(*args, **kwargs)
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     self.gen.next()
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/cache/_memcache_pool.py", line 132, in acquire
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     self._drop_expired_connections()
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/cache/_memcache_pool.py", line 166, in _drop_expired_connections
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     while self.queue and self.queue[0].ttl < now:
2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi IndexError: deque index out of range

** Affects: keystone
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Identity (keystone).
https://bugs.launchpad.net/bugs/1570158

Title:
  memcache pool reap issue (stable/liberty)

Status in OpenStack Identity (keystone):
  New

Bug description:
  There seems to be a code error in the memcache pool cleanup. I'm
  seeing this on stable/liberty (built as of 2 weeks ago). I don't have
  a specific reproducer for this, it just seems to happen. Looking at
  the code I don't really understand how this can happen.

  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi [req-30e23a7d-754d-4a89-904f-1804a20029f2 - - - - -] deque index out of range
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi Traceback (most recent call last):
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/wsgi.py", line 248, in __call__
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     result = method(context, **params)
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/controller.py", line 138, in inner
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     context['subject_token_id']))
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/token/provider.py", line 188, in validate_token
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     token = self._validate_token(unique_id)
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 1053, in decorate
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     should_cache_fn)
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 657, in get_or_create
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     async_creator) as value:
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 158, in __enter__
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     return self._enter()
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/core/dogpile.py", line 91, in _enter
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     value = value_fn()
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/cache/region.py", line 610, in get_value
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     value = self.backend.get(key)
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/dogpile/cache/backends/memcached.py", line 161, in get
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     value = self.client.get(key)
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/cache/backends/memcache_pool.py", line 36, in _run_method
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     return getattr(client, __name)(*args, **kwargs)
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     self.gen.next()
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/cache/_memcache_pool.py", line 132, in acquire
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     self._drop_expired_connections()
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi   File "/venv/local/lib/python2.7/site-packages/keystone/common/cache/_memcache_pool.py", line 166, in _drop_expired_connections
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi     while self.queue and self.queue[0].ttl < now:
  2016-04-13 20:50:29.124 46 ERROR keystone.common.wsgi IndexError: deque index out of range

To manage notifications about this bug go to:
https://bugs.launchpad.net/keystone/+bug/1570158/+subscriptions
Follow ups

[Bug 1570158] Re: memcache pool reap issue
From: Steve Martinelli, 2016-08-03
[Bug 1570158] Re: memcache pool reap issue (stable/liberty)
From: Lance Bragstad, 2016-04-14