Bug 1411479 - Clone vm from template may fail on block domain because of the initial volume size is too big
Summary: Clone vm from template may fail on block domain because of the initial volume...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: ovirt-engine
Classification: oVirt
Component: BLL.Storage
Version: 4.1.0
Hardware: Unspecified
OS: Unspecified
unspecified
urgent
Target Milestone: ovirt-4.1.0-beta
: 4.1.0.2
Assignee: Liron Aravot
QA Contact: Avihai
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-01-09 20:04 UTC by Israel Pinto
Modified: 2017-02-01 14:46 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-02-01 14:46:57 UTC
oVirt Team: Storage
rule-engine: ovirt-4.1+
rule-engine: blocker+
rule-engine: planning_ack+
tnisan: devel_ack+
ratamir: testing_ack+


Attachments (Terms of Use)
engine.log (10.06 MB, text/plain)
2017-01-09 20:04 UTC, Israel Pinto
no flags Details
vdsm.log (698.59 KB, application/zip)
2017-01-09 20:06 UTC, Israel Pinto
no flags Details
art_test_log (1.70 MB, application/zip)
2017-01-09 20:08 UTC, Israel Pinto
no flags Details


Links
System ID Private Priority Status Summary Last Updated
oVirt gerrit 69980 0 'None' MERGED core: volume initialSize calc when using collapse=true 2020-05-20 07:34:49 UTC
oVirt gerrit 70021 0 'None' MERGED core: StorageDomainValidator - getTotalSizeForClonedDisk non static 2020-05-20 07:34:49 UTC
oVirt gerrit 70022 0 'None' MERGED core: volume initialSize calc when using collapse=true 2020-05-20 07:34:49 UTC

Description Israel Pinto 2017-01-09 20:04:13 UTC
Created attachment 1238875 [details]
engine.log

Description of problem:
Clone VM from template failed.



Version-Release number of selected component (if applicable):
Engine: ovirt-engine-4.1.0-0.4.master.20170104181027.gitab0e3f4.el7.centos.noarch
Host:
OS Version:RHEL - 7.3 - 7.el7
Kernel Version:3.10.0 - 514.2.2.el7.x86_64
KVM Version:2.6.0 - 28.el7_3.2
LIBVIRT Version:libvirt-2.0.0-10.el7_3.2
VDSM Version: vdsm-4.19.1-18.git79e5ea5.el7.centos.x86_64
qemu-img-rhev: qemu-img-rhev-2.6.0-28.el7_3.2.x86_64
sanlock: sanlock-3.4.0-1.el7.x86_64
glusterfs: glusterfs-3.8.5-1.el7.x86_64
vdsm-cli: vdsm-cli-4.19.1-18.git79e5ea5.el7.centos.noarch

Additional info:
art log:
2017-01-05 23:27:32,604 - MainThread - art.logging - INFO - SETUP <TestCaseFunction 'test_clone_vm_template_case'>

REST request:
 
