Bug 1454843 - [engine-backend] VM creation from template reported false negatively in engine.log
Summary: [engine-backend] VM creation from template reported false negatively in engin...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: ovirt-engine
Classification: oVirt
Component: Backend.Core
Version: 4.2.0
Hardware: x86_64
OS: Unspecified
unspecified
medium
Target Milestone: ovirt-4.1.3
: 4.1.3.3
Assignee: Allon Mureinik
QA Contact: Lucie Leistnerova
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-05-23 14:35 UTC by Elad
Modified: 2017-07-06 13:26 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-07-06 13:26:36 UTC
oVirt Team: Infra
Embargoed:
rule-engine: ovirt-4.1+
rule-engine: exception+
pstehlik: testing_ack+


Attachments (Terms of Use)
engine.log (275.96 KB, application/x-gzip)
2017-05-23 14:35 UTC, Elad
no flags Details


Links
System ID Private Priority Status Summary Last Updated
oVirt gerrit 78054 0 master MERGED core: Remove failure reasons from EngineLock#toString 2017-06-12 14:10:46 UTC
oVirt gerrit 78111 0 ovirt-engine-4.1 MERGED core: Remove failure reasons from EngineLock#toString 2017-06-12 15:57:38 UTC

Description Elad 2017-05-23 14:35:47 UTC
Created attachment 1281585 [details]
engine.log

Description of problem:
VM creation from a template is reported with the following error in engine.log and the operation ends with success.

2017-05-23 17:33:09,244+03 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (default task-30) [2eb46001-f487-41af-ab26-44fbf3a8f38b] Lock Acquired to object 'EngineLock:{exclusiveLocks='[vm1111=<VM_NAME, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='[1c7abfd7-9633-4f81-8f14-2e616c8a9f33=<TEMPLATE, ACTION_TYPE_FAILED_TEMPLATE_IS_USED_FOR_CREATE_VM$VmName vm1111>, 31d915ed-3340-49ca-a341-bb02c6f4d1c0=<DISK, ACTION_TYPE_FAILED_DISK_IS_USED_FOR_CREATE_VM$VmName vm1111>]'}'


Version-Release number of selected component (if applicable):
ovirt-engine-4.2.0-0.0.master.20170519193842.gitf4353fb6.el7.centos.noarch

How reproducible:
100%

Steps to Reproduce:
1. Create VM/VM pool from template

VM creation ends with success with the mentioned error in engine.log

VM creation succeeds:


36854a-ecff-494f-a2ea-a671b2abfa12' child commands '[a8ff104e-e23d-47ac-a1e8-f1ae3ff44a93]' executions were completed, status 'SUCCEEDED'
2017-05-23 17:33:25,265+03 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (DefaultQuartzScheduler3) [2eb46001-f487-41af-ab26-44fbf3a8f38b] Ending command 'org.ovirt.engine.core.bll.AddVmComm
and' successfully.


Additional info:
engine.log

Comment 1 Tal Nisan 2017-05-24 09:44:13 UTC
Elad, this is not an error message, this is the lock message of the shared lock that will be reported in case another operation tries to grab the same lock, this is seen in many other places throughout the system

Comment 2 Elad 2017-05-24 12:05:01 UTC
Tal, this message indicated on a failure for VM creation. 
Please fix this issue, improve the logging.

Comment 3 Elad 2017-06-09 11:05:53 UTC
Please improve the logging

Comment 4 Allon Mureinik 2017-06-11 07:04:36 UTC
Martin - this isn't a storage issue - any lock acquired in any command will print a similar log message when acquiring the log.
As to Elad's point, since the items in the exclusive/shared locks maps are the names of the error messages that will be produced in case acquiring the lock fails. Perhaps it's worthwhile removing those messages from the log?

Moving BZ to infra, as any solution will have to be system-wide, and not only for the storage commands.

Comment 5 Allon Mureinik 2017-06-11 08:08:00 UTC
(In reply to Allon Mureinik from comment #4)
> Martin - this isn't a storage issue - any lock acquired in any command will
> print a similar log message when acquiring the log.
> As to Elad's point, since the items in the exclusive/shared locks maps are
> the names of the error messages that will be produced in case acquiring the
> lock fails. Perhaps it's worthwhile removing those messages from the log?
> 
> Moving BZ to infra, as any solution will have to be system-wide, and not
> only for the storage commands.
Martin, the attached patch suggests an implementation of this idea so we have something concrete to discuss. If you think this is a good approach, feel free to assign the BZ to me. If you think this approach is wrong, let me know, and I'll abandon the patch.

Comment 6 Martin Perina 2017-06-12 13:04:27 UTC
I think it's great, thanks for the fix

Comment 7 Allon Mureinik 2017-06-12 13:44:50 UTC
Wrong window, please ignore the noise.

Comment 8 Martin Perina 2017-06-12 19:27:47 UTC
Allon, AFAIK there will no more 4.1.3 builds, only for super blockers, so isn't 4.1.4 the right version?

Comment 9 Allon Mureinik 2017-06-13 06:41:41 UTC
The patch is merge to the 4.1.z branch. IIUC, there's another build planned to include a couple of blockers, so this should be respun in there too.

If it's not, I'll adjust the target to 4.1.4

Comment 10 Martin Perina 2017-06-14 13:23:16 UTC
Moving back to 4.1.3 as it's part of 4.1.3.3 build

Comment 11 Martin Perina 2017-06-16 17:03:16 UTC
Included in 4.1.3.4 tag, so moving to ON_QA

Comment 12 Lucie Leistnerova 2017-06-26 12:15:39 UTC
There is no error variable in info about locking. The error variable is properly used in error by lock validation.

verified in ovirt-engine-4.1.3.5-0.1.el7.noarch


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