Bug 1396960 - Live Snapshot creation fails with "Failed to complete snapshot" event
Summary: Live Snapshot creation fails with "Failed to complete snapshot" event
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: ovirt-engine
Classification: oVirt
Component: BLL.Storage
Version: 4.1.0
Hardware: x86_64
OS: Linux
unspecified
urgent vote
Target Milestone: ovirt-4.1.0-alpha
: ---
Assignee: Daniel Erez
QA Contact: Raz Tamir
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-11-21 09:48 UTC by Avihai
Modified: 2017-02-15 15:00 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-02-15 15:00:15 UTC
oVirt Team: Storage
rule-engine: ovirt-4.1+
rule-engine: blocker+
tnisan: devel_ack+


Attachments (Terms of Use)
engine&vdsm logs files (558.29 KB, application/x-gzip)
2016-11-21 09:48 UTC, Avihai
no flags Details


Links
System ID Private Priority Status Summary Last Updated
oVirt gerrit 67806 0 'None' MERGED vm: snapshot: fix xml formatting 2020-11-09 18:32:11 UTC

Description Avihai 2016-11-21 09:48:27 UTC
Created attachment 1222349 [details]
engine&vdsm logs files

Description of problem:
Snapshot creation fails with "Failed to complete snapshot" error


Version-Release number of selected component (if applicable):
4.1.0-0.0.master.20161025055056.el7.centos

How reproducible:
100%


Steps to Reproduce:
1.create iscsi domain
2.create VM1 from that domain (create from 
3.add additional disk(not OS) with 1G size to  VM1
4.create snapshot

Actual results:
Snapshot should be created successfully without ant events .
IO should be redirected to new created snapshot & base disk should become RO.


Expected results:
creation fails with "Failed to complete snapshot" event .
It looks like the new snapshot is created but not recognized & the IO does not shift from base disk to new snapshot . 

From Engine log errors appear:
2016-11-21 11:23:25,866 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [4596a489] START, SnapshotVDSCommand(HostName = camel_vdsb, SnapshotVDSCommandParameters:{runAsync='true', hostId='4d791ab5-9eb9-4f77-8b09-d66337f3ef12', vmId='96205fb7-ddd5-4b67-b128-8973cbcf0fe6'}), log id: 45c8114d
2016-11-21 11:23:26,881 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [4596a489] Failed in 'SnapshotVDS' method
2016-11-21 11:23:26,893 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler6) [4596a489] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM camel_vdsb command failed: Snapshot failed
2016-11-21 11:23:26,893 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [4596a489] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand' return value 'StatusOnlyReturnForXmlRpc [status=StatusForXmlRpc [code=48, message=Snapshot failed]]'
2016-11-21 11:23:26,893 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [4596a489] HostName = camel_vdsb
2016-11-21 11:23:26,894 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [4596a489] Command 'SnapshotVDSCommand(HostName = camel_vdsb, SnapshotVDSCommandParameters:{runAsync='true', hostId='4d791ab5-9eb9-4f77-8b09-d66337f3ef12', vmId='96205fb7-ddd5-4b67-b128-8973cbcf0fe6'})' execution failed: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48
2016-11-21 11:23:26,894 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [4596a489] FINISH, SnapshotVDSCommand, log id: 45c8114d
2016-11-21 11:23:26,894 WARN  [org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand] (DefaultQuartzScheduler6) [4596a489] Could not perform live snapshot due to error, VM will still be configured to the new created snapshot: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48 (Failed with error SNAPSHOT_FAILED and code 48)
2016-11-21 11:23:26,912 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler6) [4596a489] Correlation ID: 38f7f9d4-9b55-4a62-b1b6-aef81c06dda6, Job ID: d6deeb60-c496-499a-a9b3-649c1b81d7ee, Call Stack: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48 (Failed with error SNAPSHOT_FAILED and code 48)
	at org.ovirt.engine.core.bll.VdsHandler.handleVdsResult(VdsHandler.java:116)
	at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFrontendImpl.java:33)
	at org.ovirt.engine.core.bll.CommandBase.runVdsCommand(CommandBase.java:2145)
	at org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand.lambda$performLiveSnapshot$1(CreateAllSnapshotsFromVmCommand.java:481)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:164)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:103)
	at org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand.performLiveSnapshot(CreateAllSnapshotsFromVmCommand.java:480)
	at org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand.endVmCommand(CreateAllSnapshotsFromVmCommand.java:402)
	at org.ovirt.engine.core.bll.VmCommand.endSuccessfully(VmCommand.java:224)
	at org.ovirt.engine.core.bll.CommandBase.internalEndSuccessfully(CommandBase.java:726)
	at org.ovirt.engine.core.bll.CommandBase.endActionInTransactionScope(CommandBase.java:684)
	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2044)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:202)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:137)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:105)
	at org.ovirt.engine.core.bll.CommandBase.endAction(CommandBase.java:549)
	at org.ovirt.engine.core.bll.ChildCommandsCallbackBase.endAction(ChildCommandsCallbackBase.java:120)
	at org.ovirt.engine.core.bll.ChildCommandsCallbackBase.onSucceeded(ChildCommandsCallbackBase.java:143)
	at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.endCallback(CommandCallbacksPoller.java:57)
	at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods(CommandCallbacksPoller.java:108)
	at sun.reflect.GeneratedMethodAccessor67.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:77)
	at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:51)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48
	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createDefaultConcreteException(VdsBrokerCommand.java:76)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.createException(BrokerCommandBase.java:222)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:192)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand.executeVdsBrokerCommand(SnapshotVDSCommand.java:25)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:111)
	at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:73)
	at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.DefaultVdsCommandExecutor.execute(DefaultVdsCommandExecutor.java:14)
	at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:413)
	... 30 more