2017-01-05 23:28:33,334 - MainThread - vms - DEBUG - CREATE request content is --  url:https://jenkins-vm-13.qa.lab.tlv.redhat.com/ovirt-engine/api/vms;clone=true body:<vm>
    <name>tested_vm_clone_vm</name>
    <cluster href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a" id="bd5c13da-0d4c-49d7-9a11-ca82e0456f6a">
        <actions>
            <link href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a/resetemulatedmachine" rel="resetemulatedmachine"/>
        </actions>
        <name>golden_env_mixed_1</name>
        <description></description>
        <link href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a/affinitygroups" rel="affinitygroups"/>
        <link href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a/cpuprofiles" rel="cpuprofiles"/>
        <link href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a/permissions" rel="permissions"/>
        <link href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a/networkfilters" rel="networkfilters"/>
        <link href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a/networks" rel="networks"/>
        <link href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a/glustervolumes" rel="glustervolumes"/>
        <link href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a/glusterhooks" rel="glusterhooks"/>
        <ballooning_enabled>false</ballooning_enabled>
        <cpu>
            <architecture>x86_64</architecture>
            <type>Intel Conroe Family</type>
        </cpu>
        <custom_scheduling_policy_properties>
            <property>
                <name>HighUtilization</name>
                <value>80</value>
            </property>
            <property>
                <name>CpuOverCommitDurationMinutes</name>
                <value>2</value>
            </property>
        </custom_scheduling_policy_properties>
        <error_handling>
            <on_error>migrate</on_error>
        </error_handling>
        <fencing_policy>
            <enabled>true</enabled>
            <skip_if_connectivity_broken>
                <enabled>false</enabled>
                <threshold>50</threshold>
            </skip_if_connectivity_broken>
            <skip_if_gluster_bricks_up>false</skip_if_gluster_bricks_up>
            <skip_if_gluster_quorum_not_met>false</skip_if_gluster_quorum_not_met>
            <skip_if_sd_active>
                <enabled>false</enabled>
            </skip_if_sd_active>
        </fencing_policy>
        <gluster_service>false</gluster_service>
        <ha_reservation>false</ha_reservation>
        <ksm>
            <enabled>false</enabled>
            <merge_across_nodes>true</merge_across_nodes>
        </ksm>
        <maintenance_reason_required>false</maintenance_reason_required>
        <memory_policy>
            <over_commit>
                <percent>200</percent>
            </over_commit>
            <transparent_hugepages>
                <enabled>true</enabled>
            </transparent_hugepages>
        </memory_policy>
        <migration>
            <auto_converge>inherit</auto_converge>
            <bandwidth>
                <assignment_method>auto</assignment_method>
            </bandwidth>
            <compressed>inherit</compressed>
        </migration>
        <optional_reason>false</optional_reason>
        <required_rng_sources>
            <required_rng_source>urandom</required_rng_source>
        </required_rng_sources>
        <switch_type>legacy</switch_type>
        <threads_as_cores>false</threads_as_cores>
        <trusted_service>false</trusted_service>
        <tunnel_migration>false</tunnel_migration>
        <version>
            <major>4</major>
            <minor>1</minor>
        </version>
        <virt_service>true</virt_service>
        <data_center href="/ovirt-engine/api/datacenters/ce35d08f-9ca7-4bfb-8788-a5db39bfb041" id="ce35d08f-9ca7-4bfb-8788-a5db39bfb041"/>
        <mac_pool href="/ovirt-engine/api/macpools/586e003a-03e9-00b8-0339-000000000244" id="586e003a-03e9-00b8-0339-000000000244"/>
        <scheduling_policy href="/ovirt-engine/api/schedulingpolicies/b4ed2332-a7ac-4d5f-9596-99a439cb2812" id="b4ed2332-a7ac-4d5f-9596-99a439cb2812"/>
    </cluster>
    <disk_attachments>
        <disk_attachment>
            <bootable>true</bootable>
            <interface>virtio</interface>
            <disk id="c57181d6-b3e2-4053-9de1-5d3be9ce8869">
                <storage_domains>
                    <storage_domain href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec" id="094a33f4-a9ff-46b9-a247-75cfae9b91ec">
                        <actions>
                            <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/isattached" rel="isattached"/>
                            <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/updateovfstore" rel="updateovfstore"/>
                            <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/reduceluns" rel="reduceluns"/>
                            <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/refreshluns" rel="refreshluns"/>
                        </actions>
                        <name>fcp_0</name>
                        <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/diskprofiles" rel="diskprofiles"/>
                        <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/disks" rel="disks"/>
                        <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/storageconnections" rel="storageconnections"/>
                        <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/permissions" rel="permissions"/>
                        <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/templates" rel="templates"/>
                        <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/vms" rel="vms"/>
                        <link href="/ovirt-engine/api/storagedomains/094a33f4-a9ff-46b9-a247-75cfae9b91ec/disksnapshots" rel="disksnapshots"/>
                        <available>90194313216</available>
                        <committed>30064771072</committed>
                        <critical_space_action_blocker>5</critical_space_action_blocker>
                        <discard_after_delete>false</discard_after_delete>
                        <external_status>ok</external_status>
                        <master>true</master>
                        <storage>
                            <type>fcp</type>
                            <volume_group id="2QfhAs-Ay1D-io5a-moeT-u9cm-nko5-NAaflP">
                                <logical_units>
                                    <logical_unit id="3600a09803830347a625d467a79745665">
                                        <discard_max_size>0</discard_max_size>
                                        <discard_zeroes_data>false</discard_zeroes_data>
                                        <lun_mapping>4</lun_mapping>
                                        <paths>0</paths>
                                        <product_id>LUN C-Mode</product_id>
                                        <serial>SNETAPP_LUN_C-Mode_804zb_FzytVe</serial>
                                        <size>107374182400</size>
                                        <storage_domain_id>094a33f4-a9ff-46b9-a247-75cfae9b91ec</storage_domain_id>
                                        <vendor_id>NETAPP</vendor_id>
                                        <volume_group_id>2QfhAs-Ay1D-io5a-moeT-u9cm-nko5-NAaflP</volume_group_id>
                                    </logical_unit>
                                </logical_units>
                            </volume_group>
                        </storage>
                        <storage_format>v4</storage_format>
                        <supports_discard>false</supports_discard>
                        <supports_discard_zeroes_data>false</supports_discard_zeroes_data>
                        <type>data</type>
                        <used>16106127360</used>
                        <warning_low_space_indicator>10</warning_low_space_indicator>
                        <wipe_after_delete>false</wipe_after_delete>
                        <data_centers>
                            <data_center id="ce35d08f-9ca7-4bfb-8788-a5db39bfb041"/>
                        </data_centers>
                    </storage_domain>
                </storage_domains>
            </disk>
        </disk_attachment>
    </disk_attachments>
    <template href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451" id="8fd71887-c1bf-4358-9372-00c1b6a80451">
        <actions>
            <link href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451/seal" rel="seal"/>
            <link href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451/export" rel="export"/>
        </actions>
        <name>virt_base_template</name>
        <link href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451/permissions" rel="permissions"/>
        <link href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451/tags" rel="tags"/>
        <link href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451/diskattachments" rel="diskattachments"/>
        <link href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451/graphicsconsoles" rel="graphicsconsoles"/>
        <link href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451/cdroms" rel="cdroms"/>
        <link href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451/nics" rel="nics"/>
        <link href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451/watchdogs" rel="watchdogs"/>
        <bios>
            <boot_menu>
                <enabled>false</enabled>
            </boot_menu>
        </bios>
        <cpu>
            <architecture>x86_64</architecture>
            <topology>
                <cores>1</cores>
                <sockets>1</sockets>
                <threads>1</threads>
            </topology>
        </cpu>
        <cpu_shares>0</cpu_shares>
        <creation_time>2017-01-05T23:27:45.791000+02:00</creation_time>
        <delete_protected>false</delete_protected>
        <display>
            <allow_override>false</allow_override>
            <copy_paste_enabled>true</copy_paste_enabled>
            <disconnect_action>LOCK_SCREEN</disconnect_action>
            <file_transfer_enabled>true</file_transfer_enabled>
            <monitors>1</monitors>
            <single_qxl_pci>false</single_qxl_pci>
            <smartcard_enabled>false</smartcard_enabled>
            <type>spice</type>
        </display>
        <high_availability>
            <enabled>false</enabled>
            <priority>0</priority>
        </high_availability>
        <io>
            <threads>0</threads>
        </io>
        <large_icon href="/ovirt-engine/api/icons/ac3c2f0e-c463-46b1-bd98-3446d2b692f1" id="ac3c2f0e-c463-46b1-bd98-3446d2b692f1"/>
        <memory>1073741824</memory>
        <memory_policy>
            <guaranteed>1073741824</guaranteed>
            <max>4294967296</max>
        </memory_policy>
        <migration>
            <auto_converge>inherit</auto_converge>
            <compressed>inherit</compressed>
        </migration>
        <migration_downtime>-1</migration_downtime>
        <origin>ovirt</origin>
        <os>
            <boot>
                <devices>
                    <device>hd</device>
                </devices>
            </boot>
            <type>rhel_6x64</type>
        </os>
        <small_icon href="/ovirt-engine/api/icons/2f57c59c-b823-4d84-96b4-b0fbb2679fa0" id="2f57c59c-b823-4d84-96b4-b0fbb2679fa0"/>
        <sso>
            <methods>
                <method id="guest_agent"/>
            </methods>
        </sso>
        <start_paused>false</start_paused>
        <stateless>false</stateless>
        <time_zone>
            <name>Etc/GMT</name>
        </time_zone>
        <type>desktop</type>
        <usb>
            <enabled>false</enabled>
        </usb>
        <cluster href="/ovirt-engine/api/clusters/bd5c13da-0d4c-49d7-9a11-ca82e0456f6a" id="bd5c13da-0d4c-49d7-9a11-ca82e0456f6a"/>
        <cpu_profile href="/ovirt-engine/api/cpuprofiles/9e124b0c-7fbf-4aa7-9fb0-76af15cb6ed6" id="9e124b0c-7fbf-4aa7-9fb0-76af15cb6ed6"/>
        <quota id="28860500-0a3a-4326-be19-ca6441e28425"/>
        <status>ok</status>
        <version>
            <version_name>base version</version_name>
            <version_number>1</version_number>
            <base_template href="/ovirt-engine/api/templates/8fd71887-c1bf-4358-9372-00c1b6a80451" id="8fd71887-c1bf-4358-9372-00c1b6a80451"/>
        </version>
    </template>
