memcache client race in wsgi middleware

Bug #1289074 reported by Peter Feiner
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
python-keystoneclient
Fix Released
Critical
Dolph Mathews

Bug Description

The memcache client that keystoneclient's WSGI middleware uses isn't thread safe, yet keystoneclient.middleware.auth_token.AuthProtocol._cache is used by every thread. In particular, what's thread-unsafe is that the memcache client has a single socket connection to the memcached server that the WSGI threads concurrently concurrently read & write to.

The consequences of this race are garbage in memcache and errors like these:

2014-03-06 14:04:56.692 16992 INFO glance.wsgi.server [-] Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/eventlet/wsgi.py", line 384, in handle_one_response
    result = self.application(self.environ, start_response)
  File "/usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py", line 567, in __call__
    token_info = self._validate_user_token(user_token)
  File "/usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py", line 822, in _validate_user_token
    self._cache_store_invalid(token_id)
  File "/usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py", line 1069, in _cache_store_invalid
    self._cache_store(token_id, 'invalid')
  File "/usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py", line 1047, in _cache_store
    time=self.token_cache_time)
  File "/usr/lib/python2.7/dist-packages/memcache.py", line 565, in set
    return self._set("set", key, val, time, min_compress_len)
  File "/usr/lib/python2.7/dist-packages/memcache.py", line 802, in _set
    return _unsafe_set()
  File "/usr/lib/python2.7/dist-packages/memcache.py", line 794, in _unsafe_set
    server.send_cmd(fullcmd)
  File "/usr/lib/python2.7/dist-packages/memcache.py", line 1112, in send_cmd
    self.socket.sendall(cmd + '\r\n')
  File "/usr/lib/python2.7/dist-packages/eventlet/greenio.py", line 307, in sendall
    tail = self.send(data, flags)
  File "/usr/lib/python2.7/dist-packages/eventlet/greenio.py", line 302, in send
    timeout_exc=socket.timeout("timed out"))
  File "/usr/lib/python2.7/dist-packages/eventlet/hubs/__init__.py", line 153, in trampoline
    listener = hub.add(hub.WRITE, fileno, current.switch)
  File "/usr/lib/python2.7/dist-packages/eventlet/hubs/poll.py", line 27, in add
    listener = super(Hub, self).add(evtype, fileno, cb)
  File "/usr/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 126, in add
    evtype, fileno, evtype))
RuntimeError: Second simultaneous write on fileno 6 detected. Unless you really know what you're doing, make sure that only one greenthread can write any particular socket. Consider using a pools.Pool. If you do know what you're doing and want to disable this error, call eventlet.debug.hub_prevent_multiple_readers(False)

I've attached a patch to fix the bug.

Revision history for this message
Peter Feiner (pete5) wrote :
Revision history for this message
Dolph Mathews (dolph) wrote :

Peter, if you have a chance, can you contact me on IRC regarding this bug and the fix? (dolphm on freenode) Thanks!

Revision history for this message
Peter Feiner (pete5) wrote :

Nova's use of nova.openstack.common.memorycache in the metadata API server, ec2 API server, etc. have the same race. I'd wager that all users of this memcache client in OpenStack have the same bug.

Dolph Mathews (dolph)
Changed in python-keystoneclient:
milestone: none → 0.7.0
Changed in python-keystoneclient:
assignee: nobody → Dolph Mathews (dolph)
status: New → In Progress
Revision history for this message
Thierry Carrez (ttx) wrote :
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix proposed to python-keystoneclient (master)

Related fix proposed to branch: master
Review: https://review.openstack.org/82172

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to python-keystoneclient (master)

Reviewed: https://review.openstack.org/81078
Committed: https://git.openstack.org/cgit/openstack/python-keystoneclient/commit/?id=d11553a72ee8febc26e4a76ba900984d1b778f59
Submitter: Jenkins
Branch: master

commit d11553a72ee8febc26e4a76ba900984d1b778f59
Author: Dolph Mathews <email address hidden>
Date: Mon Mar 17 15:56:28 2014 -0500

    add pooling for cache references

    Change-Id: Iffb1d1bff5dc4437544a5aefef3bca0e5b17cc81
    Closes-Bug: 1289074

Changed in python-keystoneclient:
status: In Progress → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix merged to python-keystoneclient (master)

Reviewed: https://review.openstack.org/82172
Committed: https://git.openstack.org/cgit/openstack/python-keystoneclient/commit/?id=82c1ec707bc4980962eb1f81cb43153457453c9a
Submitter: Jenkins
Branch: master

commit 82c1ec707bc4980962eb1f81cb43153457453c9a
Author: Dolph Mathews <email address hidden>
Date: Fri Mar 21 14:12:29 2014 -0500

    add functional test for cache pool

    Change-Id: Id12c6175dc5bf72d6c453b8ab2d66652eed13656
    Related-Bug: 1289074

Dolph Mathews (dolph)
Changed in python-keystoneclient:
status: Fix Committed → Fix Released
Revision history for this message
Dolph Mathews (dolph) wrote :

Additional details about the critical nature of this bug are documented in:

  https://bugs.launchpad.net/python-keystoneclient/+bug/1282865

Changed in python-keystoneclient:
importance: Undecided → Critical
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.