, Custom Event ID: -1, Message: Failed to create live snapshot 'snap2' for VM 'vm1'. VM restart is recommended. Note that using the created snapshot might cause data inconsistency.
2016-11-21 11:23:26,945 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotCommand] (DefaultQuartzScheduler6) [4596a489] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotCommand' successfully.
2016-11-21 11:23:26,962 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (DefaultQuartzScheduler6) [4596a489] START, GetImageInfoVDSCommand( GetImageInfoVDSCommandParameters:{runAsync='true', storagePoolId='c7006a66-c997-4e44-ba85-6b2d5e2e6e5c', ignoreFailoverLimit='false', storageDomainId='64f8d460-9430-4dc8-82b5-8b6146c1537b', imageGroupId='e79d8dad-5d8e-4893-bc4d-eafd6ba81ddd', imageId='3a504a0a-eca5-4987-88d6-b47f03d0c583'}), log id: 654f6a32
2016-11-21 11:23:26,963 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (DefaultQuartzScheduler6) [4596a489] START, GetVolumeInfoVDSCommand(HostName = camel_vdsc, GetVolumeInfoVDSCommandParameters:{runAsync='true', hostId='10ed12bf-344c-4a61-9616-c9554ba22c5f', storagePoolId='c7006a66-c997-4e44-ba85-6b2d5e2e6e5c', storageDomainId='64f8d460-9430-4dc8-82b5-8b6146c1537b', imageGroupId='e79d8dad-5d8e-4893-bc4d-eafd6ba81ddd', imageId='3a504a0a-eca5-4987-88d6-b47f03d0c583'}), log id: 5dff4cb4
2016-11-21 11:23:28,164 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (DefaultQuartzScheduler6) [4596a489] FINISH, GetVolumeInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@b80e066a, log id: 5dff4cb4
2016-11-21 11:23:28,165 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (DefaultQuartzScheduler6) [4596a489] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@b80e066a, log id: 654f6a32
2016-11-21 11:23:28,224 INFO  [org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand] (DefaultQuartzScheduler6) [] Lock freed to object 'EngineLock:{exclusiveLocks='[96205fb7-ddd5-4b67-b128-8973cbcf0fe6=<VM, ACTION_TYPE_FAILED_SNAPSHOT_IS_BEING_TAKEN_FOR_VM$VmName vm1>]', sharedLocks='null'}'
2016-11-21 11:23:28,239 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler6) [] Correlation ID: 38f7f9d4-9b55-4a62-b1b6-aef81c06dda6, Job ID: d6deeb60-c496-499a-a9b3-649c1b81d7ee, Call Stack: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48 (Failed with error SNAPSHOT_FAILED and code 48)
	at org.ovirt.engine.core.bll.VdsHandler.handleVdsResult(VdsHandler.java:116)
	at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFrontendImpl.java:33)
	at org.ovirt.engine.core.bll.CommandBase.runVdsCommand(CommandBase.java:2145)
	at org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand.lambda$performLiveSnapshot$1(CreateAllSnapshotsFromVmCommand.java:481)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:164)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:103)
	at org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand.performLiveSnapshot(CreateAllSnapshotsFromVmCommand.java:480)
	at org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand.endVmCommand(CreateAllSnapshotsFromVmCommand.java:402)
	at org.ovirt.engine.core.bll.VmCommand.endSuccessfully(VmCommand.java:224)
	at org.ovirt.engine.core.bll.CommandBase.internalEndSuccessfully(CommandBase.java:726)
	at org.ovirt.engine.core.bll.CommandBase.endActionInTransactionScope(CommandBase.java:684)
	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2044)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:202)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:137)
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:105)
	at org.ovirt.engine.core.bll.CommandBase.endAction(CommandBase.java:549)
	at org.ovirt.engine.core.bll.ChildCommandsCallbackBase.endAction(ChildCommandsCallbackBase.java:120)
	at org.ovirt.engine.core.bll.ChildCommandsCallbackBase.onSucceeded(ChildCommandsCallbackBase.java:143)
	at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.endCallback(CommandCallbacksPoller.java:57)
	at org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods(CommandCallbacksPoller.java:108)
	at sun.reflect.GeneratedMethodAccessor67.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:77)
	at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:51)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48
	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createDefaultConcreteException(VdsBrokerCommand.java:76)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.createException(BrokerCommandBase.java:222)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:192)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand.executeVdsBrokerCommand(SnapshotVDSCommand.java:25)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:111)
	at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:73)
	at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
	at org.ovirt.engine.core.vdsbroker.vdsbroker.DefaultVdsCommandExecutor.execute(DefaultVdsCommandExecutor.java:14)
	at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:413)
	... 30 more
