Bug 1291360 - Running a vm with a long name fails
Running a vm with a long name fails
Status: CLOSED CURRENTRELEASE
Product: ovirt-engine
Classification: oVirt
Component: BLL.Virt (Show other bugs)
3.6.1.3
Unspecified Unspecified
medium Severity medium (vote)
: ovirt-3.6.5
: 3.6.5.3
Assigned To: Tomas Jelinek
Ilanit Stein
:
Depends On: 1282846 1289363
Blocks:
  Show dependency treegraph
 
Reported: 2015-12-14 11:50 EST by sefi litmanovich
Modified: 2016-05-13 02:45 EDT (History)
5 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2016-04-21 10:40:54 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Virt
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
michal.skrivanek: ovirt‑3.6.z?
istein: testing_plan_complete+
rule-engine: planning_ack?
rule-engine: devel_ack+
rule-engine: testing_ack+


Attachments (Terms of Use)


External Trackers
Tracker ID Priority Status Summary Last Updated
oVirt gerrit 55680 ovirt-engine-3.6 ABANDONED core: lower vm name lenght limit 2016-04-11 07:23 EDT

  None (edit)
Description sefi litmanovich 2015-12-14 11:50:26 EST
Version-Release number of selected component (if applicable):
3.6.1.3

How reproducible:
always

Steps to Reproduce:
1. Create a vm with a long name but less than limit (64 chars), e.g. in my case 'Virt_pool_size_more_than_prestarted_user_and_admin_take_vms_1' (62 chars)

2. run vm

Actual results:
Vm goes to state 'waiting_for_launch' for a second and then goes down. In engine log you can see:


