On Wed, Dec 6, 2017 at 11:42 PM, Nir Soffer <nsoffer@redhat.com> wrote:

BTW: I notice that the disk seems preallocated even if original qcow2 is thin... is this expected?
This obviously also impacts the time to upload (20Gb virtual disk with actual 1.2Gb occupied needs the time equivalent for full 20Gb...)

We upload exactly the file you provided, there is no way we can upload 20G from 1.2G file :-)

But the upload process at a medium rate of 40-50MB/s has last about 9 minutes that confirms the 20Gb size

The disk at source has been created as virtio type and format qcow2 from virt-manager and then only installed a CentOS 7.2 OS with infrastructure server configuration.

Apart from qemu-img also ls:

# ls -lhs c7lab1.qcow2

1.3G -rw------- 1 root root 21G Dec 6 23:05 c7lab1.qcow2

On target after upload:

[root@ovirt01 251063f6-5570-4bdc-b28f-21e82aa5e185]# ls -lhs 77aacfb3-9e67-4ad2-96f6-242b5ba4d9e0

21G -rw-rw----. 1 vdsm kvm 21G Dec 6 23:44 77aacfb3-9e67-4ad2-96f6-242b5ba4d9e0

[root@ovirt01 251063f6-5570-4bdc-b28f-21e82aa5e185]#

But maybe we created the file in the wrong format?

Can you share vdsm logs from the spm, showing how the disk was created?

First message at beginning of upload:

2017-12-06 23:09:50,183+0100 INFO (jsonrpc/4) [vdsm.api] START createVolume(sdUUID=u'572eabe7-15d0-42c2-8fa9-0bd773e22e2e', spUUID=u'00000001-0001-0001-0001-000000000343', imgUUID=u'251063f6-5570-4bdc-b28f-21e82aa5e185', size=u'22548578304', volFormat=4, preallocate=2, diskType=2, volUUID=u'77aacfb3-9e67-4ad2-96f6-242b5ba4d9e0', desc=u'{"DiskAlias":"c7lab1","DiskDescription":""}', srcImgUUID=u'00000000-0000-0000-0000-000000000000', srcVolUUID=u'00000000-0000-0000-0000-000000000000', initialSize=None) from=192.168.1.212,56846, flow_id=18c6bd3b-76ab-45f9-b8c7-09c727f44c91, task_id=e7cc67e6-4b61-4bb3-81b1-6bc687ea5ee9 (api:46)

Last message that corresponds to completion of upload:

2017-12-06 23:21:03,914+0100 INFO (jsonrpc/4) [storage.VolumeManifest] 572eabe7-15d0-42c2-8fa9-0bd773e22e2e/251063f6-5570-4bdc-b28f-21e82aa5e185/77aacfb3-9e67-4ad2-96f6-242b5ba4d9e0 info is {'status': 'OK', 'domain': '572eabe7-15d0-42c2-8fa9-0bd773e22e2e', 'voltype': 'LEAF', 'description': '{"DiskAlias":"c7lab1","DiskDescription":""}', 'parent': '00000000-0000-0000-0000-000000000000', 'format': 'COW', 'generation': 0, 'image': '251063f6-5570-4bdc-b28f-21e82aa5e185', 'ctime': '1512598190', 'disktype': '2', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '21496266752', 'children': [], 'pool': '', 'capacity': '22548578304', 'uuid': u'77aacfb3-9e67-4ad2-96f6-242b5ba4d9e0', 'truesize': '21496602624', 'type': 'SPARSE', 'lease': {'owners': [], 'version': None}} (volume:272)

2017-12-06 23:21:03,915+0100 INFO (jsonrpc/4) [vdsm.api] FINISH getVolumeInfo return={'info': {'status': 'OK', 'domain': '572eabe7-15d0-42c2-8fa9-0bd773e22e2e', 'voltype': 'LEAF', 'description': '{"DiskAlias":"c7lab1","DiskDescription":""}', 'parent': '00000000-0000-0000-0000-000000000000', 'format': 'COW', 'generation': 0, 'image': '251063f6-5570-4bdc-b28f-21e82aa5e185', 'ctime': '1512598190', 'disktype': '2', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '21496266752', 'children': [], 'pool': '', 'capacity': '22548578304', 'uuid': u'77aacfb3-9e67-4ad2-96f6-242b5ba4d9e0', 'truesize': '21496602624', 'type': 'SPARSE', 'lease': {'owners': [], 'version': None}}} from=192.168.1.212,56840, flow_id=18c6bd3b-76ab-45f9-b8c7-09c727f44c91, task_id=6b268651-4a7f-4366-9d01-829deaa16bfd (api:52)

Full vdsm.log.gz in between here:

https://drive.google.com/file/d/1IZIKDXyNN3bc6035C5Rc5WiI_UZ_g0ZV/view?usp=sharing

NFS version?

The mount done from the host is this:

[root@ovirt01 /] # mount | grep NFS_DOMAIN

ovirt01:/NFS_DOMAIN on /rhev/data-center/mnt/ovirt01:_NFS__DOMAIN type nfs (rw,relatime,vers=3,rsize=1048576,wsize=1048576,namlen=255,soft,nosharecache,proto=tcp,timeo=600,retrans=6,sec=sys,mountaddr=192.168.1.211,mountvers=3,mountport=20048,mountproto=udp,local_lock=none,addr=192.168.1.211)

This is a test system so that I only have one host and the NFS mount is done over an XFS local filesystem exported by itself, but I think this should not be relevant for this particular test...

Another note: it seems that in events there is no message related to image upload completion. I only see:

Dec 6, 2017 11:09:51 PM Add-Disk operation of 'c7lab1' was initiated by the system.

Dec 6, 2017 11:09:49 PM Image Upload with disk c7lab1 was initiated by admin@internal-authz.

and no message around 23:21 when the upload completes.

Thanks,

Gianluca