Cinder

cinder-api ran into hang loop in python2.6

Bug #1365901 reported by Zhikun Liu on 2014-09-05

This bug affects 2 people

	Status	Importance	Assigned to	Milestone
Cinder	Fix Released	Critical	Matt Riedemann	Cinder 2014.2 "juno"
OpenStack Compute (nova)	Fix Released	High	Matt Riedemann	OpenStack Compute (nova) 2014.2 "juno"
Icehouse	Fix Released	Undecided	Unassigned	OpenStack Compute (nova) 2014.1.4

Bug Description

#cinder-api
...
...
snip...
Exception RuntimeError: 'maximum recursion depth exceeded in __subclasscheck__' in <type 'exceptions.AttributeError'> ignored
Exception AttributeError: "'GreenSocket' object has no attribute 'fd'" in <bound method GreenSocket.__del__ of <eventlet.greenio.GreenSocket object at 0x4e052d0>> ignored
Exception RuntimeError: 'maximum recursion depth exceeded in __subclasscheck__' in <type 'exceptions.AttributeError'> ignored
Exception AttributeError: "'GreenSocket' object has no attribute 'fd'" in <bound method GreenSocket.__del__ of <eventlet.greenio.GreenSocket object at 0x4e052d0>> ignored
Exception RuntimeError: 'maximum recursion depth exceeded in __subclasscheck__' in <type 'exceptions.AttributeError'> ignored
Exception AttributeError: "'GreenSocket' object has no attribute 'fd'" in <bound method GreenSocket.__del__ of <eventlet.greenio.GreenSocket object at 0x4e052d0>> ignored
Exception RuntimeError: 'maximum recursion depth exceeded in __subclasscheck__' in <type 'exceptions.AttributeError'> ignored
Exception AttributeError: "'GreenSocket' object has no attribute 'fd'" in <bound method GreenSocket.__del__ of <eventlet.greenio.GreenSocket object at 0x4e052d0>> ignored
Exception RuntimeError: 'maximum recursion depth exceeded in __subclasscheck__' in <type 'exceptions.AttributeError'> ignored
Exception AttributeError: "'GreenSocket' object has no attribute 'fd'" in <bound method GreenSocket.__del__ of <eventlet.greenio.GreenSocket object at 0x4e052d0>> ignored
Exception RuntimeError: 'maximum recursion depth exceeded in __subclasscheck__' in <type 'exceptions.AttributeError'> ignored
Exception AttributeError: "'GreenSocket' object has no attribute 'fd'" in <bound method GreenSocket.__del__ of <eventlet.greenio.GreenSocket object at 0x4e052d0>> ignored
...
...
snip...

Tags:

Revision history for this message

Zhikun Liu (zhikunliu) wrote on 2014-09-05:

