Bug 1467099 - Creation of template from a VM with snapshot fail
Creation of template from a VM with snapshot fail
Status: CLOSED WORKSFORME
Product: ovirt-engine
Classification: oVirt
Component: BLL.Storage (Show other bugs)
4.1.3.5
Unspecified Unspecified
unspecified Severity low (vote)
: ovirt-4.2.0
: ---
Assigned To: Fred Rolland
Raz Tamir
: Automation
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2017-07-02 14:45 EDT by Raz Tamir
Modified: 2017-09-12 09:42 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2017-09-12 09:42:23 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Storage
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
rule-engine: ovirt‑4.2+


Attachments (Terms of Use)
engine.log (2.88 MB, application/x-gzip)
2017-07-02 14:45 EDT, Raz Tamir
no flags Details

  None (edit)
Description Raz Tamir 2017-07-02 14:45:24 EDT
Created attachment 1293676 [details]
engine.log

Description of problem:
Happened in our automation tier 3.
* Couldn't reproduce *

Creation of template from VM with snapshot failed

From engine.log:

2017-06-30 16:16:22,672+03 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-33) [templates_create_f0ca58db-31d2-43da] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'CreateAllTemplateDisks' completed, handling the result.
2017-06-30 16:16:22,672+03 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-33) [templates_create_f0ca58db-31d2-43da] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'CreateAllTemplateDisks' succeeded, clearing tasks.
2017-06-30 16:16:22,672+03 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-33) [templates_create_f0ca58db-31d2-43da] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 'de0b270c-d885-4b95-bbae-b73ec3c75404'
2017-06-30 16:16:22,676+03 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-33) [templates_create_f0ca58db-31d2-43da] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId='8be71a8d-4e55-4c18-a66b-c66c3027cb7b', ignoreFailoverLimit='false', taskId='de0b270c-d885-4b95-bbae-b73ec3c75404'}), log id: 5d9fcc20
2017-06-30 16:16:22,690+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-33) [templates_create_f0ca58db-31d2-43da] START, HSMClearTaskVDSCommand(HostName = host_mixed_1, HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', hostId='9686dd2d-ee47-4c7b-ad23-6d5ffd5bfabd', taskId='de0b270c-d885-4b95-bbae-b73ec3c75404'}), log id: 38590886
2017-06-30 16:16:23,641+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-33) [templates_create_f0ca58db-31d2-43da] FINISH, HSMClearTaskVDSCommand, log id: 38590886
2017-06-30 16:16:23,641+03 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-33) [templates_create_f0ca58db-31d2-43da] FINISH, SPMClearTaskVDSCommand, log id: 5d9fcc20
2017-06-30 16:16:23,670+03 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-33) [templates_create_f0ca58db-31d2-43da] BaseAsyncTask::removeTaskFromDB: Removed task 'de0b270c-d885-4b95-bbae-b73ec3c75404' from DataBase
2017-06-30 16:16:23,670+03 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-33) [templates_create_f0ca58db-31d2-43da] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '2daf903a-a2de-4b6a-b1f5-871689fee9b5'
2017-06-30 16:16:23,739+03 ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (DefaultQuartzScheduler9) [templates_create_f0ca58db-31d2-43da] Error invoking callback method 'doPolling' for 'ACTIVE' command '57f232c4-e1b8-44f1-92f3-c000e27a8c78'
2017-06-30 16:16:23,740+03 ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (DefaultQuartzScheduler9) [templates_create_f0ca58db-31d2-43da] Exception: java.util.ConcurrentModificationException
        at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:901) [rt.jar:1.8.0_131]
        at java.util.ArrayList$Itr.next(ArrayList.java:851) [rt.jar:1.8.0_131]
        at org.ovirt.engine.core.bll.ChildCommandsCallbackBase.doPolling(ChildCommandsCallbackBase.java:36) [bll.jar:]
        at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods(CommandCallbacksPoller.java:114) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor124.invoke(Unknown Source) [:1.8.0_131]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_131]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_131]
        at org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:83) [scheduler.jar:]
        at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:55) [scheduler.jar:]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz.jar:]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [rt.jar:1.8.0_131]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
        at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_131]

2017-06-30 16:16:24,836+03 ERROR [org.ovirt.engine.core.bll.AddVmTemplateCommand] (DefaultQuartzScheduler6) [templates_create_f0ca58db-31d2-43da] Ending command 'org.ovirt.engine.core.bll.AddVmTemplateCommand' with failure.
2017-06-30 16:16:24,848+03 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (DefaultQuartzScheduler6) [templates_create_f0ca58db-31d2-43da] START, SetVmStatusVDSCommand( SetVmStatusVDSCommandParameters:{runAsync='true', vmId='b7acb00a-c321-44e2-85b6-f19b3aed8a59', status='Down', exitStatus='Normal'}), log id: 5ba67092
2017-06-30 16:16:24,853+03 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (DefaultQuartzScheduler6) [templates_create_f0ca58db-31d2-43da] FINISH, SetVmStatusVDSCommand, log id: 5ba67092
2017-06-30 16:16:24,865+03 INFO  [org.ovirt.engine.core.bll.AddVmTemplateCommand] (DefaultQuartzScheduler6) [templates_create_f0ca58db-31d2-43da] Lock freed to object 'EngineLock:{exclusiveLocks='[5b347ca9-40f1-4f31-b441-af1421cfbd75=DISK, 11607_template_preallocated=TEMPLATE_NAME, 7efb0d4f-72f0-4f18-8d83-be1ec5c10403=TEMPLATE]', sharedLocks='[b7acb00a-c321-44e2-85b6-f19b3aed8a59=VM]'}'
2017-06-30 16:16:24,883+03 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler6) [templates_create_f0ca58db-31d2-43da] EVENT_ID: USER_ADD_VM_TEMPLATE_CREATE_TEMPLATE_FAILURE(1,322), Correlation ID: templates_create_f0ca58db-31d2-43da, Job ID: 03cbf7b0-be18-4543-a3a5-33e89b06715a, Call Stack: null, Custom Event ID: -1, Message: Failed to create Template 11607_template_preallocated or its disks from VM vm_prealloc_disk_image_11607.



Version-Release number of selected component (if applicable):
ovirt-engine-4.1.3.5-0.1.el7.noarch
vdsm-4.19.20-1.el7ev.x86_64

How reproducible:
Only once in our automation

Steps to Reproduce:
1. Create a VM with 1 raw preallocated disk and size 64GB
2. Create a snapshot
3. Create a template

Actual results:
Template creation failed

Expected results:


Additional info:
Comment 1 Allon Mureinik 2017-07-02 16:32:30 EDT
Tentatively targeting to 4.2 since we don't have a reproducer. If we have a reliable reproducer, we should consider retargetting.
Comment 2 Allon Mureinik 2017-09-12 09:42:23 EDT
Neither dev nor QE can reproduce this, and the stacktrace comes from the Quartz implementation that has since been removed.
I'm closing this bug, but please reopen if you can reproduce it.

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