, Custom Event ID: -1, Message: Failed to complete snapshot 'snap2' creation for VM 'vm1'.
2016-11-21 11:23:28,240 WARN  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler6) [] Command 'CreateAllSnapshotsFromVm' id: 'f142b7c5-84ae-41bf-9469-4effe6abd78c' end method execution failed, as the command isn't marked for endAction() retries silently ignoring


From VDSM log error appear:
2016-11-21 11:23:18,347 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.01 seconds (__init__:515)
2016-11-21 11:23:25,868 ERROR (jsonrpc/4) [virt.vm] (vmId='96205fb7-ddd5-4b67-b128-8973cbcf0fe6') The base volume doesn't exist: {'device': 'disk', 'domainID': '64f8d460-9430-4dc8-82b5-8b6146c1537b', 'volumeID': 'cb89ecd6-bdd3-464e-86be-9b61c82ecfe9', 'imageID': 'e79d8dad-5d8e-4893-bc4d-eafd6ba81ddd'} (vm:3296)




Additional info:

Comment 1 Allon Mureinik 2016-11-24 10:45:12 UTC
Bizzare:

2016-11-21 11:04:08,161 ERROR (jsonrpc/3) [jsonrpc.JsonRpcServer] Internal server error (__init__:552)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 547, in _handle_request
    res = method(**params)
  File "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 202, in _dynamicMethod
    result = fn(*methodArgs)
  File "/usr/share/vdsm/API.py", line 760, in snapshot
    return v.snapshot(snapDrives, memoryParams, frozen=frozen)
  File "/usr/share/vdsm/virt/vm.py", line 3368, in snapshot
    snapxml = snap.toprettyxml()
  File "/usr/share/vdsm/virt/vmxml.py", line 316, in __getattr__
    return getattr(self._elem, name)
AttributeError: 'Element' object has no attribute 'toprettyxml'

Comment 2 Allon Mureinik 2016-11-24 10:49:24 UTC
On second thought, while that's probably a bug, it doesn't seem related to this issue.
Further along in vdsm.log, we can see:

016-11-21 11:23:25,868 ERROR (jsonrpc/4) [virt.vm] (vmId='96205fb7-ddd5-4b67-b128-8973cbcf0fe6') The base volume doesn't exist: {'device': 'disk', 'domainID': '64f8d460-9430-4dc8-82b5-8b6146c1537b', 'volumeID': 'cb89ecd6-bdd3-464e-86be-9b61c82ecfe9', 'imageID': 'e79d8dad-5d8e-4893-bc4d-eafd6ba81ddd'} (vm:3296)
2016-11-21 11:23:25,869 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call VM.snapshot failed (error 48) in 0.00 seconds (__init__:515)

Comment 3 Raz Tamir 2016-11-30 17:12:41 UTC
Added 'AutomationBlocker' flag because this is blocks also
- Live Storage Migration
- Live snapshot
- RAM snapshot

