** No longer affects: oslo -- You received this bug notification because you are a member of Yahoo! Engineering Team, which is subscribed to OpenStack Compute (nova). https://bugs.launchpad.net/bugs/1273478
Title: NetworkInfoAsyncWrapper __str__ can cause deadlock when called from a log message Status in OpenStack Compute (Nova): Fix Released Bug description: CPython logging library generates the string representation of the message to log under a lock. def handle(self, record): """ Conditionally emit the specified logging record. Emission depends on filters which may have been added to the handler. Wrap the actual emission of the record with acquisition/release of the I/O thread lock. Returns whether the filter passed the record for emission. """ rv = self.filter(record) if rv: self.acquire() try: self.emit(record) finally: self.release() return rv Nova will use the __str__ method of the NetworkInfoAsyncWrapper when logging a message as in: nova/virt/libvirt/driver.py:to_xml() LOG.debug(_('Start to_xml instance=%(instance)s ' 'network_info=%(network_info)s ' 'disk_info=%(disk_info)s ' 'image_meta=%(image_meta)s rescue=%(rescue)s' 'block_device_info=%(block_device_info)s'), {'instance': instance, 'network_info': network_info, 'disk_info': disk_info, 'image_meta': image_meta, 'rescue': rescue, 'block_device_info': block_device_info}) Currently this causes the __str__ method to be called under the logging lock: File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 3058, in to_xml 'rescue': rescue, 'block_device_info': block_device_info}) File "/usr/lib/python2.7/logging/__init__.py", line 1412, in debug self.logger.debug(msg, *args, **kwargs) File "/usr/lib/python2.7/logging/__init__.py", line 1128, in debug self._log(DEBUG, msg, args, **kwargs) File "/usr/lib/python2.7/logging/__init__.py", line 1258, in _log self.handle(record) File "/usr/lib/python2.7/logging/__init__.py", line 1268, in handle self.callHandlers(record) File "/usr/lib/python2.7/logging/__init__.py", line 1308, in callHandlers hdlr.handle(record) File "/usr/lib/python2.7/logging/__init__.py", line 748, in handle self.emit(record) File "/usr/lib/python2.7/logging/handlers.py", line 414, in emit logging.FileHandler.emit(self, record) File "/usr/lib/python2.7/logging/__init__.py", line 930, in emit StreamHandler.emit(self, record) File "/usr/lib/python2.7/logging/__init__.py", line 846, in emit msg = self.format(record) File "/usr/lib/python2.7/logging/__init__.py", line 723, in format return fmt.format(record) File "/usr/lib/python2.7/dist-packages/nova/openstack/common/log.py", line 517, in format return logging.Formatter.format(self, record) File "/usr/lib/python2.7/logging/__init__.py", line 464, in format record.message = record.getMessage() File "/usr/lib/python2.7/logging/__init__.py", line 328, in getMessage msg = msg % self.args File "/usr/lib/python2.7/dist-packages/nova/network/model.py", line 383, in __str__ return self._sync_wrapper(fn, *args, **kwargs) This then waits for an eventlet to complete. This eventlet may itself attempt to use a log message as it executes. This sequence of operations can produce a deadlock between a greenlet thread waiting for the async operation to finish and the async job itself, if it decides to log a message. To manage notifications about this bug go to: https://bugs.launchpad.net/nova/+bug/1273478/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : yahoo-eng-team@lists.launchpad.net Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp