Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1720597

Summary: [REST-API] Start VM with cloud init enabled fails with java.lang.RuntimeException: Failed to build cloud-init data: (Failed with error ENGINE and code 5001)
Product: [oVirt] ovirt-engine Reporter: Avihai <aefrat>
Component: BLL.VirtAssignee: Tomasz Barański <tbaransk>
Status: CLOSED DUPLICATE QA Contact: meital avital <mavital>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 4.3.4.3CC: bugs, rbarry
Target Milestone: ---Keywords: Automation, Regression
Target Release: ---Flags: pm-rhel: ovirt-4.4+
pm-rhel: blocker?
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-06-17 09:23:14 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Virt RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
engine and vdsm logs none

Description Avihai 2019-06-14 10:23:03 UTC 
Created attachment 1580641 [details]
engine and vdsm logs

Description of problem:
Via REST (see request below) Start VM with cloud init enabled fails with  java.lang.RuntimeException: Failed to build cloud-init data: (Failed with error ENGINE and code 5001)

The exact same request was used in the same setup and worked in 4.2 and 4.3.3.

REST request:

Method: 
POST

URL:
https://storage-ge-08.scl.lab.tlv.redhat.com/ovirt-engine/api/vms/c23c3411-d3db-47e5-b7c2-439b1a95fead/start

Body:
<action>
    <async>false</async>
    <grace_period>
        <expiry>10</expiry>
    </grace_period>
    <use_cloud_init>true</use_cloud_init>
    <use_sysprep>false</use_sysprep>
    <vm>
        <os/>
    </vm>
</action>


Response:
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<action>
    <async>false</async>
    <fault>
        <detail>[]</detail>
        <reason>Operation Failed</reason>
    </fault>
    <grace_period>
        <expiry>10</expiry>
    </grace_period>
    <status>failed</status>
    <use_cloud_init>true</use_cloud_init>
    <use_sysprep>false</use_sysprep>
    <vm>
        <os/>
    </vm>
</action>

Engine Error:
2019-06-14 13:03:44,393+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] Failed in 'CreateBrokerVDS' method, for vds: 'host_mixed_2'; host: 'storage-ge8-vdsm2.scl.lab.tlv.redhat.com': Failed to build cloud-init data:
2019-06-14 13:03:44,393+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] Command 'CreateBrokerVDSCommand(HostName = host_mixed_2, CreateVDSCommandParameters:{hostId='acd46080-fc70-45fd-bd23-823759748309', vmId='c23c3411-d3db-47e5-b7c2-439b1a95fead', vm='VM [vm_TestCase26087_1412232502]'})' execution failed: Failed to build cloud-init data:
2019-06-14 13:03:44,393+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] FINISH, CreateBrokerVDSCommand, return: , log id: 53e7ea60
2019-06-14 13:03:44,393+03 ERROR [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] Failed to create VM: java.lang.RuntimeException: Failed to build cloud-init data:
	at org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand.getPayload(CreateBrokerVDSCommand.java:177) [vdsbroker.jar:]
	at org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand.generateDomainXml(CreateBrokerVDSCommand.java:90) [vdsbroker.jar:]
	at org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand.createInfo(CreateBrokerVDSCommand.java:52) [vdsbroker.jar:]
.............................................................................
.............................................................................
.............................................................................

Caused by: java.lang.NullPointerException
	at org.ovirt.engine.core.vdsbroker.builder.vminfo.VmInfoBuildUtils.buildPayload(VmInfoBuildUtils.java:1425) [vdsbroker.jar:]
	at org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand.getPayload(CreateBrokerVDSCommand.java:175) [vdsbroker.jar:]
	... 270 more

