Catch all vim exceptions in disk_detach #460

msterin · 2016-06-14T03:01:07Z

Fixes #381

Catch all vim exceptions in disk_detach
Return error message from exception, and log a warning.
Also change logging in findVMByUuid to be warning (since we retry after the failure)

test: manually shutdown Photon OS with OS->Shutdown menu in ESXi embedded UI.
Before fix: exception logged and ESX service exit
After fix: exception logged and ESX Service keeps goings

Error report in the log:

6/14/16 02:53:20 1010878803 [INFO   ] *** detachVMDK: /vmfs/volumes/vsan:572904f8c031435f-06/14/16 18:02:52 1011049660 [WARNING] Failed to detach /vmfs/volumes/vsan:572904f8c031435f-3513e0db551fcc82/dockvols/vol.vmdk (The operation is not allowed in the current state.)
(vim.fault.InvalidState) {
   dynamicType = <unset>,
   dynamicProperty = (vmodl.DynamicProperty) [],
   msg = 'The operation is not allowed in the current state.',
   faultCause = <unset>,
   faultMessage = (vmodl.LocalizableMessage) []
}
06/14/16 18:02:52 1011049660 [INFO   ] executeRequest 'detach' completed with ret={u'Error': u'Failed to detach /vmfs/volumes/vsan:572904f8c031435f-3513e0db551fcc82/dockvols/vol.vmdk (The operation is not allowed in the current state.)'}

pdhamdhere · 2016-06-14T03:31:48Z

esx_service/vmdk_ops.py

-        for f in ex.faultMessage:
-            logging.warning(f.message)
-        return err("Failed to detach " + vmdk_path)
+    except Exception as ex:


Why not just catch & handle "vim.Fault.VimFault" exception and pass others to caller? This would eliminate if isinstance(...)

Ah (forehead hit), yes ! A brain hiccup I guess. Will fix. Thanks.

pdhamdhere · 2016-06-14T07:00:54Z

Fixes #399

kerneltime · 2016-06-14T18:24:24Z

esx_service/vmdk_ops.py

-    except Exception as e:
-        logging.exception("Failed to find VM uuid=%s (traceback below), " \
-                          "retrying...", vm_uuid)
+    except Exception as ex:


is there a guarantee that the second search will always complete without exception?

there is no guarantee, but we know that on connection timeout retry fixes it, and on other issues we want to rethrow if we fail in retry

kerneltime · 2016-06-14T18:26:16Z

LGTM but the error handling seems built with assumptions.

pdhamdhere · 2016-06-14T18:44:55Z

esx_service/vmdk_ops.py

-        return err("Failed to detach " + vmdk_path)
+    except vim.Fault.VimFault as ex:
+        msg = "Failed to detach %s (%s)" % (vmdk_path, ex.msg)
+        logging.warning(msg + "\n" + str(ex))


str(ex) logs traceback and exception info?

see the bug description - there is an example there

pdhamdhere · 2016-06-14T18:45:17Z

LGTM.

govint · 2016-06-14T18:50:32Z

esx_service/vmdk_ops.py

+    except vim.Fault.VimFault as ex:
+        msg = "Failed to detach %s (%s)" % (vmdk_path, ex.msg)
+        logging.warning(msg + "\n" + str(ex))
+        return err(msg)



This will leave the disk attached to the VM. Like I'd mentioned in PR #433 (original set of changes) there is nothing the plugin can do to help this situation except log the error. Does the error notify docker that the unmount has failed and docker must keep track that the volume is still in use? The volume remains in attached state if docker doesn't care to unmount again.

i am not sure what is your question ?

andrewjstone · 2016-06-14T19:37:24Z

LGTM

msterin · 2016-06-14T20:18:21Z

