Exception Error logs shown in Citrix XenServer CI

[Naichuan Sun]

From a patch https://review.openstack.org/#/c/459485/ which passed our XenServer CI, we can see there are some errors in nova http://dd6b71949550285df7dc-dda4e480e005aaa13ec303551d2d8155.r49.cf1.rackcdn.com/85/459485/4/check/dsvm-tempest-neutron-network/61927a4/logs/screen-n-cpu.txt.gz
We need to figure out whether this is real problem or just configuration problem
2017-04-25 03:41:04.891 5135 DEBUG nova.virt.xenapi.vm_utils [req-600bd486-ca26-4a98-bcae-9ed50cea1f6b tempest-ImagesOneServerNegativeTestJSON-218904050 tempest-ImagesOneServerNegativeTestJSON-218904050] VHD 00e1b23b-9926-477a-a766-6e792d1a435d has parent 5f75df8a-b35f-447b-a731-7b1e12297271 _get_vhd_parent_uuid /opt/stack/new/nova/nova/virt/xenapi/vm_utils.py:1979
2017-04-25 03:41:04.895 5135 DEBUG nova.virt.xenapi.vm_utils [req-600bd486-ca26-4a98-bcae-9ed50cea1f6b tempest-ImagesOneServerNegativeTestJSON-218904050 tempest-ImagesOneServerNegativeTestJSON-218904050] VHD 5f75df8a-b35f-447b-a731-7b1e12297271 has parent 1afecff1-7ee0-405a-9f87-5e2b674657b2 _get_vhd_parent_uuid /opt/stack/new/nova/nova/virt/xenapi/vm_utils.py:1979
2017-04-25 03:41:04.988 5135 DEBUG os_xenapi.client.session [req-600bd486-ca26-4a98-bcae-9ed50cea1f6b tempest-ImagesOneServerNegativeTestJSON-218904050 tempest-ImagesOneServerNegativeTestJSON-218904050] glance.py.upload_vhd2 attempt 1/1, callback_result: http://192.168.33.1:9292 call_plugin_serialized_with_retry /opt/stack/new/os-xenapi/os_xenapi/client/session.py:242
2017-04-25 03:41:05.233 5135 DEBUG os_xenapi.client.session [req-600bd486-ca26-4a98-bcae-9ed50cea1f6b tempest-ImagesOneServerNegativeTestJSON-218904050 tempest-ImagesOneServerNegativeTestJSON-218904050] Got exception: ['XENAPI_PLUGIN_FAILURE', 'upload_vhd2', 'PluginError', 'Got Permanent Error response [404] while uploading image [244e93c0-28f1-4951-b922-665908bef7d5] to glance http://192.168.33.1:9292/v2/images/244e93c0-28f1-4951-b922-665908bef7d5/file'] _unwrap_plugin_exceptions /opt/stack/new/os-xenapi/os_xenapi/client/session.py:295
2017-04-25 03:41:05.448 5135 DEBUG nova.compute.manager [req-600bd486-ca26-4a98-bcae-9ed50cea1f6b tempest-ImagesOneServerNegativeTestJSON-218904050 tempest-ImagesOneServerNegativeTestJSON-218904050] [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] Cleaning up image 244e93c0-28f1-4951-b922-665908bef7d5 decorated_function /opt/stack/new/nova/nova/compute/manager.py:235
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] Traceback (most recent call last):
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/nova/nova/compute/manager.py", line 231, in decorated_function
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] *args, **kwargs)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/nova/nova/compute/manager.py", line 3128, in snapshot_instance
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] task_states.IMAGE_SNAPSHOT)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/nova/nova/compute/manager.py", line 3160, in _snapshot_instance
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] update_task_state)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/nova/nova/virt/xenapi/driver.py", line 198, in snapshot
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] self._vmops.snapshot(context, instance, image_id, update_task_state)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/nova/nova/virt/xenapi/vmops.py", line 928, in snapshot
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] vdi_uuids,
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/nova/nova/virt/xenapi/image/glance.py", line 94, in upload_image
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] 'upload_vhd2', params)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/nova/nova/virt/xenapi/image/glance.py", line 56, in _call_glance_plugin
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] **params)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/os-xenapi/os_xenapi/client/session.py", line 243, in call_plugin_serialized_with_retry
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] return self.call_plugin_serialized(plugin, fn, *args, **kwargs)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/os-xenapi/os_xenapi/client/session.py", line 218, in call_plugin_serialized
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] rv = self.call_plugin(plugin, fn, params)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/os-xenapi/os_xenapi/client/session.py", line 214, in call_plugin
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] self.host_ref, plugin, fn, args)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/os-xenapi/os_xenapi/client/session.py", line 293, in _unwrap_plugin_exceptions
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] return func(*args, **kwargs)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/os-xenapi/os_xenapi/client/XenAPI.py", line 239, in _call_
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] return self._send(self._name, args)
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/os-xenapi/os_xenapi/client/XenAPI.py", line 130, in xenapi_request
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] result = _parse_result(getattr(self, methodname)(*full_params))
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] File "/opt/stack/new/os-xenapi/os_xenapi/client/XenAPI.py", line 212, in _parse_result
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] raise Failure(result['ErrorDescription'])
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5] Failure: ['XENAPI_PLUGIN_FAILURE', 'upload_vhd2', 'PluginError', 'Got Permanent Error response [404] while uploading image [244e93c0-28f1-4951-b922-665908bef7d5] to glance http://192.168.33.1:9292/v2/images/244e93c0-28f1-4951-b922-665908bef7d5/file']
2017-04-25 03:41:05.448 5135 ERROR nova.compute.manager [instance: 92c76bb9-8dfb-4b35-9ee4-137ec23b82d5]

