Bug 715040

Summary: qemu-img [vdsm]: "qemu-img convert" fails for template export to block device when there are 3 disks
Product: Red Hat Enterprise Linux 6 Reporter: Dafna Ron <dron>
Component: qemu-kvmAssignee: Kevin Wolf <kwolf>
Status: CLOSED INSUFFICIENT_DATA QA Contact: Virtualization Bugs <virt-bugs>
Severity: high Docs Contact:
Priority: high    
Version: 6.1CC: abaron, danken, ddumas, juzhang, mkenneth, ohochman, tburke, virt-maint, ykaul
Target Milestone: rcKeywords: TestBlocker
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 715325 (view as bug list) Environment:
Last Closed: 2011-09-04 10:46:22 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Bug Depends On:    
Bug Blocks: 682015, 715325    
Attachments:
Description Flags
log + script
none
log none

Description Dafna Ron 2011-06-21 17:07:49 UTC 
Created attachment 505867 [details]
log + script

Description of problem:

trying to export VM template to iscsi block device fails - only in VirtIO RAW format and over 3 disks (also tried with NFS and it succeeded). 

the error is: 
CopyImageError: low level Image copy failed: ('General Storage Exception: ("rc: 1, err: [\'qemu-img: error while writing\']",)',)

ran the below for 3 images and it also failed:

qemu-img convert -f raw /dev/bfd358ed-0ce4-472e-aba3-927232699567/48db7966-96f2-4a94-9ddd-5b1156370ccc -O qcow2 /dev/88cf2775-b831-42de-b57a-ae396619b4f3/48db7966-96f2-4a94-9ddd-5b1156370ccc 


Version-Release number of selected component (if applicable):

ic123
vdsm-4.9-75.el6.x86_64
libvirt-0.8.7-18.el6.x86_64
gpxe-roms-qemu-0.9.7-6.7.el6.noarch
qemu-kvm-0.12.1.2-2.165.el6.x86_64
qemu-kvm-tools-0.12.1.2-2.165.el6.x86_64
qemu-img-0.12.1.2-2.165.el6.x86_64

How reproducible:

100%

Steps to Reproduce:
1. create a VM with 3 preallocated VirtIO disks -> make template
2. export template to iscsi export domain 
3.
  
Actual results:

the qemu-img convert fails and template is not exported

Expected results:

should not fail

Additional info: vdsm log + script ran 

to make it easy to find even I echoed to vdsm log the following before starting the test:

>>>>>>>>>>>>>>>>>>>VirtIO.RAW-Take2
Comment 1 Dafna Ron 2011-06-21 17:11:05 UTC 
Created attachment 505869 [details]
log

log was archived right before I copied - here is correct one
Comment 3 Omri Hochman 2011-06-22 14:12:48 UTC 
reproduced on RHEL5.7 (different scenario: qemu-img: error while reading)

rhevm (build: sm101)
kernel-2.6.18-268.el5
kvm-83-237.el5
kvm-qemu-img-83-237.el5
vdsm22-4.5-63.25.el5_6

scenario:
**********
1) create VM with 2 HDs (RAW/RAW) 
2) create new template from that VM.
3) create new VM from that template --> change provisioning in 'allocation tab' to 'clone' --> change disk 1 to Preallocated  and disk 2 to Thin provision.  

Qemu-img error whilereading in vdsm.log:
****************************************
d09c909a-c2c3-4341-87ce-88f1c947450e::ERROR::2011-06-22 16:21:27,661::misc::66::irs::low level Image copy failed: ('General Storage Exception: ("rc: 1, err: [\'qemu-img: error while reading\']",)',)
d09c909a-c2c3-4341-87ce-88f1c947450e::ERROR::2011-06-22 16:21:27,661::misc::67::irs::Traceback (most recent call last):
  File "/usr/share/vdsm/storage/image.py", line 754, in copy
    raise se.CopyImageError(str(e))
CopyImageError: low level Image copy failed: ('General Storage Exception: ("rc: 1, err: [\'qemu-img: error while reading\']",)',)