</vm>
 
engine log:
2017-01-05 23:28:32,473+02 INFO  [org.ovirt.engine.core.bll.AddVmFromTemplateCommand] (default task-16) [vms_create_24192412-ac61-4804] Lock Acquired to object 'EngineLock:{exclusiveLocks='[tested_vm_clone_vm=<VM_NAME, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='[8fd71887-c1bf-4358-9372-00c1b6a80451=<TEMPLATE, ACTION_TYPE_FAILED_TEMPLATE_IS_USED_FOR_CREATE_VM$VmName tested_vm_clone_vm>, c57181d6-b3e2-4053-9de1-5d3be9ce8869=<DISK, ACTION_TYPE_FAILED_DISK_IS_USED_FOR_CREATE_VM$VmName tested_vm_clone_vm>]'}'
2017-01-05 23:28:32,563+02 INFO  [org.ovirt.engine.core.bll.AddVmFromTemplateCommand] (default task-16) [vms_create_24192412-ac61-4804] Running command: AddVmFromTemplateCommand internal: false. Entities affected :  ID: bd5c13da-0d4c-49d7-9a11-ca82e0456f6a Type: ClusterAction group CREATE_VM with role type USER,  ID: 8fd71887-c1bf-4358-9372-00c1b6a80451 Type: VmTemplateAction group CREATE_VM with role type USER,  ID: 094a33f4-a9ff-46b9-a247-75cfae9b91ec Type: StorageAction group CREATE_DISK with role type USER
2017-01-05 23:28:32,622+02 INFO  [org.ovirt.engine.core.bll.AddRngDeviceCommand] (default task-16) [65223419] Running command: AddRngDeviceCommand internal: true. Entities affected :  ID: c18bc863-2d00-4ac3-889a-fce19f4c6e79 Type: VMAction group EDIT_VM_PROPERTIES with role type USER
2017-01-05 23:28:32,628+02 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (default task-16) [65223419] START, SetVmStatusVDSCommand( SetVmStatusVDSCommandParameters:{runAsync='true', vmId='c18bc863-2d00-4ac3-889a-fce19f4c6e79', status='ImageLocked', exitStatus='Normal'}), log id: 63150c4d
2017-01-05 23:28:32,632+02 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (default task-16) [65223419] FINISH, SetVmStatusVDSCommand, log id: 63150c4d
2017-01-05 23:28:32,664+02 INFO  [org.ovirt.engine.core.bll.CreateCloneOfTemplateCommand] (default task-16) [1dafb449] Running command: CreateCloneOfTemplateCommand internal: true. Entities affected :  ID: 094a33f4-a9ff-46b9-a247-75cfae9b91ec Type: Storage
2017-01-05 23:28:32,704+02 INFO  [org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupWithDataCommand] (default task-16) [70dd286] Running command: CopyImageGroupWithDataCommand internal: true.
2017-01-05 23:28:32,738+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (default task-16) [70dd286] START, GetVolumeInfoVDSCommand(HostName = host_mixed_2, GetVolumeInfoVDSCommandParameters:{runAsync='true', hostId='cce51c7e-9ca5-404a-bcc9-aa1a28efc423', storagePoolId='ce35d08f-9ca7-4bfb-8788-a5db39bfb041', storageDomainId='094a33f4-a9ff-46b9-a247-75cfae9b91ec', imageGroupId='c57181d6-b3e2-4053-9de1-5d3be9ce8869', imageId='92886377-d3e3-42bc-819b-86c76db3b1d4'}), log id: e09c556
2017-01-05 23:28:33,416+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (default task-16) [70dd286] FINISH, GetVolumeInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@40072cb3, log id: e09c556
2017-01-05 23:28:33,460+02 INFO  [org.ovirt.engine.core.bll.storage.disk.image.CreateVolumeContainerCommand] (default task-16) [2f7bba02] Running command: CreateVolumeContainerCommand internal: true.
2017-01-05 23:28:33,482+02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (default task-16) [2f7bba02] START, CreateSnapshotVDSCommand( CreateSnapshotVDSCommandParameters:{runAsync='true', storagePoolId='ce35d08f-9ca7-4bfb-8788-a5db39bfb041', ignoreFailoverLimit='false', storageDomainId='094a33f4-a9ff-46b9-a247-75cfae9b91ec', imageGroupId='d78ef841-e189-4f6b-b73d-46467c0cdaf6', imageSizeInBytes='1073741824', volumeFormat='COW', newImageId='a980aa98-b19c-41b6-9a59-1cdb6eb9a01a', newImageDescription='null', imageInitialSizeInBytes='1073741825', imageId='00000000-0000-0000-0000-000000000000', sourceImageGroupId='00000000-0000-0000-0000-000000000000'}), log id: 5c6e7d87
2017-01-05 23:28:33,483+02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (default task-16) [2f7bba02] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
2017-01-05 23:28:34,351+02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (default task-16) [2f7bba02] FINISH, CreateSnapshotVDSCommand, return: a980aa98-b19c-41b6-9a59-1cdb6eb9a01a, log id: 5c6e7d87
2017-01-05 23:28:34,357+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (default task-16) [2f7bba02] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'ba1addb1-c760-43e4-8737-4847aad6e3a9'
2017-01-05 23:28:34,357+02 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (default task-16) [2f7bba02] CommandMultiAsyncTasks::attachTask: Attaching task '4428b760-3a18-4757-8d30-3279437d4d9a' to command 'ba1addb1-c760-43e4-8737-4847aad6e3a9'.
2017-01-05 23:28:34,376+02 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-16) [2f7bba02] Adding task '4428b760-3a18-4757-8d30-3279437d4d9a' (Parent Command 'CreateVolumeContainer', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2017-01-05 23:28:34,386+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (default task-16) [2f7bba02] BaseAsyncTask::startPollingTask: Starting to poll task '4428b760-3a18-4757-8d30-3279437d4d9a'.
2017-01-05 23:28:34,536+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-16) [2f7bba02] Correlation ID: vms_create_24192412-ac61-4804, Job ID: 29d333b6-6945-4b71-a06d-0cf4d1e38e23, Call Stack: null, Custom Event ID: -1, Message: VM tested_vm_clone_vm creation was initiated by admin@internal-authz.
2017-01-05 23:28:35,359+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler1) [70dd286] Command 'CreateCloneOfTemplate' (id: 'e0bf579b-fc12-4e0d-806e-e099ba260e39') waiting on child command id: '1befb680-66f5-4fe3-99c3-1c288c22220b' type:'CopyImageGroupWithData' to complete
2017-01-05 23:28:35,378+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler1) [1dafb449] Command 'AddVmFromTemplate' (id: '07efe6e1-1b3a-443b-8209-b13bfddc4826') waiting on child command id: 'e0bf579b-fc12-4e0d-806e-e099ba260e39' type:'CreateCloneOfTemplate' to complete
2017-01-05 23:28:35,382+02 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler1) [2f7bba02] Command 'CopyImageGroupWithData' (id: '1befb680-66f5-4fe3-99c3-1c288c22220b') waiting on child command id: 'ba1addb1-c760-43e4-8737-4847aad6e3a9' type:'CreateVolumeContainer' to complete
2017-01-05 23:28:39,389+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler9) [70dd286] Command 'CreateCloneOfTemplate' (id: 'e0bf579b-fc12-4e0d-806e-e099ba260e39') waiting on child command id: '1befb680-66f5-4fe3-99c3-1c288c22220b' type:'CopyImageGroupWithData' to complete
2017-01-05 23:28:39,406+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler9) [1dafb449] Command 'AddVmFromTemplate' (id: '07efe6e1-1b3a-443b-8209-b13bfddc4826') waiting on child command id: 'e0bf579b-fc12-4e0d-806e-e099ba260e39' type:'CreateCloneOfTemplate' to complete
2017-01-05 23:28:39,410+02 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler9) [2f7bba02] Command 'CopyImageGroupWithData' (id: '1befb680-66f5-4fe3-99c3-1c288c22220b') waiting on child command id: 'ba1addb1-c760-43e4-8737-4847aad6e3a9' type:'CreateVolumeContainer' to complete
2017-01-05 23:28:41,952+02 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler8) [] Setting new tasks map. The map contains now 3 tasks
2017-01-05 23:28:42,250+02 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler2) [51f9fedc] Polling and updating Async Tasks: 3 tasks, 1 tasks to poll now
2017-01-05 23:28:43,258+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler2) [51f9fedc] Failed in 'HSMGetAllTasksStatusesVDS' method
2017-01-05 23:28:43,264+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler2) [51f9fedc] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM host_mixed_3 command failed: Error creating a new volume
2017-01-05 23:28:43,264+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler2) [51f9fedc] SPMAsyncTask::PollTask: Polling task '4428b760-3a18-4757-8d30-3279437d4d9a' (Parent Command 'CreateVolumeContainer', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'cleanSuccess'.
2017-01-05 23:28:43,279+02 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler2) [51f9fedc] BaseAsyncTask::logEndTaskFailure: Task '4428b760-3a18-4757-8d30-3279437d4d9a' (Parent Command 'CreateVolumeContainer', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Error creating a new volume, code = 205',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Error creating a new volume, code = 205'
2017-01-05 23:28:43,280+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler2) [51f9fedc] CommandAsyncTask::endActionIfNecessary: All tasks of command 'ba1addb1-c760-43e4-8737-4847aad6e3a9' has ended -> executing 'endAction'
2017-01-05 23:28:43,280+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler2) [51f9fedc] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: 'ba1addb1-c760-43e4-8737-4847aad6e3a9'): calling endAction '.
2017-01-05 23:28:43,281+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-31) [51f9fedc] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'CreateVolumeContainer',
2017-01-05 23:28:43,286+02 ERROR [org.ovirt.engine.core.bll.storage.disk.image.CreateVolumeContainerCommand] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.CreateVolumeContainerCommand' with failure.
2017-01-05 23:28:43,293+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'CreateVolumeContainer' completed, handling the result.
2017-01-05 23:28:43,293+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'CreateVolumeContainer' succeeded, clearing tasks.
2017-01-05 23:28:43,293+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '4428b760-3a18-4757-8d30-3279437d4d9a'
2017-01-05 23:28:43,294+02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId='ce35d08f-9ca7-4bfb-8788-a5db39bfb041', ignoreFailoverLimit='false', taskId='4428b760-3a18-4757-8d30-3279437d4d9a'}), log id: 206399ee
2017-01-05 23:28:45,524+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] START, HSMClearTaskVDSCommand(HostName = host_mixed_3, HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', hostId='a1a6c3c4-3c42-41dd-95f7-81b3e45aa342', taskId='4428b760-3a18-4757-8d30-3279437d4d9a'}), log id: 19b1486
2017-01-05 23:28:46,534+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] FINISH, HSMClearTaskVDSCommand, log id: 19b1486
2017-01-05 23:28:46,534+02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] FINISH, SPMClearTaskVDSCommand, log id: 206399ee
2017-01-05 23:28:46,538+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] BaseAsyncTask::removeTaskFromDB: Removed task '4428b760-3a18-4757-8d30-3279437d4d9a' from DataBase
2017-01-05 23:28:46,538+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-31) [2f7bba02] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'ba1addb1-c760-43e4-8737-4847aad6e3a9'
2017-01-05 23:28:47,420+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler1) [70dd286] Command 'CreateCloneOfTemplate' (id: 'e0bf579b-fc12-4e0d-806e-e099ba260e39') waiting on child command id: '1befb680-66f5-4fe3-99c3-1c288c22220b' type:'CopyImageGroupWithData' to complete
2017-01-05 23:28:47,435+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler1) [1dafb449] Command 'AddVmFromTemplate' (id: '07efe6e1-1b3a-443b-8209-b13bfddc4826') waiting on child command id: 'e0bf579b-fc12-4e0d-806e-e099ba260e39' type:'CreateCloneOfTemplate' to complete
2017-01-05 23:28:47,439+02 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler1) [2f7bba02] Command 'CopyImageGroupWithData' id: '1befb680-66f5-4fe3-99c3-1c288c22220b' child commands '[ba1addb1-c760-43e4-8737-4847aad6e3a9]' executions were completed, status 'FAILED'
2017-01-05 23:28:48,450+02 ERROR [org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupWithDataCommand] (DefaultQuartzScheduler2) [2f7bba02] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupWithDataCommand' with failure.
2017-01-05 23:28:49,487+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler1) [70dd286] Command 'CreateCloneOfTemplate' id: 'e0bf579b-fc12-4e0d-806e-e099ba260e39' child commands '[1befb680-66f5-4fe3-99c3-1c288c22220b]' executions were completed, status 'FAILED'
2017-01-05 23:28:49,487+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler1) [70dd286] Command 'CreateCloneOfTemplate' id: 'e0bf579b-fc12-4e0d-806e-e099ba260e39' Updating status to 'FAILED', The command end method logic will be executed by one of its parent commands.
2017-01-05 23:28:50,518+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler4) [1dafb449] Command 'AddVmFromTemplate' id: '07efe6e1-1b3a-443b-8209-b13bfddc4826' child commands '[e0bf579b-fc12-4e0d-806e-e099ba260e39]' executions were completed, status 'FAILED'
2017-01-05 23:28:51,542+02 ERROR [org.ovirt.engine.core.bll.AddVmFromTemplateCommand] (DefaultQuartzScheduler1) [1dafb449] Ending command 'org.ovirt.engine.core.bll.AddVmFromTemplateCommand' with failure.
2017-01-05 23:28:51,549+02 ERROR [org.ovirt.engine.core.bll.CreateCloneOfTemplateCommand] (DefaultQuartzScheduler1) [70dd286] Ending command 'org.ovirt.engine.core.bll.CreateCloneOfTemplateCommand' with failure.
2017-01-05 23:28:51,628+02 INFO  [org.ovirt.engine.core.bll.AddVmFromTemplateCommand] (DefaultQuartzScheduler1) [] Lock freed to object 'EngineLock:{exclusiveLocks='[tested_vm_clone_vm=<VM_NAME, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='[8fd71887-c1bf-4358-9372-00c1b6a80451=<TEMPLATE, ACTION_TYPE_FAILED_TEMPLATE_IS_USED_FOR_CREATE_VM$VmName tested_vm_clone_vm>, c57181d6-b3e2-4053-9de1-5d3be9ce8869=<DISK, ACTION_TYPE_FAILED_DISK_IS_USED_FOR_CREATE_VM$VmName tested_vm_clone_vm>]'}'
2017-01-05 23:28:51,637+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler1) [] Correlation ID: vms_create_24192412-ac61-4804, Job ID: 29d333b6-6945-4b71-a06d-0cf4d1e38e23, Call Stack: null, Custom Event ID: -1, Message: Failed to complete VM tested_vm_clone_vm creation.
2017-01-05 23:28:56,147+02 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (default task-16) [vms_delete_59a9fcd7-b3fe-47b2] Lock Acquired to object 'EngineLock:{exclusiveLocks='[ae7533c8-cdb4-499a-8ba0-10bd314894fd=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2017-01-05 23:28:56,190+02 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (default task-16) [vms_delete_59a9fcd7-b3fe-47b2] Running command: RemoveVmCommand internal: false. Entities affected :  ID: ae7533c8-cdb4-499a-8ba0-10bd314894fd Type: VMAction group DELETE_VM with role type USER
2017-01-05 23:28:56,192+02 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (default task-16) [vms_delete_59a9fcd7-b3fe-47b2] START, SetVmStatusVDSCommand( SetVmStatusVDSCommandParameters:{runAsync='true', vmId='ae7533c8-cdb4-499a-8ba0-10bd314894fd', status='ImageLocked', exitStatus='Normal'}), log id: 1b7ee8dd
2017-01-05 23:28:56,195+02 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (default task-16) [vms_delete_59a9fcd7-b3fe-47b2] FINISH, SetVmStatusVDSCommand, log id: 1b7ee8dd
2017-01-05 23:28:56,196+02 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (default task-16) [vms_delete_59a9fcd7-b3fe-47b2] Lock freed to object 'EngineLock:{exclusiveLocks='[ae7533c8-cdb4-499a-8ba0-10bd314894fd=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2017-01-05 23:28:56,217+02 INFO  [org.ovirt.engine.core.bll.storage.disk.image.RemoveAllVmImagesCommand] (default task-16) [65e6902] Running command: RemoveAllVmImagesCommand internal: true. Entities affected :  ID: ae7533c8-cdb4-499a-8ba0-10bd314894fd Type: VM
2017-01-05 23:28:56,222+02 INFO  [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (default task-16) [589fa86] Running command: RemoveImageCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
2017-01-05 23:28:56,271+02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (default task-16) [589fa86] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{runAsync='true', storagePoolId='ce35d08f-9ca7-4bfb-8788-a5db39bfb041', ignoreFailoverLimit='false', storageDomainId='094a33f4-a9ff-46b9-a247-75cfae9b91ec', imageGroupId='4f4cd990-e792-4102-b9a9-2236ede15ee7', postZeros='false', discard='false', forceDelete='false'}), log id: 7e2a04d9

vdsm log:
2017-01-05 23:28:34,603 INFO  (tasks/9) [storage.Volume] Creating volume a980aa98-b19c-41b6-9a59-1cdb6eb9a01a (volume:1023)
2017-01-05 23:28:34,628 ERROR (tasks/9) [storage.Volume] The volume size 2097152 is smaller than the requested initial size 2097153 (blockVolume:344)
2017-01-05 23:28:34,628 ERROR (tasks/9) [storage.Volume] Failed to create volume /rhev/data-center/ce35d08f-9ca7-4bfb-8788-a5db39bfb041/094a33f4-a9ff-46b9-a247-75cfae9b91ec/images/d78ef841-e189-4f6b-b73d-46467c0cdaf6/a980aa98-b19c-41b6-9a59-1cdb6eb9a01a: Invalid parameter: 'initial size=2097153' (volume:1047)
2017-01-05 23:28:34,629 ERROR (tasks/9) [storage.Volume] Unexpected error (volume:1087)
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/volume.py", line 1044, in create
    initialSize=initialSize)
  File "/usr/share/vdsm/storage/blockVolume.py", line 461, in _create
    size, initialSize)
  File "/usr/share/vdsm/storage/blockVolume.py", line 503, in calculate_volume_alloc_size
    preallocate, capacity, initial_size)
  File "/usr/share/vdsm/storage/blockVolume.py", line 346, in calculate_volume_alloc_size
    initial_size)