2015-12-14 18:33:27,762 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-7-thread-41) [622ca75d] START, CreateVDSCommand(HostName = host_mixed_1, CreateVmVDSCommandParameters:{runAsync='true', host
Id='25a0fd3f-9815-4750-b6da-b935fb5a8655', vmId='3a25bd8d-7909-4092-8768-88b4019c511d', vm='VM [Virt_pool_size_more_than_prestarted_user_and_admin_take_vms_1]'}), log id: 22f7dfc2
2015-12-14 18:33:27,781 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmInfoBuilderBase] (org.ovirt.thread.pool-7-thread-41) [622ca75d] Bootable disk '955a9011-8037-4a19-9d6d-7f5190f92b69' set to index '0'
2015-12-14 18:33:27,835 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-7-thread-41) [622ca75d] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand kvmEnable=true,keyboardLayout=en-us,nice=
0,displayNetwork=ovirtmgmt,copyPasteEnable=true,timeOffset=0,transparentHugePages=true,vmId=3a25bd8d-7909-4092-8768-88b4019c511d,acpiEnable=true,custom={},spiceSslCipherSuite=DEFAULT,maxMemSize=4194304,memSize=1024,smp=1,emulatedMachine=p
c-i440fx-rhel7.2.0,vmType=kvm,guestNumaNodes=[{cpus=0, nodeIndex=0, memory=1024}],memGuaranteedSize=1024,display=qxl,maxMemSlots=16,smartcardEnable=false,bootMenuEnable=false,numaTune={mode=interleave, nodeset=0},smpCoresPerSocket=1,spice
SecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,maxVCpus=16,devices=[{specParams={vram=32768, heads=1}, device=qxl, type=video, deviceId=80563cb3-bf8a-4d98-afc3-5ae1e3363327}, {specParams={copyPasteEna
ble=true, fileTransferEnable=true}, device=spice, type=graphics, deviceId=a4bd4d20-c5ec-4a97-afaf-37c604d608a5}, {shared=false, iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0, type=drive}, specParams={path=}, path=, de
vice=cdrom, type=disk, readonly=true, deviceId=6a190bff-fc5b-42fa-b4ee-726784cd4bb7}, {shared=false, index=0, volumeID=ec00c688-4b01-49d6-b478-9a0e9132f11f, propagateErrors=off, format=cow, type=disk, iface=virtio, bootOrder=1, address={b
us=0x00, domain=0x0000, type=pci, slot=0x06, function=0x0}, domainID=1e86ca7c-990e-424f-9a9d-3e133f79b433, imageID=955a9011-8037-4a19-9d6d-7f5190f92b69, specParams={}, optional=false, device=disk, poolID=838d693b-28dd-4f1d-a987-c70eb06d50
6e, readonly=false, deviceId=955a9011-8037-4a19-9d6d-7f5190f92b69}, {nicModel=pv, address={bus=0x00, domain=0x0000, type=pci, slot=0x03, function=0x0}, specParams={outbound={}, inbound={}}, macAddr=00:1a:4a:16:01:53, device=bridge, linkAc
tive=true, type=interface, network=ovirtmgmt, deviceId=f2a5f89d-387e-4197-99af-3b67b7c61355}, {address={bus=0x00, domain=0x0000, type=pci, slot=0x04, function=0x0}, specParams={}, device=ich6, type=sound, deviceId=9842f6e6-2921-44e6-886d-
2735a50bbdf2}, {address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, specParams={}, device=virtio-serial, type=controller, deviceId=1f7f0499-623a-482e-808f-d5fe2f25b412}],vmName=Virt_pool_size_more_than_prestarted_user_an
d_admin_take_vms_1,cpuType=Penryn,fileTransferEnable=true
2015-12-14 18:33:28,856 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-7-thread-41) [622ca75d] FINISH, CreateVDSCommand, log id: 22f7dfc2
2015-12-14 18:33:28,917 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-7-thread-41) [622ca75d] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 64b5a36
2015-12-14 18:33:28,917 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-41) [622ca75d] Lock freed to object 'EngineLock:{exclusiveLocks='[3a25bd8d-7909-4092-8768-88b4019c511d=<VM, ACTION_TYPE_FAILED_OBJECT_L
OCKED>]', sharedLocks='null'}'
2015-12-14 18:33:28,986 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-7-thread-41) [622ca75d] Correlation ID: 622ca75d, Job ID: a829923b-7f7b-40bb-a9b4-e83ce0bd5fa0, Call Stack: null, 
Custom Event ID: -1, Message: VM Virt_pool_size_more_than_prestarted_user_and_admin_take_vms_1 was started by admin@internal (Host: host_mixed_1).
2015-12-14 18:33:30,055 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-149) [] START, DestroyVDSCommand(HostName = host_mixed_1, DestroyVmVDSCommandParameters:{runAsync='true', hostId='25a0fd3f-
9815-4750-b6da-b935fb5a8655', vmId='3a25bd8d-7909-4092-8768-88b4019c511d', force='false', secondsToWait='0', gracefully='false', reason=''}), log id: 21e9190e
2015-12-14 18:33:31,068 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-149) [] FINISH, DestroyVDSCommand, log id: 21e9190e
2015-12-14 18:33:31,202 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-149) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM Virt_pool_size_more_than_prestarted_user_and_admin_take_vms_1 is down with error. Exit message: Invalid machine name.
2015-12-14 18:33:31,203 INFO  [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (ForkJoinPool-1-worker-149) [] Running on vds during rerun failed vm: '25a0fd3f-9815-4750-b6da-b935fb5a8655'
2015-12-14 18:33:31,205 INFO  [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (ForkJoinPool-1-worker-149) [] VM '3a25bd8d-7909-4092-8768-88b4019c511d(Virt_pool_size_more_than_prestarted_user_and_admin_take_vms_1) is running in db and not running in VDS 'host_mixed_1'
2015-12-14 18:33:31,270 ERROR [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (ForkJoinPool-1-worker-149) [] Rerun VM '3a25bd8d-7909-4092-8768-88b4019c511d'. Called from VDS 'host_mixed_1'
2015-12-14 18:33:31,386 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-7-thread-4) [] Correlation ID: 622ca75d, Job ID: a829923b-7f7b-40bb-a9b4-e83ce0bd5fa0, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM Virt_pool_size_more_than_prestarted_user_and_admin_take_vms_1 on Host host_mixed_1.
2015-12-14 18:33:31,419 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-4) [] Lock Acquired to object 'EngineLock:{exclusiveLocks='[3a25bd8d-7909-4092-8768-88b4019c511d=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2015-12-14 18:33:31,450 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-7-thread-4) [] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{runAsync='true', vmId='3a25bd8d-7909-4092-8768-88b4019c511d'}), log id: 1cf45fc4
2015-12-14 18:33:31,451 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-7-thread-4) [] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 1cf45fc4
2015-12-14 18:33:31,457 WARN  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-4) [] CanDoAction of action 'RunVm' failed for user admin@internal. Reasons: VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,SCHEDULING_NO_HOSTS
2015-12-14 18:33:31,457 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-4) [] Lock freed to object 'EngineLock:{exclusiveLocks='[3a25bd8d-7909-4092-8768-88b4019c511d=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2015-12-14 18:33:31,528 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-7-thread-4) [] Correlation ID: 622ca75d, Job ID: a829923b-7f7b-40bb-a9b4-e83ce0bd5fa0, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM Virt_pool_size_more_than_prestarted_user_and_admin_take_vms_1 (User: admin@internal).
2015-12-14 18:33:31,536 INFO  [org.ovirt.engine.core.bll.ProcessDownVmCommand] (org.ovirt.thread.pool-7-thread-35) [149189a4] Running command: ProcessDownVmCommand internal: true.
2015-12-14 18:38:11,556 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-4) [59b44a96] Lock Acquired to object 'EngineLock:{exclusiveLocks='[3a25bd8d-7909-4092-8768-88b4019c511d=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2015-12-14 18:38:11,795 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (org.ovirt.thread.pool-7-thread-15) [59b44a96] Running command: RemoveVmCommand internal: false. Entities affected :  ID: 3a25bd8d-7909-4092-8768-88b4019c511d Type: VMAction group DELETE_VM with role type USER
2015-12-14 18:38:11,797 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-7-thread-15) [59b44a96] START, SetVmStatusVDSCommand( SetVmStatusVDSCommandParameters:{runAsync='true', vmId='3a25bd8d-7909-4092-8768-88b4019c511d', status='ImageLocked', exitStatus='Normal'}), log id: 219ed3e2
2015-12-14 18:38:11,803 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-7-thread-15) [59b44a96] FINISH, SetVmStatusVDSCommand, log id: 219ed3e2
2015-12-14 18:38:11,846 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (org.ovirt.thread.pool-7-thread-15) [59b44a96] Lock freed to object 'EngineLock:{exclusiveLocks='[3a25bd8d-7909-4092-8768-88b4019c511d=<VM, ACTION_TYPE_FAILED_OBJEC
T_LOCKED>]', sharedLocks='null'}'
2015-12-14 18:38:11,909 INFO  [org.ovirt.engine.core.bll.RemoveAllVmImagesCommand] (org.ovirt.thread.pool-7-thread-15) [228cd963] Running command: RemoveAllVmImagesCommand internal: true. Entities affected :  ID: 3a25bd8d-7909-4092-8768-88b4019c511d Type: VM
2015-12-14 18:38:11,914 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (org.ovirt.thread.pool-7-thread-15) [59fb6fc7] Running command: RemoveImageCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
2015-12-14 18:38:12,305 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-7-thread-15) [59fb6fc7] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{runAsync='true', storagePoolId='838d693b-28dd-4f1d-a987-c70eb06d506e', ignoreFailoverLimit='false', storageDomainId='1e86ca7c-990e-424f-9a9d-3e133f79b433', imageGroupId='955a9011-8037-4a19-9d6d-7f5190f92b69', postZeros='false', forceDelete='false'}), log id: 78b418c4
2015-12-14 18:38:13,438 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-7-thread-15) [59fb6fc7] FINISH, DeleteImageGroupVDSCommand, log id: 78b418c4
2015-12-14 18:38:13,463 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-7-thread-15) [59fb6fc7] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command '024a57f0-4136-4d07-8de6-48d17c92bf0e'
2015-12-14 18:38:13,463 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-7-thread-15) [59fb6fc7] CommandMultiAsyncTasks::AttachTask: Attaching task '5ea54a15-8783-498a-89fd-cd3cc532c0db' to command '024a57f0-4136-4d07-8de6-48d17c92bf0e'.
2015-12-14 18:38:13,711 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-7-thread-15) [59fb6fc7] Adding task '5ea54a15-8783-498a-89fd-cd3cc532c0db' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2015-12-14 18:38:14,187 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-7-thread-15) [59fb6fc7] Correlation ID: 59b44a96, Job ID: a3f38684-4261-4668-ae48-92d0c0d17877, Call Stack: null, Custom Event ID: -1, Message: VM Virt_pool_size_more_than_prestarted_user_and_admin_take_vms_1 was successfully removed.
2015-12-14 18:38:14,187 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-7-thread-15) [59fb6fc7] BaseAsyncTask::startPollingTask: Starting to poll task '5ea54a15-8783-498a-89fd-cd3cc532c0db'.
2015-12-14 18:38:22,082 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-84) [] Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now
2015-12-14 18:38:23,997 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-84) [] SPMAsyncTask::PollTask: Polling task '5ea54a15-8783-498a-89fd-cd3cc532c0db' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2015-12-14 18:38:24,022 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-84) [] BaseAsyncTask::onTaskEndSuccess: Task '5ea54a15-8783-498a-89fd-cd3cc532c0db' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2015-12-14 18:38:24,025 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-84) [] CommandAsyncTask::endActionIfNecessary: All tasks of command '024a57f0-4136-4d07-8de6-48d17c92bf0e' has ended -> executing 'endAction'
2015-12-14 18:38:24,025 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-84) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: '024a57f0-4136-4d07-8de6-48d17c92bf0e'): calling endAction '.
2015-12-14 18:38:24,026 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-7-thread-23) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'RemoveVm', executionIndex: '0'
2015-12-14 18:38:24,090 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (org.ovirt.thread.pool-7-thread-23) [] Ending command 'org.ovirt.engine.core.bll.RemoveVmCommand' successfully.


