VMware: VimException: Exception in __deepcopy__ Method not found

Bug #1228847 reported by Gary Kotton
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
Medium
Gary Kotton
Havana
Fix Released
Medium
Gary Kotton

Bug Description

When an exception occurs in the VMWare driver, for example when there are no more IP addresses available, then the following exception is returned:

2013-09-22 05:26:22.522 ERROR nova.compute.manager [req-b29710eb-5cb9-4de1-adca-919119b10460 demo demo] [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] Error: Exception in __deepcopy__ Method not found: 'VimService.VimPort.__deepcopy__'
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] Traceback (most recent call last):
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/opt/stack/nova/nova/compute/manager.py", line 1038, in _build_instance
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] set_access_ip=set_access_ip)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/opt/stack/nova/nova/compute/claims.py", line 53, in __exit__
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] self.abort()
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/opt/stack/nova/nova/compute/claims.py", line 107, in abort
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] LOG.debug(_("Aborting claim: %s") % self, instance=self.instance)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/opt/stack/nova/nova/openstack/common/gettextutils.py", line 228, in __mod__
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] return copied._save_parameters(other)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/opt/stack/nova/nova/openstack/common/gettextutils.py", line 186, in _save_parameters
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] self.params = copy.deepcopy(other)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 190, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = _reconstruct(x, rv, 1, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 334, in _reconstruct
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] state = deepcopy(state, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 163, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = copier(x, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 257, in _deepcopy_dict
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y[deepcopy(key, memo)] = deepcopy(value, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 190, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = _reconstruct(x, rv, 1, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 334, in _reconstruct
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] state = deepcopy(state, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 163, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = copier(x, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 257, in _deepcopy_dict
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y[deepcopy(key, memo)] = deepcopy(value, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 190, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = _reconstruct(x, rv, 1, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 334, in _reconstruct
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] state = deepcopy(state, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 163, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = copier(x, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 257, in _deepcopy_dict
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y[deepcopy(key, memo)] = deepcopy(value, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 190, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = _reconstruct(x, rv, 1, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 334, in _reconstruct
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] state = deepcopy(state, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 163, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = copier(x, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 257, in _deepcopy_dict
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y[deepcopy(key, memo)] = deepcopy(value, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 190, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = _reconstruct(x, rv, 1, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 334, in _reconstruct
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] state = deepcopy(state, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 163, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = copier(x, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 257, in _deepcopy_dict
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y[deepcopy(key, memo)] = deepcopy(value, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 163, in deepcopy
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] y = copier(x, memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/usr/lib/python2.7/copy.py", line 285, in _deepcopy_inst
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] return x.__deepcopy__(memo)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] File "/opt/stack/nova/nova/virt/vmwareapi/vim.py", line 195, in vim_request_handler
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] _("Exception in %s ") % (attr_name), excep)
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c] VimException: Exception in __deepcopy__ Method not found: 'VimService.VimPort.__deepcopy__'
2013-09-22 05:26:22.522 TRACE nova.compute.manager [instance: 7f425853-63a9-4d84-8a66-38d6494b9b4c]

2013-09-22 05:37:01.926 DEBUG nova.virt.vmwareapi.driver [req-8c58e23f-3970-4c4c-bfbf-39060c0da3ba demo demo] 'VMwareAPISession' object has no attribute 'vim' from (pid=2206) __del__ /opt/stack/nova/nova/virt/vmwareapi/driver.py:705

Gary Kotton (garyk)
Changed in nova:
importance: Undecided → High
milestone: none → havana-rc1
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

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

Changed in nova:
assignee: nobody → Gary Kotton (garyk)
status: New → In Progress
Revision history for this message
Russell Bryant (russellb) wrote :

I don't think this is really High priority if it's something that only happens when an exception is raised anyway

Changed in nova:
importance: High → Medium
milestone: havana-rc1 → none
tags: added: havana-rc-potential vmware
Revision history for this message
Shawn Hartsock (hartsock) wrote :

Just looking at the error,

This looks like something tried to deep copy the value of a VimService.VimPort object which is the SOAP stub connection itself. So whatever is raising the exception is being a tad overzealous attempting to send not only the exception but the SOAP client that generated it. That seems a bit wrong.

Gary Kotton (garyk)
Changed in nova:
milestone: none → havana-rc1
Changed in nova:
milestone: havana-rc1 → none
Thierry Carrez (ttx)
tags: added: havana-backport-potential
removed: havana-rc-potential
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

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

commit be5d39eacc84c11f96357a624ffa1cdeda8a568d
Author: Gary Kotton <email address hidden>
Date: Sun Sep 22 05:50:38 2013 -0700

    VMWare: bug fix for Vim exception handling

    The exception handling in the Vim module was too broad and did not treat
    the suds.MethodNotFound exception. This would result in a exception
    that "__deepcopy__" is not supported in the VIM module.

    In the case of an exception the VMwareAPISession class may be deleted.
    The patch also ensures that the deletion is able to logout if necessary.

    Closes-bug: #1228847

    Change-Id: Ic85be9b3407c444db4b3a074108c01d9141c61be

Changed in nova:
status: In Progress → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (stable/havana)

Fix proposed to branch: stable/havana
Review: https://review.openstack.org/62820

Changed in nova:
milestone: none → icehouse-2
Thierry Carrez (ttx)
Changed in nova:
status: Fix Committed → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (stable/havana)

Reviewed: https://review.openstack.org/62820
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=d50fad849975c7fb2f8ea6395df455759f55949f
Submitter: Jenkins
Branch: stable/havana

commit d50fad849975c7fb2f8ea6395df455759f55949f
Author: Gary Kotton <email address hidden>
Date: Sun Sep 22 05:50:38 2013 -0700

    VMWare: bug fix for Vim exception handling

    The exception handling in the Vim module was too broad and did not treat
    the suds.MethodNotFound exception. This would result in a exception
    that "__deepcopy__" is not supported in the VIM module.

    In the case of an exception the VMwareAPISession class may be deleted.
    The patch also ensures that the deletion is able to logout if necessary.

    Closes-bug: #1228847

    (cherry picked from commit be5d39eacc84c11f96357a624ffa1cdeda8a568d)

    Conflicts:

     nova/tests/virt/vmwareapi/test_vmwareapi.py

    Change-Id: Ic85be9b3407c444db4b3a074108c01d9141c61be

tags: added: in-stable-havana
Thierry Carrez (ttx)
Changed in nova:
milestone: icehouse-2 → 2014.1
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.