InvalidParameterException: Invalid parameter: 'initial size=2097153'
2017-01-05 23:28:34,630 ERROR (tasks/9) [storage.TaskManager.Task] (Task='4428b760-3a18-4757-8d30-3279437d4d9a') Unexpected error (task:870)
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 877, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/storage/task.py", line 333, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/securable.py", line 79, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/share/vdsm/storage/sp.py", line 1921, in createVolume
    initialSize=initialSize)
  File "/usr/share/vdsm/storage/sd.py", line 762, in createVolume
    initialSize=initialSize)
  File "/usr/share/vdsm/storage/volume.py", line 1089, in create
    (volUUID, e))
VolumeCreationError: Error creating a new volume: ("Volume creation a980aa98-b19c-41b6-9a59-1cdb6eb9a01a failed: Invalid parameter: 'initial size=2097153'",)
2017-01-05 23:28:34,670 INFO  (tasks/9) [storage.Volume] startCreateVolumeRollback: sdUUID=094a33f4-a9ff-46b9-a247-75cfae9b91ec imgUUID=d78ef841-e189-4f6b-b73d-46467c0cdaf6 volUUID=a980aa98-b19c-41b6-9a59-1cdb6eb9a01a  (volume:933)
2017-01-05 23:28:34,670 INFO  (tasks/9) [storage.Image] createImageRollback: imageDir=/rhev/data-center/ce35d08f-9ca7-4bfb-8788-a5db39bfb041/094a33f4-a9ff-46b9-a247-75cfae9b91ec/images/d78ef841-e189-4f6b-b73d-46467c0cdaf6 (image:119)