Comment 4 Red Hat Bugzilla Rules Engine 2016-11-30 17:12:47 UTC
This bug report has Keywords: Regression or TestBlocker.
Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release. Please resolve ASAP.

Comment 5 Lucie Leistnerova 2016-12-01 10:08:55 UTC
I ran into similar problem with standard created VM, one disk with RHEL 7.3. In log and alerts is error, but snapshot with memory is created and looks OK. Then there are problems running this VM with previewed snapshot. 

creating snapshot:

engine.log
2016-12-01 11:04:40,603+01 WARN  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [5750eab] Unexpected return value: StatusForXmlRpc [code=-32603, message='Element' object has no attribute 'toprettyxml']
2016-12-01 11:04:40,603+01 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [5750eab] Failed in 'SnapshotVDS' method
2016-12-01 11:04:40,604+01 WARN  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [5750eab] Unexpected return value: StatusForXmlRpc [code=-32603, message='Element' object has no attribute 'toprettyxml']
2016-12-01 11:04:40,609+01 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler6) [5750eab] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM vmhost07 command failed: 'Element' object has no attribute 'toprettyxml'
2016-12-01 11:04:40,609+01 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (DefaultQuartzScheduler6) [5750eab] Command 'SnapshotVDSCommand(HostName = vmhost07, SnapshotVDSCommandParameters:{runAsync='true', hostId='82cb7194-c598-4e6d-ace0-a2d7a5b97651', vmId='710e78db-65c9-4c46-90a9-a023541aeb64'})' execution failed: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = 'Element' object has no attribute 'toprettyxml', code = -32603

vdsm.log
same as in Comment 1

on the first run:

2016-12-01 10:59:43,744+01 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-6) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm3-41-01 is down with error. Exit message: Wake up from hibernation failed:'_srcDomXML'.
2016-12-01 10:59:43,751+01 ERROR [org.ovirt.engine.core.vdsbroker.monitoring.VmsMonitoring] (ForkJoinPool-1-worker-6) [] Rerun VM '710e78db-65c9-4c46-90a9-a023541aeb64'. Called from VDS 'vmhost07'
2016-12-01 10:59:43,794+01 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-30) [] Correlation ID: 99270d8a-8f4b-4038-a328-61f2628ae867, Job ID: 09e25d2c-4896-4073-85af-dcfb72f8a68d, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM vm3-41-01 on Host vmhost07.
2016-12-01 10:59:43,853+01 WARN  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-6-thread-30) [] Validation of action 'RunVm' failed for user admin@internal-authz. Reasons: VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,SCHEDULING_NO_HOSTS
2016-12-01 10:59:43,866+01 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-30) [] Correlation ID: 99270d8a-8f4b-4038-a328-61f2628ae867, Job ID: 09e25d2c-4896-4073-85af-dcfb72f8a68d, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM vm3-41-01 (User: admin@internal-authz).

or

2016-12-01 10:48:21,673+01 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-9) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm3-41-03 is down with error. Exit message: Wake up from hibernation failed:'MutableDomainDescriptor' object has no attribute '_devices'.


on the second run the VM starts.

If engine says that it fails to create snapshot then the snapshot should not be functional.

testing in
ovirt-engine-4.1.0-0.0.master.20161201071307.gita5ff876.el7.centos.noarch
vdsm-4.18.999-1020.git1ff41b1.el7.centos.x86_64

Comment 6 Yaniv Kaul 2016-12-01 18:07:03 UTC
I'm not sure I understand why it was postponed to 4.0.7 (no reason given or I've missed it) - looks like a blocker to me.
Allon?

Comment 7 Allon Mureinik 2016-12-02 01:01:08 UTC
(In reply to Yaniv Kaul from comment #6)
> I'm not sure I understand why it was postponed to 4.0.7 (no reason given or
> I've missed it) - looks like a blocker to me.
> Allon?

When I targetted the BZ for 4.0.7, 4.0.6 was supposed to have been released already.
If we want to keep working on 4.0.6, sure, this should be in there too.

Comment 8 Tal Nisan 2016-12-06 13:41:41 UTC
Upon investigation by Daniel it appears that this issue occurs only on master and was fixed there already, moving to MODIFIED so it will be verified on the next build.

Comment 9 Raz Tamir 2017-01-11 08:17:25 UTC
Verified on - ovirt-engine 4.1.0-0.4.master.20170109112129.git05e2d0d.el7.centos


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