Merge lp:~vishvananda/nova/lp827024 into lp:~hudson-openstack/nova/trunk

[Vish Ishaya]

Fixes issue with exceptions getting eaten in image/s3.py if there is a failure during register. The variables referenced with locals() were actually out of scope.

[lp:~vishvananda/nova/lp827024]

1419. By Vish Ishaya on 2011-08-16

log the full exception so we don't lose traceback through eventlet

[Devin Carlen (devcamcar)]

lgtm

review: Approve

[Jason Kölker (jason-koelker)]

Is Bueno! The '% locals()' grated on my soul.
s/grated/grates/
;)

review: Approve

[Rick Harris (rconradharris)]

Vish:

A pattern we use elsewhere is to capture the traceback info before eventlet gets a chance to clear exceptions during its greenthread context switch. We then use a 3-arg raise to re-raise it, something like:

try:
  blah
except Exception as e:
  exc_info = sys.exc_info()
  handler_code() # <- Eventlet will clear exceptions here
  raise exc_info

What I like about that approach is that it continues to 'raise' instead of just logging, keeping the errors a bit more in your face.

Given that we were raising, should we try something like that here?

review: Needs Information

[Vish Ishaya (vishvananda)]

Rick:

I considered that, although in this case logging.exception logs a traceback in virtually the same way that a straight raise does. I think there is value in your version if there is something that needs to catch the exception, but in this case that method just runs in its own greenthread and nothing is keeping track of it, so I didn't feel like it was necessary to workaround it by reraising. I'm happy to switch it if you have a strong preference, though.

[Rick Harris (rconradharris)]

Vish: All that sounds reasonable--no strong preference here. I *slightly* prefer re-raising, but logging here seems like a good approach too.

Thanks!

review: Approve

=== modified file 'nova/image/s3.py'
--- nova/image/s3.py	2011-07-28 01:36:55 +0000
+++ nova/image/s3.py	2011-08-16 00:13:30 +0000
@@ -193,6 +193,8 @@
 
         def delayed_create():
             """This handles the fetching and decrypting of the part files."""
+            log_vars = {'image_location': image_location,
+                        'image_path': image_path}
             metadata['properties']['image_state'] = 'downloading'
             self.service.update(context, image_id, metadata)
 
@@ -213,11 +215,11 @@
                             shutil.copyfileobj(part, combined)
 
             except Exception:
-                LOG.error(_("Failed to download %(image_location)s "
-                            "to %(image_path)s"), locals())
+                LOG.exception(_("Failed to download %(image_location)s "
+                                "to %(image_path)s"), log_vars)
                 metadata['properties']['image_state'] = 'failed_download'
                 self.service.update(context, image_id, metadata)
-                raise
+                return
 
             metadata['properties']['image_state'] = 'decrypting'
             self.service.update(context, image_id, metadata)
@@ -237,11 +239,11 @@
                                     encrypted_iv, cloud_pk,
                                     dec_filename)
             except Exception:
-                LOG.error(_("Failed to decrypt %(image_location)s "
-                            "to %(image_path)s"), locals())
+                LOG.exception(_("Failed to decrypt %(image_location)s "
+                                "to %(image_path)s"), log_vars)
                 metadata['properties']['image_state'] = 'failed_decrypt'
                 self.service.update(context, image_id, metadata)
-                raise
+                return
 
             metadata['properties']['image_state'] = 'untarring'
             self.service.update(context, image_id, metadata)
@@ -249,11 +251,11 @@
             try:
                 unz_filename = self._untarzip_image(image_path, dec_filename)
             except Exception:
-                LOG.error(_("Failed to untar %(image_location)s "
-                            "to %(image_path)s"), locals())
+                LOG.exception(_("Failed to untar %(image_location)s "
+                                "to %(image_path)s"), log_vars)
                 metadata['properties']['image_state'] = 'failed_untar'
                 self.service.update(context, image_id, metadata)
-                raise
+                return
 
             metadata['properties']['image_state'] = 'uploading'
             self.service.update(context, image_id, metadata)
@@ -262,11 +264,11 @@
                     self.service.update(context, image_id,
                                         metadata, image_file)
             except Exception:
-                LOG.error(_("Failed to upload %(image_location)s "
-                            "to %(image_path)s"), locals())
+                LOG.exception(_("Failed to upload %(image_location)s "
+                                "to %(image_path)s"), log_vars)
                 metadata['properties']['image_state'] = 'failed_upload'
                 self.service.update(context, image_id, metadata)
-                raise
+                return
 
             metadata['properties']['image_state'] = 'available'
             metadata['status'] = 'active'