Bug 1207705

Summary: [vdsm] Template creation failure exception due to "CopyImageError" is not logged correctly
Product: Red Hat Enterprise Virtualization Manager Reporter: Elad <ebenahar>
Component: vdsmAssignee: Allon Mureinik <amureini>
Status: CLOSED ERRATA QA Contact: Elad <ebenahar>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 3.5.1CC: bazulay, ebenahar, gklein, lpeer, lsurette, sherold, tnisan, yeylon, ykaul
Target Milestone: ovirt-3.6.0-rcKeywords: Regression
Target Release: 3.6.0   
Hardware: x86_64   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-03-09 19:34:57 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Storage RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
logs from engine and vdsm and db dump
none
/rhev/data-center tree and lvs outputs none

Description Elad 2015-03-31 13:59:36 UTC
Created attachment 1009072 [details]
logs from engine and vdsm and db dump

Description of problem:
Template creation on a block domain (iSCSI and FC) fails with the following error in vdsm:

166d5870-ef4a-43f2-8576-08c4c3eb6015::ERROR::2015-03-31 16:21:01,107::task::866::Storage.TaskManager.Task::(_setError) Task=`166d5870-ef4a-43f2-8576-08c4c3eb6015`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 873, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/storage/task.py", line 334, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/share/vdsm/storage/securable.py", line 77, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/share/vdsm/storage/sp.py", line 1508, in copyImage
    postZero, force)
  File "/usr/share/vdsm/storage/image.py", line 784, in copyCollapsed
    (srcImgUUID, dstImgUUID, str(e)))
CopyImageError: low level Image copy failed: (u"src image=f083f8a2-8aa6-4d33-885f-6648252de5d0, dst image=b2cf2203-ee0e-47c7-9725-2a7c366eaf9d: msg=local variable 'e' referenced before a
ssignment",)


Version-Release number of selected component (if applicable):
rhev 3.5.1 vt14.1
vdsm-4.16.12.1-3.el7ev.x86_64
libvirt-daemon-1.2.8-16.el7_1.2.x86_64
qemu-kvm-rhev-2.1.2-23.el7_1.1.x86_64
rhevm-3.5.1-0.2.el6ev.noarch

How reproducible:
Not 100%, seems to be reproduce on more than 5G images

Steps to Reproduce:
1. Create a VM with 10G disk resides on a block domain
2. Create a template out of the VM


Actual results:
Template creation fails with the mentioned exception

Expected results:
Template creation should succeed 

Additional info: logs from engine and vdsm and db dump

Comment 1 Elad 2015-03-31 14:04:28 UTC
Created attachment 1009083 [details]
/rhev/data-center tree and lvs outputs

Comment 2 Tal Nisan 2015-04-05 11:59:10 UTC
Elad, this bug is divided into 2 problems, first and foremost that the template creation fails and aside for that, due to a bug in the code, the exception is not logged correctly making it impossible to determine the cause of the failure.
The patch tracked here (38669) is fixing the exception part making it possible to trace the cause of the template creation failure.
You should run the scenario again after this fix (possible to just update it directly on your host and do it immediately) and either open another bug for the template creation failure along with the logs containing the stack trace

Comment 3 Elad 2015-04-05 12:30:24 UTC
This bug will track the wrong handling with the exception. Created a new bug for the failure itself.

https://bugzilla.redhat.com/show_bug.cgi?id=1209034

Comment 6 Elad 2015-05-13 07:25:43 UTC
Template creation failure is now logged right in vdsm:

1dcff316-0127-468c-be23-f38db0358e3b::ERROR::2015-05-13 09:36:43,152::task::863::Storage.TaskManager.Task::(_setError) Task=`1dcff316-0127-468c-be23-f38db0358e3b`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 870, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/storage/task.py", line 331, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/share/vdsm/storage/securable.py", line 77, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/share/vdsm/storage/sp.py", line 1502, in copyImage
    postZero, force)
  File "/usr/share/vdsm/storage/image.py", line 842, in copyCollapsed
    raise se.CopyImageError(str(e))
CopyImageError: low level Image copy failed: ("ecode=1, stdout=[], stderr=['qemu-img: error writing zeroes at sector 0: Invalid argument'], message=None",)


Verified using ovirt-3.6.0-1
vdsm-4.17.0-632.git19a83a2.el7.x86_64

Comment 9 errata-xmlrpc 2016-03-09 19:34:57 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2016-0362.html