Expected results:

1 of 2:
1. Vm should run as expected.
2. char limit for vm name should be lower.
Comment 1 Michal Skrivanek 2015-12-15 01:50:35 EST
looks like a systemd bug, see related bug
Comment 2 Michal Skrivanek 2015-12-15 01:51:20 EST
keeping open in case we have to lower the limit
Comment 3 Michal Skrivanek 2016-01-28 03:12:36 EST
related to bug 1260131 (likely same cause - migration to systemd)
Comment 4 Michal Skrivanek 2016-02-08 08:23:39 EST
we want to wait for platform fix(rather than decreasing the limit in UI), which should arrive as a 7.2.z at some point
Comment 6 Michal Skrivanek 2016-04-11 07:22:26 EDT
I guess I've mis-read the dependent bug, it should be fixed already (https://bugzilla.redhat.com/show_bug.cgi?id=1308494#c19)
Comment 7 Sandro Bonazzola 2016-04-11 10:47:52 EDT
Including in 3.6.5.3 based on comment #6.
Comment 8 Ilanit Stein 2016-04-12 11:20:18 EDT
Verified on rhevm 3.6.5-4:

With libvirt  1.2.17-13.el7_2.4.x86_64 on host,
VM with name of 64 chars can be run.
VM name above 64 chars fail as expected, on validation.

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