Updated code slightly to print out backtrace (so we know who calls us) rather that exception details (which have nothing beyond "failure reason), which we print anyways). The log looks like this now:

06/14/16 20:14:51 1011078223 [INFO   ] *** detachVMDK: /vmfs/volumes/vsan:572904f8c031435f-3513e0db551fcc82/dockvols/vol.vmdk from PhotonRC_1 VM uuid = 564d0062-db25-a480-72e2-0596eaf7fcb4
06/14/16 20:14:51 1011078223 [WARNING] Failed to detach /vmfs/volumes/vsan:572904f8c031435f-3513e0db551fcc82/dockvols/vol.vmdk: The operation is not allowed in the current state.
  File "/usr/lib/vmware/vmdkops/bin/vmdk_ops.py", line 652, in disk_detach
    wait_for_tasks(si, [vm.ReconfigVM_Task(spec=spec)])
  File "/usr/lib/vmware/vmdkops/bin/vmdk_ops.py", line 838, in wait_for_tasks
    raise task.info.error

06/14/16 20:14:51 1011078223 [INFO   ] executeRequest 'detach' completed with ret={u'Error': u'Failed to detach /vmfs/volumes/vsan:572904f8c031435f-3513e0db551fcc82/dockvols/vol.vmdk: The operation is not allowed in the current state.'}

Return error message from exception, and logs a warning with traceback. Also change logging in findVMByUuid to be warning (since we retry after the failure) Fixes #381

vmwclabot added the cla-not-required label Jun 14, 2016

pdhamdhere reviewed Jun 14, 2016
View reviewed changes

pdhamdhere mentioned this pull request Jun 14, 2016

ESX services throws on detach task failure #399

Closed

msterin force-pushed the invalid.state.msterin branch from 1ef4ff5 to dcdcc1c Compare June 14, 2016 18:05

kerneltime reviewed Jun 14, 2016
View reviewed changes

pdhamdhere reviewed Jun 14, 2016
View reviewed changes

govint reviewed Jun 14, 2016
View reviewed changes

msterin force-pushed the invalid.state.msterin branch from dcdcc1c to 490821a Compare June 14, 2016 20:16

Catch all vim exceptions in disk_detach

490821a

Return error message from exception, and logs a warning with traceback. Also change logging in findVMByUuid to be warning (since we retry after the failure) Fixes #381

msterin merged commit e91738c into master Jun 15, 2016

msterin deleted the invalid.state.msterin branch June 15, 2016 02:03

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Catch all vim exceptions in disk_detach #460

Catch all vim exceptions in disk_detach #460

msterin commented Jun 14, 2016 •

edited

pdhamdhere Jun 14, 2016

msterin Jun 14, 2016

pdhamdhere commented Jun 14, 2016

kerneltime Jun 14, 2016

msterin Jun 14, 2016

kerneltime commented Jun 14, 2016

pdhamdhere Jun 14, 2016

msterin Jun 14, 2016

pdhamdhere commented Jun 14, 2016

govint Jun 14, 2016

msterin Jun 14, 2016 •

edited

andrewjstone commented Jun 14, 2016

msterin commented Jun 14, 2016

Catch all vim exceptions in disk_detach #460

Catch all vim exceptions in disk_detach #460

Conversation

msterin commented Jun 14, 2016 • edited

pdhamdhere Jun 14, 2016

Choose a reason for hiding this comment

msterin Jun 14, 2016

Choose a reason for hiding this comment

pdhamdhere commented Jun 14, 2016

kerneltime Jun 14, 2016

Choose a reason for hiding this comment

msterin Jun 14, 2016

Choose a reason for hiding this comment

kerneltime commented Jun 14, 2016

pdhamdhere Jun 14, 2016

Choose a reason for hiding this comment

msterin Jun 14, 2016

Choose a reason for hiding this comment

pdhamdhere commented Jun 14, 2016

govint Jun 14, 2016

Choose a reason for hiding this comment

msterin Jun 14, 2016 • edited

Choose a reason for hiding this comment

andrewjstone commented Jun 14, 2016

msterin commented Jun 14, 2016

msterin commented Jun 14, 2016 •

edited

msterin Jun 14, 2016 •

edited