cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Chandan Purushothama (JIRA)" <j...@apache.org>
Subject [jira] [Closed] (CLOUDSTACK-1700) VMSnapshot: In spite of CreateVMSnapshotCmd failure - Async Job is reported as a success instead of failure
Date Tue, 15 Oct 2013 22:34:42 GMT

     [ 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)

Mime
View raw message