d09c909a-c2c3-4341-87ce-88f1c947450e::INFO::2011-06-22 16:21:27,662::volume::517::irs::Volume: tearing down volume 828e851e-69b4-43fd-b83f-462033443e76/35089633-cdac-4b56-86e0-221a23be367f justme False
d09c909a-c2c3-4341-87ce-88f1c947450e::DEBUG::2011-06-22 16:21:27,662::misc::100::irs::'/usr/bin/sudo -n /usr/sbin/lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] write_cache_state=0 filter = [ 
\\"a%/dev/mapper/360a98000572d45366b4a645a696d7137%\\", \\"r%.*%\\" ] }  backup {  retain_min = 50  retain_days = 0 } " --noheadings -o tags 828e851e-69b4-43fd-b83f-462033443e76/35089633-cdac-4b56-86e0-221a23be
367f' (cwd None)
3ac56490-1c75-481e-adf3-6b0b6d0e7d9c::DEBUG::2011-06-22 16:21:27,680::misc::123::irs::SUCCESS: <err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000264 seconds, 1.9 MB/s\n'; <rc> = 0
3ac56490-1c75-481e-adf3-6b0b6d0e7d9c::DEBUG::2011-06-22 16:21:27,681::misc::291::irs::(validateDDBytes) err: ['1+0 records in', '1+0 records out', '512 bytes (512 B) copied, 0.000264 seconds, 1.9 MB/s'], size: 
512
3ac56490-1c75-481e-adf3-6b0b6d0e7d9c::DEBUG::2011-06-22 16:21:27,681::misc::100::irs::'/bin/dd oflag=direct ibs=512 obs=512 seek=669 of=/dev/378a1d6e-d4d0-47f3-b59d-feca75d4e966/metadata' (cwd None)
3ac56490-1c75-481e-adf3-6b0b6d0e7d9c::DEBUG::2011-06-22 16:21:27,707::misc::123::irs::SUCCESS: <err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000829 seconds, 618 kB/s\n'; <rc> = 0
3ac56490-1c75-481e-adf3-6b0b6d0e7d9c::DEBUG::2011-06-22 16:21:27,707::misc::291::irs::(validateDDBytes) err: ['1+0 records in', '1+0 records out', '512 bytes (512 B) copied, 0.000829 seconds, 618 kB/s'], size: 
512
3ac56490-1c75-481e-adf3-6b0b6d0e7d9c::DEBUG::2011-06-22 16:21:27,708::misc::100::irs::'/usr/bin/sudo -n /usr/sbin/lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] write_cache_state=0 filter = [ 
\\"a%/dev/mapper/36000402002ec074866d9c77300000000|/dev/mapper/36000402002ec074867580f0900000000|/dev/mapper/36000402002ec07486758344300000000%\\", \\"r%.*%\\" ] }  backup {  retain_min = 50  retain_days = 0 } 
" -o attr --noheadings 378a1d6e-d4d0-47f3-b59d-feca75d4e966/d2839105-d456-44e7-afee-aad3ac3688ce' (cwd None)
d09c909a-c2c3-4341-87ce-88f1c947450e::WARNING::2011-06-22 16:21:27,738::misc::125::irs::FAILED: <err> = '  /dev/mapper/360a98000572d45366b4a645a696d7137: read failed after 0 of 4096 at 47247720448: Input/output
 error\n  /dev/mapper/360a98000572d45366b4a645a696d7137: read failed after 0 of 4096 at 47247777792: Input/output error\n  /dev/mapper/360a98000572d45366b4a645a696d7137: read failed after 0 of 4096 at 0: Input/
output error\n  /dev/mapper/360a98000572d45366b4a645a696d7137: read failed after 0 of 4096 at 4096: Input/output error\n  Volume group "828e851e-69b4-43fd-b83f-462033443e76" not found\n  Skipping volume group 8
28e851e-69b4-43fd-b83f-462033443e76\n'; <rc> = 5
d09c909a-c2c3-4341-87ce-88f1c947450e::ERROR::2011-06-22 16:21:27,739::misc::66::irs::Cannot get tags of Logical Volumes: ('35089633-cdac-4b56-86e0-221a23be367f',)
d09c909a-c2c3-4341-87ce-88f1c947450e::ERROR::2011-06-22 16:21:27,739::misc::67::irs::Traceback (most recent call last):
  File "/usr/share/vdsm/storage/image.py", line 627, in __cleanupCopy
    srcVol.teardown()
  File "/usr/share/vdsm/storage/volume.py", line 518, in teardown
    self.llTeardown(rw=self.isLeaf(), setrw=setrw)
  File "/usr/share/vdsm/storage/volume.py", line 427, in isLeaf
    return self.getVolType() == type2name(LEAF_VOL)
  File "/usr/share/vdsm/storage/volume.py", line 388, in getVolType
    self.voltype = self.getMetaParam(VOLTYPE)
  File "/usr/share/vdsm/storage/volume.py", line 726, in getMetaParam
    meta = self.getMetadata(nocache=nocache)
  File "/usr/share/vdsm/storage/blockVolume.py", line 449, in getMetadata
    offs = self.getMetaOffset()
  File "/usr/share/vdsm/storage/blockVolume.py", line 427, in getMetaOffset
    l = self.vg.listLVTags(self.volUUID)
  File "/usr/share/vdsm/storage/vg.py", line 716, in listLVTags
    raise se.GetLogicalVolumeTagError(lv)
GetLogicalVolumeTagError: Cannot get tags of Logical Volumes: ('35089633-cdac-4b56-86e0-221a23be367f',)

d09c909a-c2c3-4341-87ce-88f1c947450e::ERROR::2011-06-22 16:21:27,739::misc::66::irs::low level Image copy failed: ('General Storage Exception: ("rc: 1, err: [\'qemu-img: error while reading\']",)',)
d09c909a-c2c3-4341-87ce-88f1c947450e::ERROR::2011-06-22 16:21:27,740::misc::67::irs::Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 978, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/storage/task.py", line 324, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/share/vdsm/storage/spm.py", line 107, in run
    return self.func(*args, **kwargs)
  File "/usr/share/vdsm/storage/spm.py", line 640, in copyImage
    volType, volFormat, preallocate, postZero, force)
  File "/usr/share/vdsm/storage/image.py", line 754, in copy
 raise se.CopyImageError(str(e))
CopyImageError: low level Image copy failed: ('General Storage Exception: ("rc: 1, err: [\'qemu-img: error while reading\']",)',)
Comment 4 Dor Laor 2011-06-23 07:59:37 UTC 
Can you please specify the exact qemu-img command?
Comment 7 Kevin Wolf 2011-07-26 08:18:40 UTC 
Is the destination LV created large enough to hold the complete image plus qcow2 metadata?

Can you run qemu-img under strace to see which operation failed, and with which error code?
Comment 8 Dor Laor 2011-09-04 10:46:22 UTC 
closed for missing info