> /usr/lib/python2.6/site-packages/cinder/wsgi.py(178)__init__()
(Pdb) l
173 "after trying for 30 seconds") %
174 {'host': host, 'port': port})
175
176 (self._host, self._port) = self._socket.getsockname()[0:2]
177 import pdb;pdb.set_trace()
178 -> LOG.info(_("%(name)s listening on %(_host)s:%(_port)s")
179 % self.__dict__)
180
181 def start(self):
182 """Start serving a WSGI application.
183
(Pdb) self.__dict__
{'_use_ssl': None, 'name': 'osapi_volume', '_logger': <cinder.openstack.common.log.ContextAdapter instance at 0x3755e18>, 'app': {(None, ''): <cinder.api.middleware.fault.FaultWrapper object at 0x50d1390>, (None, '/v1'): <cinder.openstack.common.middleware.request_id.RequestIdMiddleware object at 0x50d0c50>, (None, '/v2'): <cinder.openstack.common.middleware.request_id.RequestIdMiddleware object at 0x4de8ed0>}, '_socket': <eventlet.greenio.GreenSocket object at 0x3760790>, '_pool': <eventlet.greenpool.GreenPool object at 0x3754f10>, '_port': 8776, '_wsgi_logger': <cinder.openstack.common.log.WritableLogger object at 0x3754f90>, '_protocol': <class eventlet.wsgi.HttpProtocol at 0x3355ef0>, '_host': '0.0.0.0', '_server': None, 'pool_size': 1000}
(Pdb) c
Exception RuntimeError: 'maximum recursion depth exceeded in __subclasscheck__' in <type 'exceptions.AttributeError'> ignored
....

Above LOG.info fucntion calls i18n message to deep copy each value in self.__dict__which includes a socket object.

> /usr/lib/python2.6/site-packages/oslo/i18n/_message.py(134)_sanitize_mod_params()
-> if isinstance(self.params, dict):
(Pdb) l
129 params = (other,)
130 elif isinstance(other, dict):
131 # Merge the dictionaries
132 # Copy each item in case one does not support deep copy.
133 params = {}
134 if isinstance(self.params, dict):
135 params.update((key, self._copy_param(val))
136 for key, val in self.params.items())
137 -> params.update((key, self._copy_param(val))
138 for key, val in other.items())
139 else:
(Pdb)

In python2.6 copy.deepcopy() a sokect object will raise "Exception RuntimeError: 'maximum recursion depth exceeded in __subclasscheck__' in <type 'exceptions.AttributeError'> ignored", this causes the hang loop of cinder-api.
But in python2.7, it does not have any errors.

we don't need pass self.__dict__ into the LOG function, use instance's properties directly could fix the problem.

> /usr/lib/python2.6/site-packages/cinder/wsgi.py(178)__init__()
(Pdb) l
173                                     "after trying for 30 seconds") %
174                                     {'host': host, 'port': port})
175     
176              (self._host, self._port) = self._socket.getsockname()[0:2]
177              import pdb;pdb.set_trace()
178  ->            LOG.info(_("%(name)s listening on %(_host)s:%(_port)s")
179                       % self.__dict__)
180     
181          def start(self):
182              """Start serving a WSGI application.
183     
(Pdb) self.__dict__
{'_use_ssl': None, 'name': 'osapi_volume', '_logger': <cinder.openstack.common.log.ContextAdapter instance at 0x3755e18>, 'app': {(None, ''): <cinder.api.middleware.fault.FaultWrapper object at 0x50d1390>, (None, '/v1'): <cinder.openstack.common.middleware.request_id.RequestIdMiddleware object at 0x50d0c50>, (None, '/v2'): <cinder.openstack.common.middleware.request_id.RequestIdMiddleware object at 0x4de8ed0>}, '_socket': <eventlet.greenio.GreenSocket object at 0x3760790>, '_pool': <eventlet.greenpool.GreenPool object at 0x3754f10>, '_port': 8776, '_wsgi_logger': <cinder.openstack.common.log.WritableLogger object at 0x3754f90>, '_protocol': <class eventlet.wsgi.HttpProtocol at 0x3355ef0>, '_host': '0.0.0.0', '_server': None, 'pool_size': 1000}
(Pdb) c
Exception RuntimeError: 'maximum recursion depth exceeded in __subclasscheck__' in <type 'exceptions.AttributeError'> ignored
....

Above LOG.info fucntion calls i18n message to deep copy each value in self.__dict__which includes a socket object.

> /usr/lib/python2.6/site-packages/oslo/i18n/_message.py(134)_sanitize_mod_params()
-> if isinstance(self.params, dict):
(Pdb) l
129                  params = (other,)
130              elif isinstance(other, dict):
131                  # Merge the dictionaries
132                  # Copy each item in case one does not support deep copy.
133                  params = {}
134                  if isinstance(self.params, dict):
135                      params.update((key, self._copy_param(val))
136                                    for key, val in self.params.items())
137  ->                params.update((key, self._copy_param(val))
138                                for key, val in other.items())
139              else:
(Pdb)

we don't need pass self.__dict__ into the LOG function, use instance's properties directly could fix the problem.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-09-05: Fix proposed to cinder (master)

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

Changed in cinder:
assignee:	nobody → Zhi Kun Liu (zhikunliu)
status:	New → In Progress

Matt Riedemann (mriedem) on 2014-09-05

Changed in cinder:
importance:	Undecided → Critical
tags:	added: i18n

OpenStack Infra (hudson-openstack) on 2014-09-05

Changed in cinder:
assignee:	Zhi Kun Liu (zhikunliu) → Matt Riedemann (mriedem)

Jay Bryant (jsbryant) on 2014-09-05

Changed in cinder:
milestone:	none → juno-rc1

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-09-09: Fix merged to cinder (master)

Reviewed: https://review.openstack.org/119328
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=92ae5ac0df07a68b9c7c8f58740e2d7b2e2959d0
Submitter: Jenkins
Branch: master

