Re: owner of vm paused/unpaused operation
by Strahil
You can always check the queue_if_no_path multipath.conf option and give it a try.
But if your system that is queue-ing get's rebooted - that will be data loss -> use on your own risk.
Don't forget that the higher in I/O chain you go - the higher the timeout is needed, so your VM should also use multipath with that option, in addition to the host.
Still, we can't help you if you use that feature and you loose data.
Best Regards,
Strahil NikolovOn Oct 10, 2019 10:55, Francesco Romani <fromani(a)redhat.com> wrote:
>
> On 10/10/19 9:07 AM, Gianluca Cecchi wrote:
>
>
>> > How is determined the timeout to use to put the VM in pause mode?
>>
>>
>> The VM is paused immediately as soon as libvirt, through QEMU, reports
>> IOError, to avoid data corruption. Now, when libvirt reports this error
>>
>> depends laregly on the timeout set for the storage configuration, which
>> is done at host level, using system tools (e.g. it is not a Vdsm tunable)
>>
>
> For test I have set this in multipath.conf of host:
>
> devices {
> device {
> all_devs yes
> # Set timeout of queuing of 5*28 = 140 seconds
> # similar to vSphere APD timeout
> # no_path_retry fail
> no_path_retry 28
> polling_interval 5
> }
>
> So it should wait at least 140 seconds before passing error to upper layer correct?
>
>
> AFAICT yes
>
>
>>
>>>
>>> > Sometimes I see after clearing the problems that the VM is
>>> > automatically un-paused, sometimes no: how is this managed?
>>>
>>
>> I noticed that if I set disk as virtio-scsi (it seems virtio has no timeout definable and passes suddenly the error to upper layer) and disk timeout of vm disk (through udev rule) to 180 seconds, I can block access to the storage for example for 100 seconds and the host is able to reinstate paths and then vm is always unpaused.
>> But I would like to prevent VM from pausing at all
>> What else to tweak?
>
>
> The only way Vdsm will not pause the VM is if libvirt+qemu never reports any ioerror, which is something I'm not sure is possible and that I'd never recommend anyway.
>
> Vdsm always tries hard to be super-careful with respect possible data corruption.
>
>
> Bests,
>
>
> --
>
> Francesco Romani
>
> Senior SW Eng., Virtualization R&D
>
> Red Hat
>
> IRC: fromani github: @fromanirh
4 years, 6 months
- 2
- 1
iSCSI storage domain with no switch
by MIMMIK _
Is it possibile to have a storage domain on an iSCSI LUN if the storage is connected to the cluster physical nodes with no switch and only direct connections?
This is the scenario:
- we have two physical nodes with 2 iSCSI ports each.
- the storage has 2 controllers, 2 iSCSI ports on each controller
- each server is directly connected with a port to a storage port on a controller and to another storage port on the other controller.
Do you think is this possibile, maybe using any trick or workaround? Thanks.
Regards
4 years, 6 months
- 1
- 0
Re: Trying to add a LUN to a host and use that, instead of Gluster, as the datastore for my VM's.
by Strahil
You can create an NFS on that host and export to itself that local storage...
Best Regards,
Strahil NikolovOn Oct 9, 2019 07:43, TomK <tomkcpr(a)mdevsys.com> wrote:
>
> Manged to reverse it through the options. Had to deactivate the custom
> local cluster.
>
> Now I have my GlusterFS back and want to try and add some local storage
> to each host under the same DC, Cluster and Storage Domain. So
> effectively I will have two storage locations. One on my GlusterFS and
> the other on the local storage I've just defined.
>
> Appears I can't make them coexist with oVirt. Either the host is placed
> in a separate cluster with local storage, or I move it back to the
> GlusterFS.
>
> Appears I can't have two usable storage types under one host. Is this
> correct?
>
> What I'm looking for is in the image and shared earlier.
>
> Cheers,
> TK
>
> On 10/8/2019 11:03 PM, TomK wrote:
> > I'm working to reverse this scenario.
> >
> > My storage domain still exists. However I can't activate it. The
> > Manage button is greyed out without clear indication as to why.
> > Difficult to tell what my next move should be.
> >
> > Anyway to find out?
> >
> > Cheers,
> > TK
> >
> > On 10/7/2019 8:25 AM, TomK wrote:
> >> Allright.
> >>
> >> So I followed this and configured local storage. It had some default
> >> names that I changed. It would have been either the default name, or
> >> one I choose. In either case it would be a different name then the
> >> Gluster storage domain the host was a part of anyway.
> >>
> >> Once the process completed for both hosts, I noticed the Gluster
> >> volume storage domain was offline and the gluster volume was gone. I
> >> can't seem to add that back in anymore. I get:
> >>
> >> "Error while executing action DisconnectStorageServerConnection: Error
> >> storage server disconnection"
> >>
> >> Guessing I can't have local storage in addition to Gluster on the same
> >> hosts and available for VM's?
> >>
> >> Reason why I need that is that Gluster is slow but provides redundancy
> >> and live migration. But I also wanted direct storage for VM's
> >> requiring faster IO. So here's my scenario:
> >>
> >> host01
> >> /dev/sda OS
> >> /dev/sdb 4TB (For Gluster)
> >> /dev/sdc 4TB (For Local Storage)
> >>
> >> host02
> >> /dev/sda OS
> >> /dev/sdb 4TB (For Gluster)
> >> /dev/sdc 4TB (For Local Storage)
> >>
> >> I would like to have:
> >>
> >> 1) GlusterFS volume available to oVirt via the two /dev/sdb drives in
> >> both physical hosts.
> >> 2) Two locally attached LUN's, each separate and local to that
> >> physical host.
> >>
> >> Is this possible?
> >>
> >> Cheers,
> >> TK
> >>
> >> On 10/6/2019 12:38 AM, Strahil wrote:
> >>> Hi Tom,
> >>>
> >>> Have you checked
> >>> https://access.redhat.com/documentation/en-us/red_hat_virtualization/4.3/...
> >>> ?
> >>>
> >>> Best Regards,
> >>> Strahil NikolovOn Oct 6, 2019 06:26, TomK <tomkcpr(a)mdevsys.com> wrote:
> >>>>
> >>>> Hey All,
> >>>>
> >>>> I've added a 4TB LUN to my physical storage and now I want to use that,
> >>>> instead of GlusterFS as my datastore for VM's on that physical. How do
> >>>> I do this?
> >>>>
> >>>> I've tried a number of options, including adding LUN's but appears I
> >>>> can
> >>>> only add them to VM's directly but not use them as my datastores
> >>>> instead
> >>>> of GlusterFS.
> >>>>
> >>>> --
> >>>> Thx,
> >>>> TK.
> >>>> _______________________________________________
> >>>> Users mailing list -- users(a)ovirt.org
> >>>> To unsubscribe send an email to users-leave(a)ovirt.org
> >>>> Privacy Statement: https://www.ovirt.org/site/privacy-policy/
> >>>> oVirt Code of Conduct:
> >>>> https://www.ovirt.org/community/about/community-guidelines/
> >>>> List Archives:
> >>>> https://lists.ovirt.org/archives/list/users@ovirt.org/message/ZES6FCONNYB...
> >>>>
> >>> _______________________________________________
> >>> Users mailing list -- users(a)ovirt.org
> >>> To unsubscribe send an email to users-leave(a)ovirt.org
> >>> Privacy Statement: https://www.ovirt.org/site/privacy-policy/
> >>> oVirt Code of Conduct:
> >>> https://www.ovirt.org/community/about/community-guidelines/
> >>> List Archives:
> >>> https://lists.ovirt.org/archives/list/users@ovirt.org/message/WE2MPSRXTJC...
> >>>
> >>>
> >>
> >>
> >
> >
>
>
> --
> Thx,
> TK.
>
> _______________________________________________
> Users mailing list -- users(a)ovirt.org
> To unsubscribe send an email to users-leave(a)ovirt.org
> Privacy Statement: https://www.ovirt.org/site/privacy-policy/
> oVirt Code of Conduct: https://www.ovirt.org/community/about/community-guidelines/
> List Archives: https://lists.ovirt.org/archives/list/users@ovirt.org/message/QJDCKXESPUM...
4 years, 6 months
- 3
- 2
owner of vm paused/unpaused operation
by Gianluca Cecchi
Hello,
I'm doing some tests related to storage latency or problems manually
created to debug and manage reactions of hosts and VMs.
What is the subsystem/process/daemon responsible to pause a VM when
problems arise on storage for the host where the VM is running?
How is determined the timeout to use to put the VM in pause mode?
Sometimes I see after clearing the problems that the VM is automatically
un-paused, sometimes no: how is this managed? Are there any counters so
that if VM has been paused and and problems are not solved in a certain
timeframe the unpause can be done only manually by the sysadmin?
Thanks in advance,
Gianluca
4 years, 6 months
- 2
- 7
Hyperconverged setup questions
by Vrgotic, Marko
Dear oVirt,
Is it possible to add oVirt 3Hosts/Gluster hyperconverged cluster to existing oVirt setup? I need this to achieve Local storage performance, but still have pool of Hypevisors available.
Is it possible to have more than 3Hosts in Hyperconverged setup?
I have currently 1Shared Cluster (NFS based storage, where also SHE is hosted) and 2Local Storage clusters.
oVirt current version running is 4.3.4.
Kindly awaiting your reply.
— — —
Met vriendelijke groet / Kind regards,
Marko Vrgotic
ActiveVideo
4 years, 6 months
- 1
- 0
Re: Delete snapshots task hung
by Strahil
Maybe you can change the status of the VM in order the engine to know that it has to blockcommit the snapshots.
Best Regards,
Strahil NikolovOn Oct 9, 2019 09:02, Leo David <leoalex(a)gmail.com> wrote:
>
> Hi Everyone,
> Please let me know if any thoughts or recommandations that could help me solve this issue..
> The real bad luck in this outage is that these 5 vms are part on an Openshift deployment, and now we are not able to start it up...
> Before trying to sort this at ocp platform level by replacing the failed nodes with new vms, I would rather prefer to do it at the oVirt level and have the vms starting since the disks are still present on gluster.
> Thank you so much !
>
>
> Leo
4 years, 6 months
- 2
- 1
Upgrading from oVirt-Node 4.2.8 to latest
by Sven Achtelik
Hi All,
is there a way to go from 4.2.8 on ovirt node to go directly to the latest version, without reinstalling the node from the iso file ? I wasn't able to find anything in documentation on how to get this done.
Thanks, Sven
4 years, 6 months
- 5
- 8
Bridge issue
by Constantinos L
Hello all,
I am trying to setup a bridge. I have 3 virtual machines. The 1st acting as router, the second acting as bridge and the 3rd is the client, like the following diagram
ROUTER BRIDGE CLIENT
internet(ovirtmng network) ----- [eth0 router --eth1 ] -------[eth0 --[br0]-- eth1] -------[--eth Windows 10]
The problem is that windows 10 is not able to connect the internet although is able to allocate ip. I use ovirt external network to connect the VMs to each other.
It seems that Windows 10 sends ARP to BRIDGE, the BRIDGE sends the ARP to ROUTER but the replies are not passing the br0 when it comes a reply from ROUTER to Windows 10.
I use oVirt 4.3.6. Do you know what should be the issue ? Is there a chance that ovirt blocking the bridge?
Thanks
4 years, 6 months
- 1
- 0
Fail to attach/create disk from template when running via Ansible
by Vrgotic, Marko
Dear oVirt,
Just recently, I have upgraded oVirt staging environment from 4.3.4 to 4.3.6 release.
Since then I noticed the issue when creating VMs from template, using Ansible. When creating VM from template using UI, all works well.
Tests were executed with same user, with SuperUser priviledges.
pip freeze
ansible==2.7.13
asn1crypto==1.0.0
bcrypt==3.1.7
cffi==1.12.3
cryptography==2.7
dnspython==1.16.0
ipaddress==1.0.22
Jinja2==2.10.1
lxml==4.4.1
MarkupSafe==1.1.1
netaddr==0.7.19
ovirt-engine-sdk-python==4.3.3
paramiko==2.6.0
pycparser==2.19
pycurl==7.43.0.3
PyNaCl==1.3.0
PyYAML==5.1.2
six==1.12.0
Logs from engine:
2019-10-08 09:57:42,294Z INFO [org.ovirt.engine.core.bll.AddVmCommand] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Lock Acquired to object 'EngineLock:{exclusiveLocks='[centos-testvm-024=VM_NAME]', sharedLocks='[9ac6f4ad-58d0-4a7e-b424-91f2d76abcac=TEMPLATE, a7e42574-be60-4c94-94a5-cc4b30fdb16f=DISK]'}'
2019-10-08 09:57:42,299Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43687) [390b4c75] FINISH, HSMClearTaskVDSCommand, return: , log id: be932a0
2019-10-08 09:57:42,299Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43687) [390b4c75] FINISH, SPMClearTaskVDSCommand, return: , log id: 3e25883
2019-10-08 09:57:42,303Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43687) [390b4c75] BaseAsyncTask::removeTaskFromDB: Removed task '7e1d68a2-bb49-4456-b228-db851fe6603c' from DataBase
2019-10-08 09:57:42,303Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43687) [390b4c75] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '4f8a6897-66e8-453b-b706-246cb8505b3e'
2019-10-08 09:57:42,375Z INFO [org.ovirt.engine.core.bll.AddVmCommand] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Running command: AddVmCommand internal: false. Entities affected : ID: 2e428504-c339-11e9-87ef-00163e3ec101 Type: ClusterAction group CREATE_VM with role type USER, ID: 9ac6f4ad-58d0-4a7e-b424-91f2d76abcac Type: VmTemplateAction group CREATE_VM with role type USER, ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: StorageAction group CREATE_DISK with role type USER
2019-10-08 09:57:42,488Z INFO [org.ovirt.engine.core.bll.AddRngDeviceCommand] (default task-23) [332c57d4] Running command: AddRngDeviceCommand internal: true. Entities affected : ID: d5719cf0-2a64-4a28-bbf2-edc1bb05b777 Type: VMAction group EDIT_VM_PROPERTIES with role type USER
2019-10-08 09:57:42,498Z INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (default task-23) [332c57d4] START, SetVmStatusVDSCommand( SetVmStatusVDSCommandParameters:{vmId='d5719cf0-2a64-4a28-bbf2-edc1bb05b777', status='ImageLocked', exitStatus='Normal'}), log id: 2fe004e2
2019-10-08 09:57:42,507Z INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (default task-23) [332c57d4] FINISH, SetVmStatusVDSCommand, return: , log id: 2fe004e2
2019-10-08 09:57:42,528Z INFO [org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Running command: CreateSnapshotFromTemplateCommand internal: true. Entities affected : ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: Storage
2019-10-08 09:57:42,554Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateVolumeVDSCommand] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] START, CreateVolumeVDSCommand( CreateVolumeVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', imageSizeInBytes='8589934592', volumeFormat='COW', newImageId='9a96018c-ce7d-4c77-a91a-30fc16c7b2ba', imageType='Sparse', newImageDescription='', imageInitialSizeInBytes='0', imageId='f9e0c4d9-81dd-4e44-8a71-33e55d4399c6', sourceImageGroupId='a7e42574-be60-4c94-94a5-cc4b30fdb16f'}), log id: 37b29c7d
2019-10-08 09:57:42,639Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateVolumeVDSCommand] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] FINISH, CreateVolumeVDSCommand, return: 9a96018c-ce7d-4c77-a91a-30fc16c7b2ba, log id: 37b29c7d
2019-10-08 09:57:42,645Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'f1665b66-2032-4a60-944e-c04beace088e'
2019-10-08 09:57:42,645Z INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] CommandMultiAsyncTasks::attachTask: Attaching task '99abc310-b44b-435c-8d43-922b782a69dc' to command 'f1665b66-2032-4a60-944e-c04beace088e'.
2019-10-08 09:57:42,660Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Adding task '99abc310-b44b-435c-8d43-922b782a69dc' (Parent Command 'CreateSnapshotFromTemplate', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2019-10-08 09:57:42,934Z INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] EVENT_ID: USER_ADD_VM_STARTED(37), VM centos-testvm-024 creation was initiated by mteam@internal-authz.
2019-10-08 09:57:42,935Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (default task-23) [067ec489-ae6c-4871-8ab6-8296016ca1ce] BaseAsyncTask::startPollingTask: Starting to poll task '99abc310-b44b-435c-8d43-922b782a69dc'.
2019-10-08 09:57:44,384Z INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-74) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Command 'AddVm' (id: '1b65f576-365d-4e8b-a920-621516cbdaed') waiting on child command id: 'f1665b66-2032-4a60-944e-c04beace088e' type:'CreateSnapshotFromTemplate' to complete
2019-10-08 09:57:48,393Z INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Command 'AddVm' (id: '1b65f576-365d-4e8b-a920-621516cbdaed') waiting on child command id: 'f1665b66-2032-4a60-944e-c04beace088e' type:'CreateSnapshotFromTemplate' to complete
2019-10-08 09:57:48,394Z INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [5830ba58] Command 'AddDisk' id: '937776b8-b94d-4178-b9c2-e39fe42cb06c' child commands '[63409b0b-749a-45d5-85a5-baf55d5fa2a4]' executions were completed, status 'SUCCEEDED'
2019-10-08 09:57:48,394Z INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [5830ba58] Command 'AddDisk' id: '937776b8-b94d-4178-b9c2-e39fe42cb06c' Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
2019-10-08 09:57:48,398Z INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [5830ba58] Command 'AddDisk' id: 'fdc5571e-a925-4400-a54a-a1ef1dcd23ae' child commands '[54d68cae-6585-4351-aaf7-fe687905acf4]' executions were completed, status 'SUCCEEDED'
2019-10-08 09:57:48,398Z INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [5830ba58] Command 'AddDisk' id: 'fdc5571e-a925-4400-a54a-a1ef1dcd23ae' Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
2019-10-08 09:57:48,401Z INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [5830ba58] Command 'ProcessOvfUpdateForStorageDomain' (id: 'bdcdae3a-00f6-4176-9d27-0bb0f04912a3') waiting on child command id: 'b4050edd-62a7-4b83-a4ab-a21c83bf3ade' type:'CreateOvfVolumeForStorageDomain' to complete
2019-10-08 09:57:48,402Z INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [5830ba58] Command 'CreateOvfVolumeForStorageDomain' id: 'b4050edd-62a7-4b83-a4ab-a21c83bf3ade' child commands '[937776b8-b94d-4178-b9c2-e39fe42cb06c]' executions were completed, status 'SUCCEEDED'
2019-10-08 09:57:48,404Z INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [5830ba58] Command 'CreateOvfVolumeForStorageDomain' id: '5fd47910-95b2-4387-8e26-ea2c80b078a0' child commands '[fdc5571e-a925-4400-a54a-a1ef1dcd23ae]' executions were completed, status 'SUCCEEDED'
2019-10-08 09:57:49,416Z INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [390b4c75] Command 'ProcessOvfUpdateForStorageDomain' id: '849bd16c-00d2-48a2-8fde-631af0dfe1b5' child commands '[a80a3657-c813-42c1-a43d-27442b5dc238, 4f8a6897-66e8-453b-b706-246cb8505b3e]' executions were completed, status 'SUCCEEDED'
2019-10-08 09:57:49,418Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.CreateOvfVolumeForStorageDomainCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] Ending command 'org.ovirt.engine.core.bll.storage.ovfstore.CreateOvfVolumeForStorageDomainCommand' successfully.
2019-10-08 09:57:49,420Z INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully.
2019-10-08 09:57:49,426Z INFO [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand' successfully.
2019-10-08 09:57:49,427Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] START, GetImageInfoVDSCommand( GetImageInfoVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='66984468-bbfa-4941-8c6b-df72a6d920f2', imageId='7db55211-041a-40c8-85a6-a2ff1bd182ce'}), log id: 6c02a73c
2019-10-08 09:57:49,429Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] START, GetVolumeInfoVDSCommand(HostName = ovirt-staging-hv-01.avinity.tv, GetVolumeInfoVDSCommandParameters:{hostId='bfc4c379-bd5f-45be-98a4-f0469dc3817c', storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='66984468-bbfa-4941-8c6b-df72a6d920f2', imageId='7db55211-041a-40c8-85a6-a2ff1bd182ce'}), log id: 2e131d9d
2019-10-08 09:57:49,456Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] FINISH, GetVolumeInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@26992dd0, log id: 2e131d9d
2019-10-08 09:57:49,456Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@26992dd0, log id: 6c02a73c
2019-10-08 09:57:49,464Z WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [] VM is null - no unlocking
2019-10-08 09:57:49,481Z INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'OVF_STORE' was successfully added.
2019-10-08 09:57:49,490Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.CreateOvfVolumeForStorageDomainCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] Ending command 'org.ovirt.engine.core.bll.storage.ovfstore.CreateOvfVolumeForStorageDomainCommand' successfully.
2019-10-08 09:57:49,491Z INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] Ending command 'org.ovirt.engine.core.bll.storage.disk.AddDiskCommand' successfully.
2019-10-08 09:57:49,495Z INFO [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand' successfully.
2019-10-08 09:57:49,497Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] START, GetImageInfoVDSCommand( GetImageInfoVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='ee208fd3-e05c-4ba8-aba9-fa521d69a870', imageId='484c1eed-b03a-4fa0-a12d-0087294dec86'}), log id: 7a3dad31
2019-10-08 09:57:49,498Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] START, GetVolumeInfoVDSCommand(HostName = ovirt-staging-hv-01.avinity.tv, GetVolumeInfoVDSCommandParameters:{hostId='bfc4c379-bd5f-45be-98a4-f0469dc3817c', storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='ee208fd3-e05c-4ba8-aba9-fa521d69a870', imageId='484c1eed-b03a-4fa0-a12d-0087294dec86'}), log id: 5b85c4a5
2019-10-08 09:57:49,522Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] FINISH, GetVolumeInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@13555e4, log id: 5b85c4a5
2019-10-08 09:57:49,522Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [5830ba58] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@13555e4, log id: 7a3dad31
2019-10-08 09:57:49,529Z WARN [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [] VM is null - no unlocking
2019-10-08 09:57:49,540Z INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-3) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'OVF_STORE' was successfully added.
2019-10-08 09:57:50,552Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStorageDomainCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [390b4c75] Ending command 'org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStorageDomainCommand' successfully.
2019-10-08 09:57:50,575Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] START, SetVolumeDescriptionVDSCommand( SetVolumeDescriptionVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='ee208fd3-e05c-4ba8-aba9-fa521d69a870', imageId='484c1eed-b03a-4fa0-a12d-0087294dec86'}), log id: 7e77a9a8
2019-10-08 09:57:50,576Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters:
2019-10-08 09:57:50,576Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ spUUID=2e3b3484-c339-11e9-8d02-00163e3ec101
2019-10-08 09:57:50,576Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ sdUUID=935de3ac-a735-4fc8-9161-26bfd751ffc7
2019-10-08 09:57:50,576Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ imageGroupGUID=ee208fd3-e05c-4ba8-aba9-fa521d69a870
2019-10-08 09:57:50,576Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ volUUID=484c1eed-b03a-4fa0-a12d-0087294dec86
2019-10-08 09:57:50,576Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ description={"Updated":false,"Last Updated":null,"Storage Domains":[{"uuid":"935de3ac-a735-4fc8-9161-26bfd751ffc7"}],"Disk Description":"OVF_STORE"}
2019-10-08 09:57:50,606Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] FINISH, SetVolumeDescriptionVDSCommand, return: , log id: 7e77a9a8
2019-10-08 09:57:50,614Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] Lock Acquired to object 'EngineLock:{exclusiveLocks='', sharedLocks='[bfc4c379-bd5f-45be-98a4-f0469dc3817c=VDS_EXECUTION]'}'
2019-10-08 09:57:50,623Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] Running command: UploadStreamCommand internal: true. Entities affected : ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: Storage
2019-10-08 09:57:50,624Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] START, UploadStreamVDSCommand(HostName = ovirt-staging-hv-01.avinity.tv, UploadStreamVDSCommandParameters:{hostId='bfc4c379-bd5f-45be-98a4-f0469dc3817c'}), log id: 531a4a4a
2019-10-08 09:57:50,625Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] -- executeVdsBrokerCommand, parameters:
2019-10-08 09:57:50,625Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ spUUID=2e3b3484-c339-11e9-8d02-00163e3ec101
2019-10-08 09:57:50,625Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ sdUUID=935de3ac-a735-4fc8-9161-26bfd751ffc7
2019-10-08 09:57:50,625Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ imageGUID=ee208fd3-e05c-4ba8-aba9-fa521d69a870
2019-10-08 09:57:50,625Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ volUUID=484c1eed-b03a-4fa0-a12d-0087294dec86
2019-10-08 09:57:50,625Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ size=30720
2019-10-08 09:57:51,331Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] FINISH, UploadStreamVDSCommand, return: , log id: 531a4a4a
2019-10-08 09:57:51,342Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'c11f4d3c-f85b-43c5-986f-a517aed66d7e'
2019-10-08 09:57:51,342Z INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] CommandMultiAsyncTasks::attachTask: Attaching task 'e5d00ff5-eaa2-48e9-ab10-d6d06a01e89d' to command 'c11f4d3c-f85b-43c5-986f-a517aed66d7e'.
2019-10-08 09:57:51,351Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] Adding task 'e5d00ff5-eaa2-48e9-ab10-d6d06a01e89d' (Parent Command 'UploadStream', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2019-10-08 09:57:51,355Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] BaseAsyncTask::startPollingTask: Starting to poll task 'e5d00ff5-eaa2-48e9-ab10-d6d06a01e89d'.
2019-10-08 09:57:51,358Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] Lock freed to object 'EngineLock:{exclusiveLocks='', sharedLocks='[bfc4c379-bd5f-45be-98a4-f0469dc3817c=VDS_EXECUTION]'}'
2019-10-08 09:57:51,360Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] START, SetVolumeDescriptionVDSCommand( SetVolumeDescriptionVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='ee208fd3-e05c-4ba8-aba9-fa521d69a870', imageId='484c1eed-b03a-4fa0-a12d-0087294dec86'}), log id: 238169f6
2019-10-08 09:57:51,360Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters:
2019-10-08 09:57:51,360Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ spUUID=2e3b3484-c339-11e9-8d02-00163e3ec101
2019-10-08 09:57:51,360Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ sdUUID=935de3ac-a735-4fc8-9161-26bfd751ffc7
2019-10-08 09:57:51,360Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ imageGroupGUID=ee208fd3-e05c-4ba8-aba9-fa521d69a870
2019-10-08 09:57:51,360Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ volUUID=484c1eed-b03a-4fa0-a12d-0087294dec86
2019-10-08 09:57:51,360Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ description={"Updated":true,"Size":30720,"Last Updated":"Tue Oct 08 09:57:50 UTC 2019","Storage Domains":[{"uuid":"935de3ac-a735-4fc8-9161-26bfd751ffc7"}],"Disk Description":"OVF_STORE"}
2019-10-08 09:57:51,389Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] FINISH, SetVolumeDescriptionVDSCommand, return: , log id: 238169f6
2019-10-08 09:57:51,596Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] START, SetVolumeDescriptionVDSCommand( SetVolumeDescriptionVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='66984468-bbfa-4941-8c6b-df72a6d920f2', imageId='7db55211-041a-40c8-85a6-a2ff1bd182ce'}), log id: 59bde70f
2019-10-08 09:57:51,627Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters:
2019-10-08 09:57:51,627Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ spUUID=2e3b3484-c339-11e9-8d02-00163e3ec101
2019-10-08 09:57:51,627Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ sdUUID=935de3ac-a735-4fc8-9161-26bfd751ffc7
2019-10-08 09:57:51,627Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ imageGroupGUID=66984468-bbfa-4941-8c6b-df72a6d920f2
2019-10-08 09:57:51,627Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ volUUID=7db55211-041a-40c8-85a6-a2ff1bd182ce
2019-10-08 09:57:51,627Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ description={"Updated":false,"Last Updated":null,"Storage Domains":[{"uuid":"935de3ac-a735-4fc8-9161-26bfd751ffc7"}],"Disk Description":"OVF_STORE"}
2019-10-08 09:57:51,664Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] FINISH, SetVolumeDescriptionVDSCommand, return: , log id: 59bde70f
2019-10-08 09:57:51,672Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] Lock Acquired to object 'EngineLock:{exclusiveLocks='', sharedLocks='[bfc4c379-bd5f-45be-98a4-f0469dc3817c=VDS_EXECUTION]'}'
2019-10-08 09:57:51,683Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] Running command: UploadStreamCommand internal: true. Entities affected : ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: Storage
2019-10-08 09:57:51,684Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] START, UploadStreamVDSCommand(HostName = ovirt-staging-hv-01.avinity.tv, UploadStreamVDSCommandParameters:{hostId='bfc4c379-bd5f-45be-98a4-f0469dc3817c'}), log id: 1cb812b6
2019-10-08 09:57:51,684Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] -- executeVdsBrokerCommand, parameters:
2019-10-08 09:57:51,684Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ spUUID=2e3b3484-c339-11e9-8d02-00163e3ec101
2019-10-08 09:57:51,684Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ sdUUID=935de3ac-a735-4fc8-9161-26bfd751ffc7
2019-10-08 09:57:51,684Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ imageGUID=66984468-bbfa-4941-8c6b-df72a6d920f2
2019-10-08 09:57:51,684Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ volUUID=7db55211-041a-40c8-85a6-a2ff1bd182ce
2019-10-08 09:57:51,684Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ size=30720
2019-10-08 09:57:51,933Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] FINISH, UploadStreamVDSCommand, return: , log id: 1cb812b6
2019-10-08 09:57:51,943Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'd0c07988-0e43-4e6d-b86c-e736b28d4537'
2019-10-08 09:57:51,943Z INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] CommandMultiAsyncTasks::attachTask: Attaching task 'ba88edd0-8188-472e-8f59-aa3f90e63181' to command 'd0c07988-0e43-4e6d-b86c-e736b28d4537'.
2019-10-08 09:57:51,952Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] Adding task 'ba88edd0-8188-472e-8f59-aa3f90e63181' (Parent Command 'UploadStream', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2019-10-08 09:57:51,958Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] BaseAsyncTask::startPollingTask: Starting to poll task 'ba88edd0-8188-472e-8f59-aa3f90e63181'.
2019-10-08 09:57:51,961Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] Lock freed to object 'EngineLock:{exclusiveLocks='', sharedLocks='[bfc4c379-bd5f-45be-98a4-f0469dc3817c=VDS_EXECUTION]'}'
2019-10-08 09:57:51,962Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] START, SetVolumeDescriptionVDSCommand( SetVolumeDescriptionVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='66984468-bbfa-4941-8c6b-df72a6d920f2', imageId='7db55211-041a-40c8-85a6-a2ff1bd182ce'}), log id: 213b3075
2019-10-08 09:57:51,962Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] -- executeIrsBrokerCommand: calling 'setVolumeDescription', parameters:
2019-10-08 09:57:51,962Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ spUUID=2e3b3484-c339-11e9-8d02-00163e3ec101
2019-10-08 09:57:51,962Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ sdUUID=935de3ac-a735-4fc8-9161-26bfd751ffc7
2019-10-08 09:57:51,962Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ imageGroupGUID=66984468-bbfa-4941-8c6b-df72a6d920f2
2019-10-08 09:57:51,962Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ volUUID=7db55211-041a-40c8-85a6-a2ff1bd182ce
2019-10-08 09:57:51,962Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] ++ description={"Updated":true,"Size":30720,"Last Updated":"Tue Oct 08 09:57:50 UTC 2019","Storage Domains":[{"uuid":"935de3ac-a735-4fc8-9161-26bfd751ffc7"}],"Disk Description":"OVF_STORE"}
2019-10-08 09:57:52,028Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5830ba58] FINISH, SetVolumeDescriptionVDSCommand, return: , log id: 213b3075
2019-10-08 09:57:52,224Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] Polling and updating Async Tasks: 7 tasks, 3 tasks to poll now
2019-10-08 09:57:52,228Z ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] Failed in 'HSMGetAllTasksStatusesVDS' method
2019-10-08 09:57:52,235Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM ovirt-staging-hv-01.avinity.tv command HSMGetAllTasksStatusesVDS failed: Invalid parameter: 'size=16777216'
2019-10-08 09:57:52,235Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] SPMAsyncTask::PollTask: Polling task '99abc310-b44b-435c-8d43-922b782a69dc' (Parent Command 'CreateSnapshotFromTemplate', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'cleanSuccess'.
2019-10-08 09:57:52,240Z ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] BaseAsyncTask::logEndTaskFailure: Task '99abc310-b44b-435c-8d43-922b782a69dc' (Parent Command 'CreateSnapshotFromTemplate', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Invalid parameter: 'size=16777216', code = 100',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Invalid parameter: 'size=16777216', code = 100'
2019-10-08 09:57:52,241Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] CommandAsyncTask::endActionIfNecessary: All tasks of command 'f1665b66-2032-4a60-944e-c04beace088e' has ended -> executing 'endAction'
2019-10-08 09:57:52,241Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: 'f1665b66-2032-4a60-944e-c04beace088e'): calling endAction '.
2019-10-08 09:57:52,241Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] SPMAsyncTask::PollTask: Polling task 'e5d00ff5-eaa2-48e9-ab10-d6d06a01e89d' (Parent Command 'UploadStream', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2019-10-08 09:57:52,241Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] BaseAsyncTask::onTaskEndSuccess: Task 'e5d00ff5-eaa2-48e9-ab10-d6d06a01e89d' (Parent Command 'UploadStream', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2019-10-08 09:57:52,241Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43693) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'CreateSnapshotFromTemplate',
2019-10-08 09:57:52,242Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] CommandAsyncTask::endActionIfNecessary: All tasks of command 'c11f4d3c-f85b-43c5-986f-a517aed66d7e' has ended -> executing 'endAction'
2019-10-08 09:57:52,243Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: 'c11f4d3c-f85b-43c5-986f-a517aed66d7e'): calling endAction '.
2019-10-08 09:57:52,243Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] SPMAsyncTask::PollTask: Polling task 'ba88edd0-8188-472e-8f59-aa3f90e63181' (Parent Command 'UploadStream', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2019-10-08 09:57:52,243Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] BaseAsyncTask::onTaskEndSuccess: Task 'ba88edd0-8188-472e-8f59-aa3f90e63181' (Parent Command 'UploadStream', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2019-10-08 09:57:52,243Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43694) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'UploadStream',
2019-10-08 09:57:52,244Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] CommandAsyncTask::endActionIfNecessary: All tasks of command 'd0c07988-0e43-4e6d-b86c-e736b28d4537' has ended -> executing 'endAction'
2019-10-08 09:57:52,244Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-91) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: 'd0c07988-0e43-4e6d-b86c-e736b28d4537'): calling endAction '.
2019-10-08 09:57:52,245Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43695) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'UploadStream',
2019-10-08 09:57:52,245Z INFO [org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Command [id=f1665b66-2032-4a60-944e-c04beace088e]: Updating status to 'FAILED', The command end method logic will be executed by one of its parent commands.
2019-10-08 09:57:52,247Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'CreateSnapshotFromTemplate' completed, handling the result.
2019-10-08 09:57:52,247Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'CreateSnapshotFromTemplate' succeeded, clearing tasks.
2019-10-08 09:57:52,247Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '99abc310-b44b-435c-8d43-922b782a69dc'
2019-10-08 09:57:52,247Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] Ending command 'org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand' successfully.
2019-10-08 09:57:52,247Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] Ending command 'org.ovirt.engine.core.bll.storage.ovfstore.UploadStreamCommand' successfully.
2019-10-08 09:57:52,247Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', taskId='99abc310-b44b-435c-8d43-922b782a69dc'}), log id: 66a4e67
2019-10-08 09:57:52,247Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] START, HSMClearTaskVDSCommand(HostName = ovirt-staging-hv-01.avinity.tv, HSMTaskGuidBaseVDSCommandParameters:{hostId='bfc4c379-bd5f-45be-98a4-f0469dc3817c', taskId='99abc310-b44b-435c-8d43-922b782a69dc'}), log id: 7ec6d8b8
2019-10-08 09:57:52,249Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'UploadStream' completed, handling the result.
2019-10-08 09:57:52,249Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'UploadStream' succeeded, clearing tasks.
2019-10-08 09:57:52,249Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 'e5d00ff5-eaa2-48e9-ab10-d6d06a01e89d'
2019-10-08 09:57:52,249Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', taskId='e5d00ff5-eaa2-48e9-ab10-d6d06a01e89d'}), log id: 356927d
2019-10-08 09:57:52,250Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'UploadStream' completed, handling the result.
2019-10-08 09:57:52,250Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'UploadStream' succeeded, clearing tasks.
2019-10-08 09:57:52,250Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 'ba88edd0-8188-472e-8f59-aa3f90e63181'
2019-10-08 09:57:52,251Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', taskId='ba88edd0-8188-472e-8f59-aa3f90e63181'}), log id: 75844e34
2019-10-08 09:57:52,259Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] FINISH, HSMClearTaskVDSCommand, return: , log id: 7ec6d8b8
2019-10-08 09:57:52,259Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] FINISH, SPMClearTaskVDSCommand, return: , log id: 66a4e67
2019-10-08 09:57:52,260Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] START, HSMClearTaskVDSCommand(HostName = ovirt-staging-hv-01.avinity.tv, HSMTaskGuidBaseVDSCommandParameters:{hostId='bfc4c379-bd5f-45be-98a4-f0469dc3817c', taskId='e5d00ff5-eaa2-48e9-ab10-d6d06a01e89d'}), log id: 3b239769
2019-10-08 09:57:52,263Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] BaseAsyncTask::removeTaskFromDB: Removed task '99abc310-b44b-435c-8d43-922b782a69dc' from DataBase
2019-10-08 09:57:52,263Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43693) [067ec489-ae6c-4871-8ab6-8296016ca1ce] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'f1665b66-2032-4a60-944e-c04beace088e'
2019-10-08 09:57:52,297Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] FINISH, HSMClearTaskVDSCommand, return: , log id: 3b239769
2019-10-08 09:57:52,297Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] FINISH, SPMClearTaskVDSCommand, return: , log id: 356927d
2019-10-08 09:57:52,298Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] START, HSMClearTaskVDSCommand(HostName = ovirt-staging-hv-01.avinity.tv, HSMTaskGuidBaseVDSCommandParameters:{hostId='bfc4c379-bd5f-45be-98a4-f0469dc3817c', taskId='ba88edd0-8188-472e-8f59-aa3f90e63181'}), log id: 32d44e1
2019-10-08 09:57:52,301Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] BaseAsyncTask::removeTaskFromDB: Removed task 'e5d00ff5-eaa2-48e9-ab10-d6d06a01e89d' from DataBase
2019-10-08 09:57:52,301Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43694) [5830ba58] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'c11f4d3c-f85b-43c5-986f-a517aed66d7e'
2019-10-08 09:57:52,314Z INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] FINISH, HSMClearTaskVDSCommand, return: , log id: 32d44e1
2019-10-08 09:57:52,314Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] FINISH, SPMClearTaskVDSCommand, return: , log id: 75844e34
2019-10-08 09:57:52,317Z INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] BaseAsyncTask::removeTaskFromDB: Removed task 'ba88edd0-8188-472e-8f59-aa3f90e63181' from DataBase
2019-10-08 09:57:52,317Z INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-43695) [5830ba58] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'd0c07988-0e43-4e6d-b86c-e736b28d4537'
2019-10-08 09:57:54,039Z INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-44) [5830ba58] Command 'ProcessOvfUpdateForStorageDomain' id: 'bdcdae3a-00f6-4176-9d27-0bb0f04912a3' child commands '[b4050edd-62a7-4b83-a4ab-a21c83bf3ade, 5fd47910-95b2-4387-8e26-ea2c80b078a0, c11f4d3c-f85b-43c5-986f-a517aed66d7e, d0c07988-0e43-4e6d-b86c-e736b28d4537]' executions were completed, status 'SUCCEEDED'
2019-10-08 09:57:55,046Z INFO [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStorageDomainCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-40) [5830ba58] Ending command 'org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStorageDomainCommand' successfully.
2019-10-08 09:57:58,077Z INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-76) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Command 'AddVm' id: '1b65f576-365d-4e8b-a920-621516cbdaed' child commands '[f1665b66-2032-4a60-944e-c04beace088e]' executions were completed, status 'FAILED'
2019-10-08 09:57:59,094Z ERROR [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.AddVmCommand' with failure.
2019-10-08 09:57:59,099Z ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand' with failure.
2019-10-08 09:57:59,104Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5794ed92] Running command: RemoveImageCommand internal: true. Entities affected : ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: Storage
2019-10-08 09:57:59,126Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5794ed92] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'}), log id: 69861a78
2019-10-08 09:57:59,139Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5794ed92] EVENT_ID: IRS_BROKER_COMMAND_FAILURE(10,803), VDSM command DeleteImageGroupVDS failed: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:57:59,139Z ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5794ed92] Command 'DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'})' execution failed: IRSGenericException: IRSErrorException: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:57:59,139Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5794ed92] FINISH, DeleteImageGroupVDSCommand, return: , log id: 69861a78
2019-10-08 09:57:59,139Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5794ed92] Disk 'd680a46a-7188-45f6-b6a7-3333f830c0b4' doesn't exist on storage domain '935de3ac-a735-4fc8-9161-26bfd751ffc7', rolling forward
2019-10-08 09:57:59,149Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5794ed92] Removed task 'b4c4c723-4ba1-4d5a-86e6-24658a293a04' from DataBase
2019-10-08 09:57:59,220Z INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [] transaction rolled back
2019-10-08 09:57:59,220Z INFO [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [] Lock freed to object 'EngineLock:{exclusiveLocks='[centos-testvm-024=VM_NAME]', sharedLocks='[9ac6f4ad-58d0-4a7e-b424-91f2d76abcac=TEMPLATE, a7e42574-be60-4c94-94a5-cc4b30fdb16f=DISK]'}'
2019-10-08 09:57:59,233Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [] EVENT_ID: USER_ADD_VM_FINISHED_FAILURE(60), Failed to complete VM centos-testvm-024 creation.
2019-10-08 09:57:59,233Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [] Failed invoking callback end method 'onFailed' for command '1b65f576-365d-4e8b-a920-621516cbdaed' with exception 'null', the callback is marked for end method retries
2019-10-08 09:58:01,252Z ERROR [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.AddVmCommand' with failure.
2019-10-08 09:58:01,257Z ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand' with failure.
2019-10-08 09:58:01,270Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [19251787] Running command: RemoveImageCommand internal: true. Entities affected : ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: Storage
2019-10-08 09:58:01,308Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [19251787] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'}), log id: 35fec55
2019-10-08 09:58:01,324Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [19251787] EVENT_ID: IRS_BROKER_COMMAND_FAILURE(10,803), VDSM command DeleteImageGroupVDS failed: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:01,324Z ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [19251787] Command 'DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'})' execution failed: IRSGenericException: IRSErrorException: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:01,324Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [19251787] FINISH, DeleteImageGroupVDSCommand, return: , log id: 35fec55
2019-10-08 09:58:01,324Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [19251787] Disk 'd680a46a-7188-45f6-b6a7-3333f830c0b4' doesn't exist on storage domain '935de3ac-a735-4fc8-9161-26bfd751ffc7', rolling forward
2019-10-08 09:58:01,335Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [19251787] Removed task '6ed0a844-5363-4afd-bffc-a80b6ace69ea' from DataBase
2019-10-08 09:58:01,395Z INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [] transaction rolled back
2019-10-08 09:58:01,395Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [] Trying to release a shared lock for key: '9ac6f4ad-58d0-4a7e-b424-91f2d76abcacTEMPLATE' , but lock does not exist
2019-10-08 09:58:01,395Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [] Trying to release a shared lock for key: 'a7e42574-be60-4c94-94a5-cc4b30fdb16fDISK' , but lock does not exist
2019-10-08 09:58:01,395Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [] Trying to release exclusive lock which does not exist, lock key: 'centos-testvm-024VM_NAME'
2019-10-08 09:58:01,395Z INFO [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [] Lock freed to object 'EngineLock:{exclusiveLocks='[centos-testvm-024=VM_NAME]', sharedLocks='[9ac6f4ad-58d0-4a7e-b424-91f2d76abcac=TEMPLATE, a7e42574-be60-4c94-94a5-cc4b30fdb16f=DISK]'}'
2019-10-08 09:58:01,407Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [] EVENT_ID: USER_ADD_VM_FINISHED_FAILURE(60), Failed to complete VM centos-testvm-024 creation.
2019-10-08 09:58:01,407Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-85) [] Failed invoking callback end method 'onFailed' for command '1b65f576-365d-4e8b-a920-621516cbdaed' with exception 'null', the callback is marked for end method retries
2019-10-08 09:58:05,427Z ERROR [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.AddVmCommand' with failure.
2019-10-08 09:58:05,430Z ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand' with failure.
2019-10-08 09:58:05,437Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [cf91364] Running command: RemoveImageCommand internal: true. Entities affected : ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: Storage
2019-10-08 09:58:05,452Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [cf91364] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'}), log id: 6ac726b6
2019-10-08 09:58:05,466Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [cf91364] EVENT_ID: IRS_BROKER_COMMAND_FAILURE(10,803), VDSM command DeleteImageGroupVDS failed: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:05,466Z ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [cf91364] Command 'DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'})' execution failed: IRSGenericException: IRSErrorException: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:05,466Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [cf91364] FINISH, DeleteImageGroupVDSCommand, return: , log id: 6ac726b6
2019-10-08 09:58:05,467Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [cf91364] Disk 'd680a46a-7188-45f6-b6a7-3333f830c0b4' doesn't exist on storage domain '935de3ac-a735-4fc8-9161-26bfd751ffc7', rolling forward
2019-10-08 09:58:05,477Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [cf91364] Removed task '31bd7a11-203d-4459-ac54-3c398c85771d' from DataBase
2019-10-08 09:58:05,490Z INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [] transaction rolled back
2019-10-08 09:58:05,490Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [] Trying to release a shared lock for key: '9ac6f4ad-58d0-4a7e-b424-91f2d76abcacTEMPLATE' , but lock does not exist
2019-10-08 09:58:05,490Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [] Trying to release a shared lock for key: 'a7e42574-be60-4c94-94a5-cc4b30fdb16fDISK' , but lock does not exist
2019-10-08 09:58:05,490Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [] Trying to release exclusive lock which does not exist, lock key: 'centos-testvm-024VM_NAME'
2019-10-08 09:58:05,490Z INFO [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [] Lock freed to object 'EngineLock:{exclusiveLocks='[centos-testvm-024=VM_NAME]', sharedLocks='[9ac6f4ad-58d0-4a7e-b424-91f2d76abcac=TEMPLATE, a7e42574-be60-4c94-94a5-cc4b30fdb16f=DISK]'}'
2019-10-08 09:58:05,503Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [] EVENT_ID: USER_ADD_VM_FINISHED_FAILURE(60), Failed to complete VM centos-testvm-024 creation.
2019-10-08 09:58:05,503Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [] Failed invoking callback end method 'onFailed' for command '1b65f576-365d-4e8b-a920-621516cbdaed' with exception 'null', the callback is marked for end method retries
2019-10-08 09:58:13,523Z ERROR [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.AddVmCommand' with failure.
2019-10-08 09:58:13,527Z ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand' with failure.
2019-10-08 09:58:13,533Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [56103b5a] Running command: RemoveImageCommand internal: true. Entities affected : ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: Storage
2019-10-08 09:58:13,548Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [56103b5a] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'}), log id: 33164673
2019-10-08 09:58:13,560Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [56103b5a] EVENT_ID: IRS_BROKER_COMMAND_FAILURE(10,803), VDSM command DeleteImageGroupVDS failed: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:13,560Z ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [56103b5a] Command 'DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'})' execution failed: IRSGenericException: IRSErrorException: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:13,560Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [56103b5a] FINISH, DeleteImageGroupVDSCommand, return: , log id: 33164673
2019-10-08 09:58:13,560Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [56103b5a] Disk 'd680a46a-7188-45f6-b6a7-3333f830c0b4' doesn't exist on storage domain '935de3ac-a735-4fc8-9161-26bfd751ffc7', rolling forward
2019-10-08 09:58:13,570Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [56103b5a] Removed task 'ce6882de-2d89-4298-bdcf-86d621a54084' from DataBase
2019-10-08 09:58:13,583Z INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [] transaction rolled back
2019-10-08 09:58:13,583Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [] Trying to release a shared lock for key: '9ac6f4ad-58d0-4a7e-b424-91f2d76abcacTEMPLATE' , but lock does not exist
2019-10-08 09:58:13,583Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [] Trying to release a shared lock for key: 'a7e42574-be60-4c94-94a5-cc4b30fdb16fDISK' , but lock does not exist
2019-10-08 09:58:13,583Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [] Trying to release exclusive lock which does not exist, lock key: 'centos-testvm-024VM_NAME'
2019-10-08 09:58:13,583Z INFO [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [] Lock freed to object 'EngineLock:{exclusiveLocks='[centos-testvm-024=VM_NAME]', sharedLocks='[9ac6f4ad-58d0-4a7e-b424-91f2d76abcac=TEMPLATE, a7e42574-be60-4c94-94a5-cc4b30fdb16f=DISK]'}'
2019-10-08 09:58:13,595Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [] EVENT_ID: USER_ADD_VM_FINISHED_FAILURE(60), Failed to complete VM centos-testvm-024 creation.
2019-10-08 09:58:13,595Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [] Failed invoking callback end method 'onFailed' for command '1b65f576-365d-4e8b-a920-621516cbdaed' with exception 'null', the callback is marked for end method retries
2019-10-08 09:58:23,616Z ERROR [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.AddVmCommand' with failure.
2019-10-08 09:58:23,620Z ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand' with failure.
2019-10-08 09:58:23,627Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [48f2f9bd] Running command: RemoveImageCommand internal: true. Entities affected : ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: Storage
2019-10-08 09:58:23,642Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [48f2f9bd] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'}), log id: 7346a5bd
2019-10-08 09:58:23,663Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [48f2f9bd] EVENT_ID: IRS_BROKER_COMMAND_FAILURE(10,803), VDSM command DeleteImageGroupVDS failed: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:23,663Z ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [48f2f9bd] Command 'DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'})' execution failed: IRSGenericException: IRSErrorException: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:23,663Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [48f2f9bd] FINISH, DeleteImageGroupVDSCommand, return: , log id: 7346a5bd
2019-10-08 09:58:23,663Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [48f2f9bd] Disk 'd680a46a-7188-45f6-b6a7-3333f830c0b4' doesn't exist on storage domain '935de3ac-a735-4fc8-9161-26bfd751ffc7', rolling forward
2019-10-08 09:58:23,682Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [48f2f9bd] Removed task '8483357d-6d4f-418e-9751-70fcb69685cb' from DataBase
2019-10-08 09:58:23,695Z INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [] transaction rolled back
2019-10-08 09:58:23,695Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [] Trying to release a shared lock for key: '9ac6f4ad-58d0-4a7e-b424-91f2d76abcacTEMPLATE' , but lock does not exist
2019-10-08 09:58:23,695Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [] Trying to release a shared lock for key: 'a7e42574-be60-4c94-94a5-cc4b30fdb16fDISK' , but lock does not exist
2019-10-08 09:58:23,695Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [] Trying to release exclusive lock which does not exist, lock key: 'centos-testvm-024VM_NAME'
2019-10-08 09:58:23,695Z INFO [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [] Lock freed to object 'EngineLock:{exclusiveLocks='[centos-testvm-024=VM_NAME]', sharedLocks='[9ac6f4ad-58d0-4a7e-b424-91f2d76abcac=TEMPLATE, a7e42574-be60-4c94-94a5-cc4b30fdb16f=DISK]'}'
2019-10-08 09:58:23,706Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [] EVENT_ID: USER_ADD_VM_FINISHED_FAILURE(60), Failed to complete VM centos-testvm-024 creation.
2019-10-08 09:58:23,706Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-71) [] Failed invoking callback end method 'onFailed' for command '1b65f576-365d-4e8b-a920-621516cbdaed' with exception 'null', the callback is marked for end method retries
2019-10-08 09:58:33,725Z ERROR [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.AddVmCommand' with failure.
2019-10-08 09:58:33,729Z ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotFromTemplateCommand' with failure.
2019-10-08 09:58:33,736Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [3eea0406] Running command: RemoveImageCommand internal: true. Entities affected : ID: 935de3ac-a735-4fc8-9161-26bfd751ffc7 Type: Storage
2019-10-08 09:58:33,752Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [3eea0406] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'}), log id: 6d120001
2019-10-08 09:58:33,767Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [3eea0406] EVENT_ID: IRS_BROKER_COMMAND_FAILURE(10,803), VDSM command DeleteImageGroupVDS failed: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:33,767Z ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [3eea0406] Command 'DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='2e3b3484-c339-11e9-8d02-00163e3ec101', ignoreFailoverLimit='false', storageDomainId='935de3ac-a735-4fc8-9161-26bfd751ffc7', imageGroupId='d680a46a-7188-45f6-b6a7-3333f830c0b4', postZeros='false', discard='false', forceDelete='false'})' execution failed: IRSGenericException: IRSErrorException: Image does not exist in domain: u'image=d680a46a-7188-45f6-b6a7-3333f830c0b4, domain=935de3ac-a735-4fc8-9161-26bfd751ffc7'
2019-10-08 09:58:33,767Z INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [3eea0406] FINISH, DeleteImageGroupVDSCommand, return: , log id: 6d120001
2019-10-08 09:58:33,767Z INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [3eea0406] Disk 'd680a46a-7188-45f6-b6a7-3333f830c0b4' doesn't exist on storage domain '935de3ac-a735-4fc8-9161-26bfd751ffc7', rolling forward
2019-10-08 09:58:33,778Z INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [3eea0406] Removed task 'bfb5e88a-0e62-4e03-b02b-a5a0b36f84db' from DataBase
2019-10-08 09:58:33,791Z INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [] transaction rolled back
2019-10-08 09:58:33,791Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [] Trying to release a shared lock for key: '9ac6f4ad-58d0-4a7e-b424-91f2d76abcacTEMPLATE' , but lock does not exist
2019-10-08 09:58:33,791Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [] Trying to release a shared lock for key: 'a7e42574-be60-4c94-94a5-cc4b30fdb16fDISK' , but lock does not exist
2019-10-08 09:58:33,791Z WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [] Trying to release exclusive lock which does not exist, lock key: 'centos-testvm-024VM_NAME'
2019-10-08 09:58:33,791Z INFO [org.ovirt.engine.core.bll.AddVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [] Lock freed to object 'EngineLock:{exclusiveLocks='[centos-testvm-024=VM_NAME]', sharedLocks='[9ac6f4ad-58d0-4a7e-b424-91f2d76abcac=TEMPLATE, a7e42574-be60-4c94-94a5-cc4b30fdb16f=DISK]'}'
2019-10-08 09:58:33,804Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [] EVENT_ID: USER_ADD_VM_FINISHED_FAILURE(60), Failed to complete VM centos-testvm-024 creation.
2019-10-08 09:58:33,824Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Failed invoking callback end method 'onFailed' for command '1b65f576-365d-4e8b-a920-621516cbdaed' with exception 'null', the callback is marked for end method retries but max number of retries have been attempted. The command will be marked as Failed.
2019-10-08 09:58:33,824Z INFO [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Exception in invoking callback of command AddVm (1b65f576-365d-4e8b-a920-621516cbdaed): NullPointerException:
2019-10-08 09:58:33,824Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Error invoking callback method 'onFailed' for 'FAILED' command '1b65f576-365d-4e8b-a920-621516cbdaed'
2019-10-08 09:58:33,824Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-engineScheduled-Thread-63) [067ec489-ae6c-4871-8ab6-8296016ca1ce] Exception: javax.ejb.EJBTransactionRolledbackException
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:203) [wildfly-ejb3-17.0.1.Final.jar:17.0.1.Final]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:420) [wildfly-ejb3-17.0.1.Final.jar:17.0.1.Final]
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:148) [wildfly-ejb3-17.0.1.Final.jar:17.0.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81) [weld-ejb-3.1.1.Final.jar:3.1.1.Final]
at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [wildfly-ejb3-17.0.1.Final.jar:17.0.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) [wildfly-ejb3-17.0.1.Final.jar:17.0.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) [wildfly-ejb3-17.0.1.Final.jar:17.0.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [wildfly-ejb3-17.0.1.Final.jar:17.0.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-17.0.1.Final.jar:17.0.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) [wildfly-ejb3-17.0.1.Final.jar:17.0.1.Final]
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:618)
at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:81)
at org.ovirt.engine.core.bll.interfaces.BackendInternal$$$view3.endAction(Unknown Source) [bll.jar:]
at sun.reflect.GeneratedMethodAccessor1032.invoke(Unknown Source) [:1.8.0_222]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_222]
at org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:410) [weld-core-impl-3.1.1.Final.jar:3.1.1.Final]
at org.jboss.weld.module.ejb.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:134) [weld-ejb-3.1.1.Final.jar:3.1.1.Final]
at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56) [weld-core-impl-3.1.1.Final.jar:3.1.1.Final]
at org.jboss.weld.module.ejb.InjectionPointPropagatingEnterpriseTargetBeanInstance.invoke(InjectionPointPropagatingEnterpriseTargetBeanInstance.java:68) [weld-ejb-3.1.1.Final.jar:3.1.1.Final]
at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:106) [weld-core-impl-3.1.1.Final.jar:3.1.1.Final]
at org.ovirt.engine.core.bll.BackendCommandObjectsHandler$BackendInternal$BackendLocal$2049259618$Proxy$_$$_Weld$EnterpriseProxy$.endAction(Unknown Source) [bll.jar:]
at org.ovirt.engine.core.bll.VmCommand.endActionOnDisks(VmCommand.java:266) [bll.jar:]
at org.ovirt.engine.core.bll.AddVmCommand.endWithFailure(AddVmCommand.java:1452) [bll.jar:]
at org.ovirt.engine.core.bll.CommandBase.internalEndWithFailure(CommandBase.java:736) [bll.jar:]
at org.ovirt.engine.core.bll.CommandBase.endActionInTransactionScope(CommandBase.java:658) [bll.jar:]
at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2003) [bll.jar:]
at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:202) [utils.jar:]
at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:137) [utils.jar:]
at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:105) [utils.jar:]
at org.ovirt.engine.core.bll.CommandBase.endAction(CommandBase.java:520) [bll.jar:]
at org.ovirt.engine.core.bll.ChildCommandsCallbackBase.endAction(ChildCommandsCallbackBase.java:134) [bll.jar:]
at org.ovirt.engine.core.bll.ChildCommandsCallbackBase.onFailed(ChildCommandsCallbackBase.java:174) [bll.jar:]
at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.endCallback(CommandCallbacksPoller.java:67) [bll.jar:]
at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethodsImpl(CommandCallbacksPoller.java:166) [bll.jar:]
at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods(CommandCallbacksPoller.java:109) [bll.jar:]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [rt.jar:1.8.0_222]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [rt.jar:1.8.0_222]
at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383) [javax.enterprise.concurrent-1.0.jar:]
at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534) [javax.enterprise.concurrent-1.0.jar:]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_222]
at org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250) [javax.enterprise.concurrent-1.0.jar:]
Caused by: java.lang.NullPointerException
Ansible output:
The full traceback is:
Traceback (most recent call last):
File "/var/folders/40/w2c8fp151854mddz_4n3czwm0000gn/T/ansible_ovirt_vm_payload_uy4lqway/__main__.py", line 2024, in main
clone_permissions=module.params['clone_permissions'],
File "/var/folders/40/w2c8fp151854mddz_4n3czwm0000gn/T/ansible_ovirt_vm_payload_uy4lqway/ansible_ovirt_vm_payload.zip/ansible/module_utils/ovirt.py", line 610, in create
poll_interval=self._module.params['poll_interval'],
File "/var/folders/40/w2c8fp151854mddz_4n3czwm0000gn/T/ansible_ovirt_vm_payload_uy4lqway/ansible_ovirt_vm_payload.zip/ansible/module_utils/ovirt.py", line 341, in wait
raise Exception("Timeout exceed while waiting on result state of the entity.")
Exception: Timeout exceed while waiting on result state of the entity.
fatal: [centos-testvm-024.avinity.tv -> localhost]: FAILED! => {
"changed": false,
"invocation": {
"module_args": {
"affinity_group_mappings": [],
"affinity_label_mappings": [],
"allow_partial_import": null,
"ballooning_enabled": null,
"boot_devices": null,
"boot_menu": null,
"cd_iso": null,
"clone": false,
"clone_permissions": false,
"cloud_init": {
"authorized_ssh_keys": "ssh-rsa removed pubkey",
"host_name": "centos-testvm-024.avinity.tv",
"user_name": "centos"
},
"cloud_init_nics": [],
"cloud_init_persist": false,
"cluster": "avshared1",
"cluster_mappings": [],
"comment": "oVirt Template Bakery Validation",
"cpu_cores": null,
"cpu_mode": null,
"cpu_pinning": null,
"cpu_shares": null,
"cpu_sockets": null,
"cpu_threads": null,
"custom_compatibility_version": null,
"custom_properties": null,
"delete_protected": null,
"description": null,
"disk_format": "cow",
"disks": [],
"domain_mappings": [],
"fetch_nested": false,
"force": false,
"graphical_console": null,
"high_availability": null,
"high_availability_priority": null,
"host": null,
"host_devices": null,
"id": null,
"initrd_path": null,
"instance_type": "Medium",
"io_threads": null,
"kernel_params": null,
"kernel_path": null,
"kvm": null,
"lease": null,
"lun_mappings": [],
"memory": null,
"memory_guaranteed": null,
"memory_max": null,
"name": "centos-testvm-024",
"nested_attributes": [],
"nics": [
{
"interface": "virtio",
"name": "nic1",
"profile_name": "tenant1"
}
],
"numa_nodes": [],
"numa_tune_mode": null,
"operating_system": null,
"placement_policy": null,
"poll_interval": 3,
"quota_id": null,
"reassign_bad_macs": null,
"rng_device": null,
"role_mappings": [],
"serial_console": null,
"serial_policy": null,
"serial_policy_value": null,
"smartcard_enabled": null,
"soundcard_enabled": null,
"sso": null,
"state": "running",
"stateless": null,
"storage_domain": null,
"sysprep": null,
"template": "av-centos-75-baseimage_nfs9000",
"template_version": null,
"ticket": null,
"timeout": 180,
"timezone": null,
"type": null,
"usb_support": null,
"use_latest_template_version": null,
"vmware": null,
"vnic_profile_mappings": [],
"wait": true,
"watchdog": null,
"xen": null
}
},
"msg": "Timeout exceed while waiting on result state of the entity."
}
4 years, 6 months
- 3
- 4
ovirt UI update and webproxy server
by kim.kargaard＠noroff.no
Hi,
I want our users to be able to use novnc via the VM portal, so I installed a separate version of the UI, following the information I could find on that process. It is now possible to get the novnc console option in the VM portal, but it seems something with this broke the internal CA for the webproxy, as I get the wonderful:
Disconnected from ConsoleCannot connect to websocket proxy server. Please check your websocket proxy certificate or ask your administrator for help. For further information please refer to the console manual.
Press the 'Connect' button to reconnect the console.
When using the Admin Portal, I of course get a bit more detail and a suggestion to check if websocket proxy server is running, if the firewall is blocking it or if the CA is installed. But, it was working perfectly before the UI update. When I check the status of the websocket proxy on the engine, I see the following:
Active: active (running) since Fri 2019-09-27 10:58:28 CEST; 1 weeks 5 days ago
Main PID: 58139 (ovirt-websocket)
CGroup: /system.slice/ovirt-websocket-proxy.service
└─58139 /usr/bin/python /usr/share/ovirt-engine/services/ovirt-websocket-proxy/ovirt-websocket-proxy.py --systemd=notify start
Oct 09 14:14:00 enginedomain ovirt-websocket[3569]: 2019-10-09 14:14:00,746+0200 ovirt-websocket-proxy: INFO msg:887 handler exception: [Errno 13] Permission denied
Oct 09 14:14:00 enginedomain ovirt-websocket-proxy.py[58139]: ovirt-websocket-proxy[3569] INFO msg:887 handler exception: [Errno 13] Permission denied
Oct 09 14:17:44 enginedomain ovirt-websocket[3855]: 2019-10-09 14:17:44,797+0200 ovirt-websocket-proxy: INFO msg:887 handler exception: [Errno 13] Permission denied
Oct 09 14:17:44 enginedomain ovirt-websocket-proxy.py[58139]: ovirt-websocket-proxy[3855] INFO msg:887 handler exception: [Errno 13] Permission denied
Oct 09 14:21:43 enginedomain ovirt-websocket[4146]: 2019-10-09 14:21:43,126+0200 ovirt-websocket-proxy: INFO msg:887 handler exception: [Errno 13] Permission denied
Oct 09 14:21:43 enginedomain ovirt-websocket-proxy.py[58139]: ovirt-websocket-proxy[4146] INFO msg:887 handler exception: [Errno 13] Permission denied
Oct 09 14:22:25 enginedomain ovirt-websocket[4180]: 2019-10-09 14:22:25,004+0200 ovirt-websocket-proxy: INFO msg:887 handler exception: [Errno 13] Permission denied
Oct 09 14:22:25 enginedomain ovirt-websocket-proxy.py[58139]: ovirt-websocket-proxy[4180] INFO msg:887 handler exception: [Errno 13] Permission denied
Oct 09 14:22:40 enginedomain ovirt-websocket[4206]: 2019-10-09 14:22:40,506+0200 ovirt-websocket-proxy: INFO msg:887 handler exception: [Errno 13] Permission denied
Oct 09 14:22:40 enginedomain ovirt-websocket-proxy.py[58139]: ovirt-websocket-proxy[4206] INFO msg:887 handler exception: [Errno 13] Permission denied
The CA files have not changed permissions, so I am at a bit of a loss. Any suggestions? I checked the ovirt logs, but I struggled to find a log for the websocket proxy, so I can't find a more detailed error log.
I installed ovirt-web-ui-1.6.1-0.20190923.git6ca35b5.el7.noarch.rpm to get the novnc console on the VM portal.
4 years, 6 months
- 1
- 0