[Sean Dague (sdague)]

There are no currently open reviews on this bug, changing the status back to the previous state and unassigning. If there are active reviews related to this bug, please include links in comments.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/478429
Committed: https://git.openstack.org/cgit/openstack/os-xenapi/commit/?id=7ac84ec31dd1df6af90b2bf333253848cb4de2c3
Submitter: Jenkins
Branch: master

commit 7ac84ec31dd1df6af90b2bf333253848cb4de2c3
Author: naichuans <email address hidden>
Date: Wed Jun 28 08:19:03 2017 +0000

    os-xenapi: Exception Error logs shown in Citrix XenServer CI

    There are many errors in the patchs which passed our XenServer CI,
    it is because when run tempest, test case will ask nova sevice to
    do snapshotting, then delete image before snapshotting done. Then
    nova compute service couldn't find the image when do image upload
    and raise an exception.
    Normally the exception can be consumed by nova service. But the
    exception generated by os-xenapi can't be recognized by nova, so
    the error logs come out.

    Throw an exception XenAPI.Failure which computer service can process
    Add unit test to check XenAPI.Failure exception

    Change-Id: Ibe30a76f278264e0ddd1fc29d533fdeaab0a13a5
    Closes-Bug: 1700926

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/480406
Committed: https://git.openstack.org/cgit/openstack/os-xenapi/commit/?id=d674b8362436eb966be1a2b89230d8ac7e25a219
Submitter: Jenkins
Branch: master

commit d674b8362436eb966be1a2b89230d8ac7e25a219
Author: naichuans <email address hidden>
Date: Wed Jul 5 08:20:40 2017 +0000

    os-xenapi: Exception Error logs shown in Citrix XenServer CI

    There are many errors in the patchs which passed our XenServer CI,
    it is because when run tempest, test case will ask nova sevice to
    do snapshotting, then delete image before snapshotting done. Then
    nova compute service couldn't find the image when do image upload
    and raise an exception.
    Normally the exception can be consumed by nova service. But the
    exception generated by os-xenapi can't be recognized by nova, so
    the error logs come out.
    Add a exception in os_xenapi/client to mark image not found
    exception and convert it to another exception which computer
    service can process in nova/virt/xenapi.

    Change-Id: I16d199e93f615e4f374d49948dceeb4d1d600aa9
    Depends-On: Ibe30a76f278264e0ddd1fc29d533fdeaab0a13a5
    Closes-Bug: 1700926

[Sean Dague (sdague)]

There are no currently open reviews on this bug, changing the status back to the previous state and unassigning. If there are active reviews related to this bug, please include links in comments.

[OpenStack Infra (hudson-openstack)]

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

commit aaddd51d6fa8863a505e3f33810660b0b27be14d
Author: naichuans <email address hidden>
Date: Wed Jun 28 08:36:29 2017 +0000

    xenapi: Exception Error logs shown in Citrix XenServer CI

    There are many errors in the patchs which passed our XenServer CI,
    it is because when run tempest, test case will ask nova sevice to
    do snapshotting, then delete image before snapshotting done. Then
    nova compute service couldn't find the image when do image upload
    and raise an exception.
    Normally the exception can be consumed by nova service. But the
    exception generated by os-xenapi can't be recognized by nova, so
    the error logs come out.
    Add a exception which computer service can process.
    Modify vmops.py to transfer exception to Nova compute.
    Add unit test for exception transfer

    Change-Id: I49f1a2aab507cc4b1c4a3d6c13df96ee3e678a99
    Depends-On: I16d199e93f615e4f374d49948dceeb4d1d600aa9
    Depends-On: I80007bb897a1f7eda47ebda82e08fe270f97ff40
    Closes-Bug: 1700926

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 17.0.0.0b1 development milestone.