commit 92ae5ac0df07a68b9c7c8f58740e2d7b2e2959d0
Author: Zhi Kun Liu <email address hidden>
Date: Fri Sep 5 16:51:30 2014 +0800

remove object in wsgi LOG.info

    Method __init__ in Server class records log for wsgi server name, host
    and port using its __dict__ which includes a socket object. i18n message
    will deep copy each item's value in __dict__. In python2.6, deep copy
    the socket object will raise "Exception RuntimeError" and can not be
    caught. This makes cinder-api run into a hang loop. This patch uses the
    related properties instead of __dict__ object to fix the problem.

Closes-Bug: #1365901
Change-Id: Ia6ac51f4849d369c54ac88b1587741a2d2beb40b

Changed in cinder:
status:	In Progress → Fix Committed

Revision history for this message

Matt Riedemann (mriedem) wrote on 2014-09-23:

Nova is doing the same thing:

http://git.openstack.org/cgit/openstack/nova/tree/nova/wsgi.py#n138

Changed in nova:
importance:	Undecided → High
status:	New → In Progress
assignee:	nobody → Matt Riedemann (mriedem)

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-09-23: Fix proposed to nova (master)

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

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-09-26: Fix merged to nova (master)

Reviewed: https://review.openstack.org/123469
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=59576bc73423f37466af4c7c511190a3d51d0449
Submitter: Jenkins
Branch: master

commit 59576bc73423f37466af4c7c511190a3d51d0449
Author: Matt Riedemann <email address hidden>
Date: Tue Sep 23 08:05:54 2014 -0700

Remove usage of self.__dict__ for message var replacement

    This is the same as using locals() for variable replacement in a log
    message which violates hacking rule H501. On Cinder this actually
    caused the cinder-api process to hang on python 2.6.

Nova has the same code so this fixes the hacking violation.

Note that the H501 rule was updated in commit 55e96ee but it's not in a
released version of hacking yet (and won't be in time for Juno).

Closes-Bug: #1365901

Change-Id: I1be0db327a2fa1e866328eecd2e7c3dd3ee3cc93

Changed in nova:
status:	In Progress → Fix Committed

Thierry Carrez (ttx) on 2014-10-01

Changed in cinder:
status:	Fix Committed → Fix Released

Thierry Carrez (ttx) on 2014-10-01

Changed in nova:
milestone:	none → juno-rc1
status:	Fix Committed → Fix Released

Thierry Carrez (ttx) on 2014-10-16

Changed in nova:
milestone:	juno-rc1 → 2014.2

Thierry Carrez (ttx) on 2014-10-16

Changed in cinder:
milestone:	juno-rc1 → 2014.2

Qin Zhao (zhaoqin) on 2014-12-01

tags:

added: icehouse-backport-potential

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-12-01: Fix proposed to nova (stable/icehouse)

Fix proposed to branch: stable/icehouse
Review: https://review.openstack.org/138074

Revision history for this message

yinyin (yinyin2010) wrote on 2014-12-24:

on swift2.2.0 with python2.6, we see the same problem.

swift/common/swob.py

body = body % defaultdict(lambda: 'unknown', self.__dict__)

how to fix it?

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2015-02-02: Fix merged to nova (stable/icehouse)

Reviewed: https://review.openstack.org/138074
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=1e2abd61d2dedced7f74a5c0d08c00195513db36
Submitter: Jenkins
Branch: stable/icehouse

commit 1e2abd61d2dedced7f74a5c0d08c00195513db36
Author: Matt Riedemann <email address hidden>
Date: Tue Sep 23 08:05:54 2014 -0700

Remove usage of self.__dict__ for message var replacement

    This is the same as using locals() for variable replacement in a log
    message which violates hacking rule H501. On Cinder this actually
    caused the cinder-api process to hang on python 2.6.

Nova has the same code so this fixes the hacking violation.

Note that the H501 rule was updated in commit 55e96ee but it's not in a
released version of hacking yet (and won't be in time for Juno).

Closes-Bug: #1365901

Change-Id: I1be0db327a2fa1e866328eecd2e7c3dd3ee3cc93
(cherry picked from commit 59576bc73423f37466af4c7c511190a3d51d0449)

tags:

added: in-stable-icehouse

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

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