You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Luis <lm...@yahoo.com.INVALID> on 2015/09/24 13:25:48 UTC
Expunge
Hi
I notice that when I Expunge VM the hard disk space is not returned, I still have the same use, I had to deleted manually from the raid, is this a bug or I am missing a comfiguration?
Re: Expunge
Posted by Vadim Kimlaychuk <va...@kickcloud.net>.
Dear Luis,
I see, indeed, there is a problem with volume removal at your CS
instance. Log you provided does not show anything critical. Can you look
forward the log and search for any JAVA exceptions? This process is
asynchronous and error may come some minutes later after you actually
fire the event. There should be something in management log. Another
place to look is KVM host logs. Check syslog. Look for NFS errors.
Regarding HA VM capacity -- post another topic into this list. I don't
know the answer on the second question.
Regards,
Vadim
On 2015-09-25 15:42, Luis wrote:
> Hi
>
> I did this, I created a VM called DELETEME (First picture), on the
> picture 2 you can see the storage, two record per VM, I don't know why
> and I get confuse when trying to create a snapshot, Picture 3 I
> destroyed the VM, Picture 4 shows the two records in the storage, after
> deleting a lot of VM I was running out of space until I found this, now
> I delete them manually in the storage section.
>
> I added my log at the end of this email.
>
> Another thing I notice, not related with this, I have all my VM on HA
> in case the server shuts down and restart, at the moment of stating
> cloudstack, all my VM get started but the server gets over hot and
> shuts down, is there a way to limit the number of VM to start on HA?
>
> Thank you for your help, I really appreciate it.
>
> Picture 1
>
> Picture 2
>
> Picture 3
>
> Picture 4
>
> log
> 2015-09-25 08:35:40,329 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-11:ctx-61765fe6 ctx-f5f4d09f) ===END=== 10.0.8.6 -- GET
> command=queryAsyncJobResult&jobId=605e1db3-f3a6-4b7e-b62c-00ccc65944df&response=json&_=1443184540233
> 2015-09-25 08:35:41,628 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-bfc1897e) Execute sync-queue item:
> SyncQueueItemVO {id:64, queueId: 504, contentType: AsyncJob, contentId:
> 1016, lastProcessMsid: 191612618435011, lastprocessNumber: 3,
> lastProcessTime: Fri Sep 25 08:35:41 EDT 2015, created: Fri Sep 25
> 08:35:39 EDT 2015}
> 2015-09-25 08:35:41,629 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-bfc1897e) Schedule queued job-1016
> 2015-09-25 08:35:41,808 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016) Add job-1016 into
> job monitoring
> 2015-09-25 08:35:41,812 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016) Executing
> AsyncJobVO {id:1016, userId: 2, accountId: 2, instanceType: null,
> instanceId: null, cmd:
> com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, cmdInfo:
> rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAAAFV0ABVWTVNuYXBzaG90TWFuYWdlckltcGxw,
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 191612618435011, completeMsid: null,
> lastUpdated: null, lastPolled: null, created: Fri Sep 25 08:35:39 EDT
> 2015}
> 2015-09-25 08:35:41,812 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016) Run VM work job:
> com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 85, job origin:
> 1014
> 2015-09-25 08:35:41,813 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016 ctx-8deba3f4)
> Execute VM work job:
> com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":85,"handlerName":"VMSnapshotManagerImpl"}
> 2015-09-25 08:35:41,813 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016 ctx-8deba3f4) Done
> executing VM work job:
> com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":85,"handlerName":"VMSnapshotManagerImpl"}
> 2015-09-25 08:35:41,813 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016 ctx-8deba3f4)
> Complete async job-1016, jobStatus: SUCCEEDED, resultCode: 0, result:
> rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
> 2015-09-25 08:35:41,814 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016 ctx-8deba3f4)
> Publish async job-1016 complete on message bus
> 2015-09-25 08:35:41,814 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016 ctx-8deba3f4) Wake
> up jobs related to job-1016
> 2015-09-25 08:35:41,814 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016 ctx-8deba3f4)
> Update db status for job-1016
> 2015-09-25 08:35:41,814 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016 ctx-8deba3f4) Wake
> up jobs joined with job-1016 and disjoin all subjobs created from job-
> 1016
> 2015-09-25 08:35:41,907 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016) Done with run of
> VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM
> 85, job origin: 1014
> 2015-09-25 08:35:41,907 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016) Done executing
> com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-1016
> 2015-09-25 08:35:41,908 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-64:ctx-5e28e999 job-1014/job-1016) Remove job-1016
> from job monitoring
> 2015-09-25 08:35:42,155 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) VM state
> transitted from :Stopped to Destroyed with event: DestroyRequestedvm's
> original host id: 1 new host id: null host id before state transition:
> null
> 2015-09-25 08:35:42,157 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Hosts's actual
> total CPU: 28888 and CPU after applying overprovisioning: 28888
> 2015-09-25 08:35:42,157 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Hosts's actual
> total RAM: 25140768768 and RAM after applying overprovisioning:
> 25140768768
> 2015-09-25 08:35:42,157 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) release cpu
> from host: 1, old used: 6000,reserved: 500, actual total: 28888, total
> with overprovisioning: 28888; new used: 6000,reserved:0;
> movedfromreserved: true,moveToReserveredfalse
> 2015-09-25 08:35:42,157 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) release mem
> from host: 1, old used: 6710886400,reserved: 536870912, total:
> 25140768768; new used: 6710886400,reserved:0; movedfromreserved:
> true,moveToReserveredfalse
> 2015-09-25 08:35:42,275 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-14:null) SeqA 2-245135: Processing Seq 2-245135:
> { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2015-09-25 08:35:42,399 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-14:null) SeqA 2-245135: Sending Seq 2-245135: {
> Ans: , MgmtId: 191612618435011, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-09-25 08:35:42,663 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Sync job-1017
> execution on object VmWorkJobQueue.85
> 2015-09-25 08:35:43,243 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-2:ctx-c01c9e4a) ===START=== 10.0.8.6 -- GET
> command=queryAsyncJobResult&jobId=605e1db3-f3a6-4b7e-b62c-00ccc65944df&response=json&_=1443184543247
> 2015-09-25 08:35:43,326 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-2:ctx-c01c9e4a ctx-7a19cef4) ===END=== 10.0.8.6 -- GET
> command=queryAsyncJobResult&jobId=605e1db3-f3a6-4b7e-b62c-00ccc65944df&response=json&_=1443184543247
> 2015-09-25 08:35:43,480 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-f64d0027) Execute sync-queue item:
> SyncQueueItemVO {id:65, queueId: 504, contentType: AsyncJob, contentId:
> 1017, lastProcessMsid: 191612618435011, lastprocessNumber: 4,
> lastProcessTime: Fri Sep 25 08:35:43 EDT 2015, created: Fri Sep 25
> 08:35:42 EDT 2015}
> 2015-09-25 08:35:43,481 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-f64d0027) Schedule queued job-1017
> 2015-09-25 08:35:43,571 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017) Add job-1017 into
> job monitoring
> 2015-09-25 08:35:43,574 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017) Executing
> AsyncJobVO {id:1017, userId: 2, accountId: 2, instanceType: null,
> instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo:
> rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAVXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA,
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 191612618435011, completeMsid: null,
> lastUpdated: null, lastPolled: null, created: Fri Sep 25 08:35:42 EDT
> 2015}
> 2015-09-25 08:35:43,574 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017) Run VM work job:
> com.cloud.vm.VmWorkStop for VM 85, job origin: 1014
> 2015-09-25 08:35:43,575 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017 ctx-37ced5d2)
> Execute VM work job:
> com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":85,"handlerName":"VirtualMachineManagerImpl"}
> 2015-09-25 08:35:43,576 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017 ctx-37ced5d2)
> Stopped called on VM[User|i-2-85-VM] but the state is Destroyed
> 2015-09-25 08:35:43,576 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017 ctx-37ced5d2) Done
> executing VM work job:
> com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":85,"handlerName":"VirtualMachineManagerImpl"}
> 2015-09-25 08:35:43,576 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017 ctx-37ced5d2)
> Complete async job-1017, jobStatus: SUCCEEDED, resultCode: 0, result:
> null
> 2015-09-25 08:35:43,577 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017 ctx-37ced5d2)
> Publish async job-1017 complete on message bus
> 2015-09-25 08:35:43,577 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017 ctx-37ced5d2) Wake
> up jobs related to job-1017
> 2015-09-25 08:35:43,577 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017 ctx-37ced5d2)
> Update db status for job-1017
> 2015-09-25 08:35:43,577 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017 ctx-37ced5d2) Wake
> up jobs joined with job-1017 and disjoin all subjobs created from job-
> 1017
> 2015-09-25 08:35:43,659 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017) Done with run of
> VM work job: com.cloud.vm.VmWorkStop for VM 85, job origin: 1014
> 2015-09-25 08:35:43,659 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017) Done executing
> com.cloud.vm.VmWorkStop for job-1017
> 2015-09-25 08:35:43,660 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-65:ctx-0ce67abc job-1014/job-1017) Remove job-1017
> from job monitoring
> 2015-09-25 08:35:43,926 DEBUG [c.c.c.CapacityManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) VM state
> transitted from :Destroyed to Expunging with event:
> ExpungeOperationvm's original host id: 1 new host id: null host id
> before state transition: null
> 2015-09-25 08:35:43,927 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Destroying vm
> VM[User|i-2-85-VM]
> 2015-09-25 08:35:43,927 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Cleaning up
> NICS
> 2015-09-25 08:35:43,927 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Cleaning
> network for vm: 85
> 2015-09-25 08:35:44,019 DEBUG [c.c.n.g.DirectNetworkGuru]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Deallocate
> network: networkId: 204, ip: 10.0.10.103
> 2015-09-25 08:35:44,022 DEBUG [c.c.n.g.DirectNetworkGuru]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) remove nic 96
> secondary ip
> 2015-09-25 08:35:44,194 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Removed nic
> id=96
> 2015-09-25 08:35:44,195 DEBUG [o.a.c.e.o.NetworkOrchestrator]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Revoving nic
> secondary ip entry ...
> 2015-09-25 08:35:44,195 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Cleaning up
> hypervisor data structures (ex. SRs in XenServer) for managed storage
> 2015-09-25 08:35:44,198 DEBUG [o.a.c.e.o.VolumeOrchestrator]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Cleaning
> storage for vm: 85
> 2015-09-25 08:35:44,202 DEBUG [o.a.c.e.o.VolumeOrchestrator]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Detaching
> Vol[139|vm=85|DATADISK]
> 2015-09-25 08:35:44,388 DEBUG [c.c.a.t.Request]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Seq
> 1-2274317811822224501: Sending { Cmd , MgmtId: 191612618435011, via:
> 1(cloud.cosiab.com), Ver: v1, Flags: 100011,
> [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b226ac21-69d6-4e08-a81b-1e5a78559e48","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"0e92d828-2be1-35f0-83da-f21c1137c7f6","id":1,"poolType":"NetworkFilesystem","host":"10.0.10.2","path":"/primary","port":2049,"url":"NetworkFilesystem://10.0.10.2/primary/?ROLE=Primary&STOREUUID=0e92d828-2be1-35f0-83da-f21c1137c7f6"}},"name":"ROOT-85","size":21474836480,"path":"b226ac21-69d6-4e08-a81b-1e5a78559e48","volumeId":138,"vmName":"i-2-85-VM","accountId":2,"format":"QCOW2","provisioningType":"THIN","id":138,"deviceId":0,"hypervisorType":"KVM"}},"wait":0}}]
> }
> 2015-09-25 08:35:44,443 DEBUG [c.c.a.t.Request]
> (AgentManager-Handler-10:null) Seq 1-2274317811822224501: Processing: {
> Ans: , MgmtId: 191612618435011, via: 1, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
> 2015-09-25 08:35:44,443 DEBUG [c.c.a.t.Request]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Seq
> 1-2274317811822224501: Received: { Ans: , MgmtId: 191612618435011, via:
> 1, Ver: v1, Flags: 10, { Answer } }
> 2015-09-25 08:35:44,564 INFO [o.a.c.s.v.VolumeServiceImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Volume 138 is
> not referred anywhere, remove it from volumes table
> 2015-09-25 08:35:44,852 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Expunged
> VM[User|i-2-85-VM]
> 2015-09-25 08:35:44,942 DEBUG [c.c.u.AccountManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Access granted
> to Acct[89b1af9a-23d4-11e5-83b6-048d3840e222-admin] to Domain:1/ by
> AffinityGroupAccessChecker
> 2015-09-25 08:35:45,030 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Starting
> cleaning up vm VM[User|i-2-85-VM] resources...
> 2015-09-25 08:35:45,032 INFO [c.c.n.s.SecurityGroupManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Disassociated
> 1 network groups from uservm 85
> 2015-09-25 08:35:45,131 DEBUG [c.c.n.s.SecurityGroupManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Security group
> mappings are removed successfully for vm id=85
> 2015-09-25 08:35:45,200 DEBUG [c.c.n.f.FirewallManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) No firewall
> rules are found for vm id=85
> 2015-09-25 08:35:45,276 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Firewall rules
> are removed successfully as a part of vm id=85 expunge
> 2015-09-25 08:35:45,277 DEBUG [c.c.n.r.RulesManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) No port
> forwarding rules are found for vm id=85
> 2015-09-25 08:35:45,277 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Port
> forwarding rules are removed successfully as a part of vm id=85 expunge
> 2015-09-25 08:35:45,278 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Removed vm
> id=85 from all load balancers as a part of expunge process
> 2015-09-25 08:35:45,278 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Successfully
> cleaned up vm VM[User|i-2-85-VM] resources as a part of expunge process
> 2015-09-25 08:35:45,409 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-8b683ae7) Begin cleanup expired async-jobs
> 2015-09-25 08:35:45,411 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-8b683ae7) End cleanup expired async-jobs
> 2015-09-25 08:35:45,444 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Complete async
> job-1014, jobStatus: SUCCEEDED, resultCode: 0, result:
> org.apache.cloudstack.api.response.UserVmResponse/null/{"securitygroup":[],"nic":[],"tags":[],"affinitygroup":[]}
> 2015-09-25 08:35:45,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Publish async
> job-1014 complete on message bus
> 2015-09-25 08:35:45,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Wake up jobs
> related to job-1014
> 2015-09-25 08:35:45,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Update db
> status for job-1014
> 2015-09-25 08:35:45,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014 ctx-85a6409c) Wake up jobs
> joined with job-1014 and disjoin all subjobs created from job- 1014
> 2015-09-25 08:35:45,523 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014) Done executing
> org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin for
> job-1014
> 2015-09-25 08:35:45,523 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (API-Job-Executor-55:ctx-2e9eb037 job-1014) Remove job-1014 from job
> monitoring
> 2015-09-25 08:35:46,231 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-3:ctx-51adc6ae) ===START=== 10.0.8.6 -- GET
> command=queryAsyncJobResult&jobId=605e1db3-f3a6-4b7e-b62c-00ccc65944df&response=json&_=1443184546234
> 2015-09-25 08:35:46,326 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-3:ctx-51adc6ae ctx-eafb69bc) ===END=== 10.0.8.6 -- GET
> command=queryAsyncJobResult&jobId=605e1db3-f3a6-4b7e-b62c-00ccc65944df&response=json&_=1443184546234
> 2015-09-25 08:35:46,570 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-3:null) Ping from 1
> 2015-09-25 08:35:46,571 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) Process host VM state report from ping
> process. host: 1
> 2015-09-25 08:35:46,579 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) Process VM state report. host: 1, number
> of records in report: 10
> 2015-09-25 08:35:46,579 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 1, power
> state: PowerOn
> 2015-09-25 08:35:46,580 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 1
> 2015-09-25 08:35:46,580 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 71,
> power state: PowerOn
> 2015-09-25 08:35:46,581 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 71
> 2015-09-25 08:35:46,581 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 81,
> power state: PowerOn
> 2015-09-25 08:35:46,582 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 81
> 2015-09-25 08:35:46,582 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 4, power
> state: PowerOn
> 2015-09-25 08:35:46,583 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 4
> 2015-09-25 08:35:46,583 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 6, power
> state: PowerOn
> 2015-09-25 08:35:46,584 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 6
> 2015-09-25 08:35:46,584 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 7, power
> state: PowerOn
> 2015-09-25 08:35:46,584 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 7
> 2015-09-25 08:35:46,584 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 78,
> power state: PowerOn
> 2015-09-25 08:35:46,585 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 78
> 2015-09-25 08:35:46,585 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 12,
> power state: PowerOn
> 2015-09-25 08:35:46,586 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 12
> 2015-09-25 08:35:46,586 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 62,
> power state: PowerOn
> 2015-09-25 08:35:46,587 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 62
> 2015-09-25 08:35:46,587 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM state report. host: 1, vm id: 13,
> power state: PowerOn
> 2015-09-25 08:35:46,588 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) VM power state does not change, skip DB
> writing. vm id: 13
> 2015-09-25 08:35:46,591 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (AgentManager-Handler-3:null) Done with process of VM state report.
> host: 1
> 2015-09-25 08:35:47,275 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-11:null) SeqA 2-245136: Processing Seq 2-245136:
> { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2015-09-25 08:35:47,369 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-11:null) SeqA 2-245136: Sending Seq 2-245136: {
> Ans: , MgmtId: 191612618435011, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-09-25 08:35:53,871 DEBUG [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-30000194) Zone 1 is ready to launch console proxy
> 2015-09-25 08:35:54,006 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-84615df7) Zone 1 is ready to launch secondary storage
> VM
> 2015-09-25 08:35:55,409 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-a4c24e78) Begin cleanup expired async-jobs
> 2015-09-25 08:35:55,411 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-a4c24e78) End cleanup expired async-jobs
> 2015-09-25 08:35:57,276 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-6:null) SeqA 2-245137: Processing Seq 2-245137: {
> Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2015-09-25 08:35:57,385 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-6:null) SeqA 2-245137: Sending Seq 2-245137: {
> Ans: , MgmtId: 191612618435011, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-09-25 08:35:58,316 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-2:ctx-c7f1171e) VmStatsCollector is running...
> 2015-09-25 08:35:58,493 DEBUG [c.c.a.t.Request]
> (StatsCollector-2:ctx-c7f1171e) Seq 1-2274317811822224502: Received: {
> Ans: , MgmtId: 191612618435011, via: 1, Ver: v1, Flags: 10, {
> GetVmStatsAnswer } }
> 2015-09-25 08:35:58,505 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-4:ctx-499745dc) StorageCollector is running...
> 2015-09-25 08:35:58,553 DEBUG [c.c.a.t.Request]
> (StatsCollector-4:ctx-499745dc) Seq 5-87538717757044704: Received: {
> Ans: , MgmtId: 191612618435011, via: 5, Ver: v1, Flags: 10, {
> GetStorageStatsAnswer } }
> 2015-09-25 08:35:58,581 DEBUG [c.c.a.t.Request]
> (StatsCollector-4:ctx-499745dc) Seq 1-2274317811822224503: Received: {
> Ans: , MgmtId: 191612618435011, via: 1, Ver: v1, Flags: 10, {
> GetStorageStatsAnswer } }
> 2015-09-25 08:35:58,667 DEBUG [c.c.a.t.Request]
> (StatsCollector-4:ctx-499745dc) Seq 1-2274317811822224504: Received: {
> Ans: , MgmtId: 191612618435011, via: 1, Ver: v1, Flags: 10, {
> GetStorageStatsAnswer } }
>
> -------------------------
> FROM: Vadim Kimlaychuk <va...@kickcloud.net>
> TO: Cloudstack Users <us...@cloudstack.apache.org>
> CC: Luis <lm...@yahoo.com>
> SENT: Friday, September 25, 2015 3:08 AM
> SUBJECT: Re: Expunge
>
> Luis,
>
> Do you use shared mount point with your KVM hypervisor or local
> NFS server? I have tested "Expunge" at my CS 4.5.3 and when I delete VM
> with "expunge" option -- Cloudstack deletes it from the storage
> immediately. Can you do the same test and look into management log file
> ? It would be nice to see trace from what is going on. Or do you have
> problem only with delayed "expunge" ?
>
> Vadim.
>
> On 2015-09-24 21:04, Luis wrote:
>
>> Hi
>>
>> Thank you for your answer.
>>
>> I am using CL 4.5.2 with KVM in Raid 5, after a month the space was
>> not
>> freed up, previously i changes the expunge to 100
>>
>> -------------------------
>> FROM: Vadim Kimlaychuk <va...@kickcloud.net>
>> TO: Luis <lm...@yahoo.com>
>> CC: users@cloudstack.apache.org
>> SENT: Thursday, September 24, 2015 1:33 PM
>> SUBJECT: Re: Expunge
>
>>
>> Hello Luis,
>>
>> If I remember correctly - you don't get it freed immediately.
>> There is some background process that cleans up. You can probably get
>> better response if write down what version of CS, hypervisor and
>> storage
>> type are you using.
>>
>> Regards,
>>
>> Vadim
>>
>> On 2015-09-24 14:25, Luis wrote:
>>
>>> Hi
>>> I notice that when I Expunge VM the hard disk space is not returned,
>>> I
>>> still have the same use, I had to deleted manually from the raid, is
>>> this a bug or I am missing a comfiguration?
Re: Expunge
Posted by Vadim Kimlaychuk <va...@kickcloud.net>.
Luis,
Do you use shared mount point with your KVM hypervisor or local
NFS server? I have tested "Expunge" at my CS 4.5.3 and when I delete VM
with "expunge" option -- Cloudstack deletes it from the storage
immediately. Can you do the same test and look into management log file
? It would be nice to see trace from what is going on. Or do you have
problem only with delayed "expunge" ?
Vadim.
On 2015-09-24 21:04, Luis wrote:
> Hi
>
> Thank you for your answer.
>
> I am using CL 4.5.2 with KVM in Raid 5, after a month the space was not
> freed up, previously i changes the expunge to 100
>
> -------------------------
> FROM: Vadim Kimlaychuk <va...@kickcloud.net>
> TO: Luis <lm...@yahoo.com>
> CC: users@cloudstack.apache.org
> SENT: Thursday, September 24, 2015 1:33 PM
> SUBJECT: Re: Expunge
>
> Hello Luis,
>
> If I remember correctly - you don't get it freed immediately.
> There is some background process that cleans up. You can probably get
> better response if write down what version of CS, hypervisor and
> storage
> type are you using.
>
> Regards,
>
> Vadim
>
> On 2015-09-24 14:25, Luis wrote:
>
>> Hi
>> I notice that when I Expunge VM the hard disk space is not returned, I
>> still have the same use, I had to deleted manually from the raid, is
>> this a bug or I am missing a comfiguration?
Re: Expunge
Posted by Vadim Kimlaychuk <va...@kickcloud.net>.
Hello Luis,
If I remember correctly - you don't get it freed immediately.
There is some background process that cleans up. You can probably get
better response if write down what version of CS, hypervisor and storage
type are you using.
Regards,
Vadim
On 2015-09-24 14:25, Luis wrote:
> Hi
> I notice that when I Expunge VM the hard disk space is not returned, I
> still have the same use, I had to deleted manually from the raid, is
> this a bug or I am missing a comfiguration?