2019-06-14 13:03:45,008+03 ERROR [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] Command 'CreateVDSCommand( CreateVDSCommandParameters:{hostId='67ef8604-72d3-4633-a49b-1856ff385b7b', vmId='c23c3411-d3db-47e5-b7c2-439b1a95fead', vm='VM [vm_TestCase26087_1412232502]'})' execution failed: java.lang.RuntimeException: Failed to build cloud-init data:
2019-06-14 13:03:45,008+03 INFO  [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] FINISH, CreateVDSCommand, return: Down, log id: 3516d91d
2019-06-14 13:03:45,009+03 WARN  [org.ovirt.engine.core.bll.RunVmCommand] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] Failed to run VM 'vm_TestCase26087_1412232502': EngineException: java.lang.RuntimeException: java.lang.RuntimeException: Failed to build cloud-init data: (Failed with error ENGINE and code 5001)
2019-06-14 13:03:45,009+03 INFO  [org.ovirt.engine.core.bll.RunVmOnceCommand] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] Lock freed to object 'EngineLock:{exclusiveLocks='[c23c3411-d3db-47e5-b7c2-439b1a95fead=VM]', sharedLocks=''}'
2019-06-14 13:03:45,009+03 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] Trying to rerun VM 'vm_TestCase26087_1412232502'
2019-06-14 13:03:45,025+03 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] EVENT_ID: USER_INITIATED_RUN_VM_FAILED(151), Failed to run VM vm_TestCase26087_1412232502 on Host host_mixed_3.
2019-06-14 13:03:45,031+03 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-7) [ffb27202-ab57-4a98-9123-9566e608ddee] EVENT_ID: USER_FAILED_RUN_VM(54), Failed to run VM vm_TestCase26087_1412232502  (User: admin@internal-authz).
2019-06-14 13:03:45,041+03 INFO  [org.ovirt.engine.core.bll.ProcessDownVmCommand] (EE-ManagedThreadFactory-engine-Thread-103211) [1a665e83] Running command: ProcessDownVmCommand internal: true.
2019-06-14 13:03:45,063+03 ERROR [org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default task-7) [] Operation Failed: []
2019-06-14 13:03:45,070+03 INFO  [org.ovirt.engine.core.bll.aaa.LogoutSessionCommand] (default task-7) [788b4c54] Running command: LogoutSessionCommand internal: false.
2019-06-14 13:03:45,078+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-7) [788b4c54] EVENT_ID: USER_VDC_LOGOUT(31), User admin@internal-authz connected from '10.35.206.21' using session '7lZLe5+l7r7cZtB7gUqSNWgGTfWcXXp4QfrBXnTP/W7PZwpz5Z2nOMUBGx3ylyYQ7M1SHRyRJ0T8+7r4pMsOFg==' logged out.



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


How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:
Comment 1 Avihai 2019-06-14 10:29:35 UTC 
Version-Release number of selected component (if applicable):
4.3.4.3-0.1.el7
vdsm-4.30.17-1.el7ev.x86_64
libvirt-4.5.0-10.el7_6.10.x86_64
qemu-img-rhev-2.12.0-31.el7.x86_64
qemu-guest-agent-2.12.0-2.el7.x86_64

How reproducible:
100%

Steps to Reproduce:
1. Create VM from a template(with OS)
2. Try to start VM with cloud-init enabled with the flowing REST request:

Method: 
POST

URL:
https://storage-ge-08.scl.lab.tlv.redhat.com/ovirt-engine/api/vms/c23c3411-d3db-47e5-b7c2-439b1a95fead/start

Body:
<action>
    <async>false</async>
    <grace_period>
        <expiry>10</expiry>
    </grace_period>
    <use_cloud_init>true</use_cloud_init>
    <use_sysprep>false</use_sysprep>
    <vm>
        <os/>
    </vm>
</action>



Actual results:
Start VM does not work

Expected results:
Start VM should work as it did in 4.3.3 and 4.2 builds.

Additional info:
Same request works with 4.3.3 and 4.2 builds.
Starting the same VM with cloud-init=false works.
Comment 2 Avihai 2019-06-14 10:30:24 UTC 
Start VM via Webadmin with cloud-init enabled works.
Comment 3 RHEL Program Management 2019-06-15 02:34:19 UTC 
This bug report has Keywords: Regression or TestBlocker.
Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release. Please resolve ASAP.
Comment 4 Tomasz Barański 2019-06-17 09:23:14 UTC 

*** This bug has been marked as a duplicate of bug 1716932 ***