You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Chandan Purushothama (JIRA)" <ji...@apache.org> on 2013/10/16 00:34:42 UTC
[jira] [Closed] (CLOUDSTACK-1700) VMSnapshot: In spite of
CreateVMSnapshotCmd failure - Async Job is reported as a success instead of
failure
[ https://issues.apache.org/jira/browse/CLOUDSTACK-1700?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Chandan Purushothama closed CLOUDSTACK-1700.
--------------------------------------------
Verified on 4.2 Build.
2013-10-15 15:25:59,357 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-1:null) submit async job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ], details: AsyncJobVO {id:299, userId: 56, accountId: 53, sessionKey: null, instanceType: None, instanceId: 2, cmd: org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"yHWC3hWT3DB43fZ091UEiv6PeeE\u003d","virtualmachineid":"f0bce37c-76ab-4467-be58-5b6e3a2a1c09","cmdEventType":"VMSNAPSHOT.CREATE","ctxUserId":"56","snapshotmemory":"true","httpmethod":"GET","response":"json","id":"2","description":"VMSnapshot-Xen-2","name":"VMSnapshot-Xen-2","_":"1381876358087","ctxAccountId":"53","ctxStartEventId":"1389"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 7471666038533, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-10-15 15:25:59,359 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===END=== 10.214.5.31 -- GET command=createVMSnapshot&virtualmachineid=f0bce37c-76ab-4467-be58-5b6e3a2a1c09&snapshotmemory=true&name=VMSnapshot-Xen-2&description=VMSnapshot-Xen-2&response=json&sessionkey=yHWC3hWT3DB43fZ091UEiv6PeeE%3D&_=1381876358087
2013-10-15 15:25:59,360 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-5:job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]) Executing org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd for job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]
2013-10-15 15:25:59,369 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-5:job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]) Access to Acct[3139550d-90e8-405e-b3de-55464d4a868c-atoms] granted to Acct[3139550d-90e8-405e-b3de-55464d4a868c-atoms] by DomainChecker_EnhancerByCloudStack_dfb5cff0
2013-10-15 15:25:59,394 DEBUG [agent.transport.Request] (Job-Executor-5:job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]) Seq 7-1737949249: Sending { Cmd , MgmtId: 7471666038533, via: 7, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CreateVMSnapshotCommand":{"vmState":"Running","volumeTOs":[{"id":116,"name":"ROOT-88","path":"f1d9400e-6a0d-467a-bbe5-57226fdd3040","size":21474836480,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"c2e14a53-b7de-3abe-a9b0-f030c691b56d","deviceId":0,"chainSize":120045568}],"target":{"id":2,"snapshotName":"i-53-88-MyTestVM_VS_20131015222559","type":"DiskAndMemory","current":false,"description":"VMSnapshot-Xen-2","parent":{"id":1,"snapshotName":"i-53-88-MyTestVM_VS_20131015222513","type":"Disk","createTime":1381875913000,"current":true,"description":"VMSnapshot-Xen-1"}},"vmName":"i-53-88-MyTestVM","guestOSType":"CentOS 5.3 (64-bit)","wait":1800}}] }
2013-10-15 15:25:59,394 DEBUG [agent.transport.Request] (Job-Executor-5:job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]) Seq 7-1737949249: Executing: { Cmd , MgmtId: 7471666038533, via: 7, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CreateVMSnapshotCommand":{"vmState":"Running","volumeTOs":[{"id":116,"name":"ROOT-88","path":"f1d9400e-6a0d-467a-bbe5-57226fdd3040","size":21474836480,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"c2e14a53-b7de-3abe-a9b0-f030c691b56d","deviceId":0,"chainSize":120045568}],"target":{"id":2,"snapshotName":"i-53-88-MyTestVM_VS_20131015222559","type":"DiskAndMemory","current":false,"description":"VMSnapshot-Xen-2","parent":{"id":1,"snapshotName":"i-53-88-MyTestVM_VS_20131015222513","type":"Disk","createTime":1381875913000,"current":true,"description":"VMSnapshot-Xen-1"}},"vmName":"i-53-88-MyTestVM","guestOSType":"CentOS 5.3 (64-bit)","wait":1800}}] }
2013-10-15 15:25:59,395 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-45:null) Seq 7-1737949249: Executing request
2013-10-15 15:25:59,594 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===START=== 10.214.5.31 -- GET command=listZones&id=52e342e1-6640-4d77-a12b-76c1cf37d64f&response=json&sessionkey=yHWC3hWT3DB43fZ091UEiv6PeeE%3D&_=1381876358477
2013-10-15 15:25:59,607 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===END=== 10.214.5.31 -- GET command=listZones&id=52e342e1-6640-4d77-a12b-76c1cf37d64f&response=json&sessionkey=yHWC3hWT3DB43fZ091UEiv6PeeE%3D&_=1381876358477
2013-10-15 15:25:59,624 WARN [xen.resource.CitrixResourceBase] (DirectAgent-45:null) Task failed! Task record: uuid: 294e1e24-7b67-7ee0-86cf-d6e4c2b26951
nameLabel: Async.VM.checkpoint
nameDescription:
allowedOperations: []
currentOperations: {}
created: Tue Oct 15 11:24:19 PDT 2013
finished: Tue Oct 15 11:24:19 PDT 2013
status: failure
residentOn: com.xensource.xenapi.Host@2e966f5e
progress: 1.0
type: <none/>
result:
errorInfo: [LICENCE_RESTRICTION]
otherConfig: {CS_VM_SNAPSHOT_KEY=i-53-88-MyTestVM_VS_20131015222559}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
2013-10-15 15:25:59,632 ERROR [xen.resource.CitrixResourceBase] (DirectAgent-45:null) Creating VM Snapshot i-53-88-MyTestVM_VS_20131015222559 failed due to: LICENCE_RESTRICTION
2013-10-15 15:25:59,632 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-45:null) Seq 7-1737949249: Response Received:
2013-10-15 15:25:59,632 DEBUG [agent.transport.Request] (DirectAgent-45:null) Seq 7-1737949249: Processing: { Ans: , MgmtId: 7471666038533, via: 7, Ver: v1, Flags: 10, [{"com.cloud.agent.api.CreateVMSnapshotAnswer":{"result":false,"details":"LICENCE_RESTRICTION","wait":0}}] }
2013-10-15 15:25:59,632 DEBUG [agent.transport.Request] (Job-Executor-5:job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]) Seq 7-1737949249: Received: { Ans: , MgmtId: 7471666038533, via: 7, Ver: v1, Flags: 10, { CreateVMSnapshotAnswer } }
2013-10-15 15:25:59,632 ERROR [vm.snapshot.VMSnapshotManagerImpl] (Job-Executor-5:job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]) Creating VM snapshot: i-53-88-MyTestVM_VS_20131015222559 failed due to LICENCE_RESTRICTION
2013-10-15 15:25:59,661 ERROR [vm.snapshot.VMSnapshotManagerImpl] (Job-Executor-5:job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]) Create vm snapshot i-53-88-MyTestVM_VS_20131015222559 failed for vm: i-53-88-MyTestVM due to Creating VM snapshot: i-53-88-MyTestVM_VS_20131015222559 failed due to LICENCE_RESTRICTION
2013-10-15 15:25:59,668 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-5:job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]) Unexpected exception while executing org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd
com.cloud.utils.exception.CloudRuntimeException: Creating VM snapshot: i-53-88-MyTestVM_VS_20131015222559 failed due to LICENCE_RESTRICTION
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.createVmSnapshotInternal(VMSnapshotManagerImpl.java:406)
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.creatVMSnapshot(VMSnapshotManagerImpl.java:356)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd.execute(CreateVMSnapshotCmd.java:100)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2013-10-15 15:25:59,670 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-5:job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ]) Complete async job-299 = [ 863abf9f-50df-48eb-80dc-23037fbe9286 ], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Creating VM snapshot: i-53-88-MyTestVM_VS_20131015222559 failed due to LICENCE_RESTRICTION
> VMSnapshot: In spite of CreateVMSnapshotCmd failure - Async Job is reported as a success instead of failure
> -----------------------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-1700
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-1700
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Management Server
> Affects Versions: 4.2.0
> Reporter: Chandan Purushothama
> Assignee: Chandan Purushothama
> Fix For: 4.2.0
>
>
> ======================
> Steps to Reproduce the Bug:
> ======================
> 1. CreateVMSnapshot on a VM running on a XenServer that has evaluation license
> ===========
> Observations:
> ===========
> **JobStatus = 1 implies Success . Observe the Management Server Log Snippet below**
> 2013-03-15 17:40:34,781 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-5:null) submit async job-108, details: AsyncJobVO {id:108, userId: 3, accountId: 3, sessionKey: null, instanceType: null, instanceId: 18, cmd: org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd, cmdOriginator: null, cmdInfo: {"id":"18","response":"json","sessionkey":"vrHJOCEZnUh0hUqgBw0EUdEvjqs\u003d","virtualmachineid":"41fce8fd-9fdf-4f2f-bf04-c7173f2e3c2a","ctxUserId":"3","snapshotmemory":"true","description":"Xen-boron-VMSnapshot-7-1","name":"Xen-boron-VMSnapshot-7-1","_":"1363394459368","ctxAccountId":"3","ctxStartEventId":"164"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 7200344900649, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-03-15 17:40:34,783 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===END=== 10.216.133.69 -- GET command=createVMSnapshot&virtualmachineid=41fce8fd-9fdf-4f2f-bf04-c7173f2e3c2a&snapshotmemory=true&name=Xen-boron-VMSnapshot-7-1&description=Xen-boron-VMSnapshot-7-1&response=json&sessionkey=vrHJOCEZnUh0hUqgBw0EUdEvjqs%3D&_=1363394459368
> 2013-03-15 17:40:34,784 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-5:job-108) Executing org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd for job-108
> 2013-03-15 17:40:34,793 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-5:job-108) Access to Acct[3-boron] granted to Acct[3-boron] by DomainChecker
> 2013-03-15 17:40:34,844 DEBUG [agent.transport.Request] (Job-Executor-5:job-108) Seq 5-1223557136: Sending { Cmd , MgmtId: 7200344900649, via: 5, Ver: v1, Flags: 100011, [{"CreateVMSnapshotCommand":{"vmState":"Running","volumeTOs":[{"id":23,"name":"ROOT-14","mountPoint":"/export/home/chandan/asf4-131-170/primary2","path":"07389d9c-6b97-4ef8-9db0-4167afef078e","size":21474836480,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"067fc155-b77d-3cd4-9599-579c5123a806","deviceId":0},{"id":24,"name":"DATA-14","mountPoint":"/export/home/chandan/asf4-131-170/primary2","path":"b83505e0-4dbb-460b-8e8d-01b0fe205146","size":5368709120,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"067fc155-b77d-3cd4-9599-579c5123a806","deviceId":1}],"target":{"id":18,"snapshotName":"i-3-14-VMSNAP_VS_20130316004034","type":"DiskAndMemory","current":false,"description":"Xen-boron-VMSnapshot-7-1"},"vmName":"i-3-14-VMSNAP","guestOSType":"CentOS 5.3 (64-bit)","wait":0}}] }
> 2013-03-15 17:40:34,845 DEBUG [agent.transport.Request] (Job-Executor-5:job-108) Seq 5-1223557136: Executing: { Cmd , MgmtId: 7200344900649, via: 5, Ver: v1, Flags: 100011, [{"CreateVMSnapshotCommand":{"vmState":"Running","volumeTOs":[{"id":23,"name":"ROOT-14","mountPoint":"/export/home/chandan/asf4-131-170/primary2","path":"07389d9c-6b97-4ef8-9db0-4167afef078e","size":21474836480,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"067fc155-b77d-3cd4-9599-579c5123a806","deviceId":0},{"id":24,"name":"DATA-14","mountPoint":"/export/home/chandan/asf4-131-170/primary2","path":"b83505e0-4dbb-460b-8e8d-01b0fe205146","size":5368709120,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"067fc155-b77d-3cd4-9599-579c5123a806","deviceId":1}],"target":{"id":18,"snapshotName":"i-3-14-VMSNAP_VS_20130316004034","type":"DiskAndMemory","current":false,"description":"Xen-boron-VMSnapshot-7-1"},"vmName":"i-3-14-VMSNAP","guestOSType":"CentOS 5.3 (64-bit)","wait":0}}] }
> 2013-03-15 17:40:34,845 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-6:null) Seq 5-1223557136: Executing request
> 2013-03-15 17:40:34,879 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===START=== 10.216.133.69 -- GET command=listZones&id=3d539919-57e1-4fb1-bd67-a2e5ccaec8fe&response=json&sessionkey=vrHJOCEZnUh0hUqgBw0EUdEvjqs%3D&_=1363394459571
> 2013-03-15 17:40:34,886 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===END=== 10.216.133.69 -- GET command=listZones&id=3d539919-57e1-4fb1-bd67-a2e5ccaec8fe&response=json&sessionkey=vrHJOCEZnUh0hUqgBw0EUdEvjqs%3D&_=1363394459571
> 2013-03-15 17:40:34,980 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null) ===START=== 10.216.133.69 -- GET command=listVirtualMachines&id=41fce8fd-9fdf-4f2f-bf04-c7173f2e3c2a&response=json&sessionkey=vrHJOCEZnUh0hUqgBw0EUdEvjqs%3D&_=1363394459626
> 2013-03-15 17:40:35,002 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null) ===END=== 10.216.133.69 -- GET command=listVirtualMachines&id=41fce8fd-9fdf-4f2f-bf04-c7173f2e3c2a&response=json&sessionkey=vrHJOCEZnUh0hUqgBw0EUdEvjqs%3D&_=1363394459626
> 2013-03-15 17:40:35,054 WARN [xen.resource.CitrixResourceBase] (DirectAgent-6:null) Task failed! Task record: uuid: 205fa77c-6e12-59e4-f400-bff8e9017fa6
> nameLabel: Async.VM.checkpoint
> nameDescription:
> allowedOperations: []
> currentOperations: {}
> created: Fri Mar 15 09:40:54 PDT 2013
> finished: Fri Mar 15 09:40:54 PDT 2013
> status: failure
> residentOn: com.xensource.xenapi.Host@551f702b
> progress: 1.0
> type: <none/>
> result:
> errorInfo: [LICENCE_RESTRICTION]
> otherConfig: {CS_VM_SNAPSHOT_KEY=i-3-14-VMSNAP_VS_20130316004034}
> subtaskOf: com.xensource.xenapi.Task@aaf13f6f
> subtasks: []
> 2013-03-15 17:40:35,062 ERROR [xen.resource.CitrixResourceBase] (DirectAgent-6:null) Creating VM Snapshot i-3-14-VMSNAP_VS_20130316004034 failed due to: null
> 2013-03-15 17:40:35,062 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-6:null) Seq 5-1223557136: Response Received:
> 2013-03-15 17:40:35,062 DEBUG [agent.transport.Request] (DirectAgent-6:null) Seq 5-1223557136: Processing: { Ans: , MgmtId: 7200344900649, via: 5, Ver: v1, Flags: 10, [{"CreateVMSnapshotAnswer":{"result":false,"wait":0}}] }
> 2013-03-15 17:40:35,062 DEBUG [agent.transport.Request] (Job-Executor-5:job-108) Seq 5-1223557136: Received: { Ans: , MgmtId: 7200344900649, via: 5, Ver: v1, Flags: 10, { CreateVMSnapshotAnswer } }
> 2013-03-15 17:40:35,062 ERROR [vm.snapshot.VMSnapshotManagerImpl] (Job-Executor-5:job-108) Agent reports creating vm snapshot i-3-14-VMSNAP_VS_20130316004034 failed for vm: i-3-14-VMSNAP due to null
> 2013-03-15 17:40:35,071 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-5:job-108) Complete async job-108, jobStatus: 1, resultCode: 0, result: org.apache.cloudstack.api.response.VMSnapshotResponse@1ee801fd
> 2013-03-15 17:40:35,078 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-5:job-108) Done executing org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd for job-108
> =========
> Bug Impact:
> =========
> User is not informed about the failure and a success notification in sent on the UI.
--
This message was sent by Atlassian JIRA
(v6.1#6144)