Comment 1 Israel Pinto 2017-01-09 20:06:26 UTC
Created attachment 1238876 [details]
vdsm.log

Comment 2 Israel Pinto 2017-01-09 20:08:25 UTC
Created attachment 1238877 [details]
art_test_log

Comment 3 Raz Tamir 2017-01-11 16:57:40 UTC
Liron,
What exactly the problem here?
Cloning vm from template is working fine for me ovirt-engine-4.1.0-0.4.master.20170111000229.git9ce0636.el7.centos.noarch

Comment 4 Liron Aravot 2017-01-11 17:04:22 UTC
Steps to reproduce:
Have a 4.1 DC - 
1. Create a new VM
2. Create a 1GB Sparse disk on a block domain
3. Attach the disk to the vm
4. Create template from the VM
5. Add a VM based on the template with the following chosen in the add dialog:
*"Server" VM
* Resource allocation - choose block domain as the target for the template disk, COW format.

Comment 5 Liron Aravot 2017-01-11 17:12:48 UTC
(In reply to Raz Tamir from comment #3)
> Liron,
> What exactly the problem here?
> Cloning vm from template is working fine for me
> ovirt-engine-4.1.0-0.4.master.20170111000229.git9ce0636.el7.centos.noarch

Raz, the failure is on a specific scenario - I've added steps to reproduce.

Thanks,
Liron

Comment 6 Raz Tamir 2017-01-11 17:50:14 UTC
Thanks Liron

Comment 7 Avihai 2017-01-22 14:05:09 UTC
verified.

Engine :
ovirt-engine-4.1.0.1-0.4.master.20170118134729.gitf34da1f.el7.centos.noarch

vdsm:
4.19.2-1


Note You need to log in before you can comment on or make changes to this bug.