You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Ghaith Bannoura <gb...@etq.com> on 2016/11/23 13:59:54 UTC

Basic and Advanced Zone

Hi All,

I have a basic zone with ACS 4.8 with xenserver 6.5 , I created a new advanced zone (Untagged for management , tagged for public and guest ) , after creating the advanced zone I tried to create an instance but an error appeared , I know that first vm once created it should be create a virtual router and I checked it and it was stopped and I can't start it , also I tried copy templates from basic zone to advanced zone with no luck ( failed to copy template I checked the logs and the error is connection refused ) .

Below logs from management to create a new VM , can you please advise ?

2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring



2016-11-23 12:46:19,109 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:a12b373b) Add job-44040 into job monitoring
2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-10:ctx-cde514ac ctx-618855d1) (logid:7a08842b) submit async job-44040, details: AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Executing AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2016-11-23 12:46:19,136 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
2016-11-23 12:46:20,906 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44042 execution on object VmWorkJobQueue.3307
2016-11-23 12:46:22,895 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:56caed9e) Add job-44042 into job monitoring
2016-11-23 12:46:22,907 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Executing AsyncJobVO {id:44042, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, cmdInfo: rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAADOt0ABVWTVNuYXBzaG90TWFuYWdlckltcGxw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:20 EET 2016}
2016-11-23 12:46:22,907 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Run VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
2016-11-23 12:46:22,908 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Execute VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
2016-11-23 12:46:22,910 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
2016-11-23 12:46:22,910 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Complete async job-44042, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Publish async job-44042 complete on message bus
2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs related to job-44042
2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Update db status for job-44042
2016-11-23 12:46:22,912 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs joined with job-44042 and disjoin all subjobs created from job- 44042
2016-11-23 12:46:22,916 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
2016-11-23 12:46:22,916 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done executing com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-44042
2016-11-23 12:46:22,917 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Remove job-44042 from job monitoring
2016-11-23 12:46:22,928 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Error to Expunging with event: DestroyRequestedvm's original host id: null new host id: null host id before state transition: null
2016-11-23 12:46:22,942 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44043 execution on object VmWorkJobQueue.3307
2016-11-23 12:46:24,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:9d472300) Add job-44043 into job monitoring
2016-11-23 12:46:24,886 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Executing AsyncJobVO {id:44043, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:22 EET 2016}
2016-11-23 12:46:24,886 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
2016-11-23 12:46:24,887 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
2016-11-23 12:46:24,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Expunging
2016-11-23 12:46:24,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
2016-11-23 12:46:24,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Complete async job-44043, jobStatus: SUCCEEDED, resultCode: 0, result: null
2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Publish async job-44043 complete on message bus
2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs related to job-44043
2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Update db status for job-44043
2016-11-23 12:46:24,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs joined with job-44043 and disjoin all subjobs created from job- 44043
2016-11-23 12:46:24,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
2016-11-23 12:46:24,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44043
2016-11-23 12:46:24,910 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Remove job-44043 from job monitoring
2016-11-23 12:46:24,910 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Expunging to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null
2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up NICS
2016-11-23 12:46:24,910 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning network for vm: 3307
2016-11-23 12:46:24,914 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Service SecurityGroup is not supported in the network id=209
2016-11-23 12:46:24,917 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Asking VirtualRouter to release Nic[3307-3307-null-192.168.114.127]
2016-11-23 12:46:24,923 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Deallocate network: networkId: 209, ip: 192.168.114.127
2016-11-23 12:46:24,929 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) remove nic 3307 secondary ip
2016-11-23 12:46:24,932 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed nic id=3307
2016-11-23 12:46:24,933 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Revoving nic secondary ip entry ...
2016-11-23 12:46:24,933 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage
2016-11-23 12:46:24,934 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning storage for vm: 3307
2016-11-23 12:46:24,936 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Expunged VM[User|i-2-3307-VM]
2016-11-23 12:46:24,936 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Starting cleaning up vm VM[User|i-2-3307-VM] resources...
2016-11-23 12:46:24,947 DEBUG [c.c.n.f.FirewallManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No firewall rules are found for vm id=3307
2016-11-23 12:46:24,951 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Firewall rules are removed successfully as a part of vm id=3307 expunge
2016-11-23 12:46:24,954 DEBUG [c.c.n.r.RulesManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No port forwarding rules are found for vm id=3307
2016-11-23 12:46:24,954 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Port forwarding rules are removed successfully as a part of vm id=3307 expunge
2016-11-23 12:46:24,956 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed vm id=3307 from all load balancers as a part of expunge process
2016-11-23 12:46:24,957 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Successfully cleaned up vm VM[User|i-2-3307-VM] resources as a part of expunge process
2016-11-23 12:46:24,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Complete async job-44040, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse/null/{"securitygroup":[],"nic":[],"tags":[],"affinitygroup":[]}
2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Publish async job-44040 complete on message bus
2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs related to job-44040
2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Update db status for job-44040
2016-11-23 12:46:24,977 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs joined with job-44040 and disjoin all subjobs created from job- 44040
2016-11-23 12:46:24,983 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Done executing org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin for job-44040
2016-11-23 12:46:24,983 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Remove job-44040 from job monitoring

2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
2016-11-23 12:46:20,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-7534d4fd) (logid:ca865d0b) Schedule queued job-44041
2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring



Best Regards,
EtQ, Inc.
Ghaith Bannoura
Senior System Administrator
MCT, MCSE (Messaging, Server Infrastructure)
MCSA (Windows Server 2008, 2012), MCP

*  Phone: +9626-537-0923 Ext. 376
*  Gbannoura@etq.com <ma...@etq.com>
*   http://www.etq.com<http://www.etq.com/>


Re: Basic and Advanced Zone

Posted by Sergey Levitskiy <Se...@autodesk.com>.
Unfortunately, this is not good enough. You need to keep all log entries in the interval when VM was being deployed. You can simply archive and post link to you full log and indicate timeframe the failure happened.   


RE: Basic and Advanced Zone

Posted by Ghaith Bannoura <gb...@etq.com>.
I tried to attached logs with no luck , I attached a log related for creating a VM in the advanced zone 

Please advise if this log is useful or not 


2016-11-25 23:11:12,029 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-7:ctx-95cf0684 ctx-bc3de092) (logid:50fd0c24) Allocating entries for VM: VM[User|i-2-3400-VM]
2016-11-25 23:11:12,029 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-7:ctx-95cf0684 ctx-bc3de092) (logid:50fd0c24) Allocating nics for VM[User|i-2-3400-VM]
2016-11-25 23:11:12,030 DEBUG [o.a.c.e.o.NetworkOrchestrator] (catalina-exec-7:ctx-95cf0684 ctx-bc3de092) (logid:50fd0c24) Allocating nic for vm VM[User|i-2-3400-VM] in network Ntwk[209|Guest|7] with requested profile NicProfile[0-0-null-null-null
2016-11-25 23:11:12,049 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-7:ctx-95cf0684 ctx-bc3de092) (logid:50fd0c24) Allocating disks for VM[User|i-2-3400-VM]
2016-11-25 23:11:12,081 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-7:ctx-95cf0684 ctx-bc3de092) (logid:50fd0c24) Allocation completed for VM: VM[User|i-2-3400-VM]
2016-11-25 23:11:12,081 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-7:ctx-95cf0684 ctx-bc3de092) (logid:50fd0c24) Successfully allocated DB entry for VM[User|i-2-3400-VM]
2016-11-25 23:11:12,850 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-1369daff job-45620/job-45621 ctx-09924a6b) (logid:7a41ca6b) Successfully transitioned to start state for VM[User|i-2-3400-VM] reservation id = a29aee14-4695-49dc-9c6e-4b2a66cf1245
2016-11-25 23:11:12,873 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-1369daff job-45620/job-45621 ctx-09924a6b) (logid:7a41ca6b) Deployment found  - P0=VM[User|i-2-3400-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(2)-Pod(2)-Cluster(10)-Host(18)-Storage(Volume(4461|ROOT-->Pool(12))]
2016-11-25 23:11:12,968 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-1369daff job-45620/job-45621 ctx-09924a6b) (logid:7a41ca6b) Cleaning up resources for the vm VM[User|i-2-3400-VM] in Starting state
2016-11-25 23:11:12,971 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-1369daff job-45620/job-45621 ctx-09924a6b) (logid:7a41ca6b) Seq 18-8243839117901693056: Sending  { Cmd , MgmtId: 144344642087, via: 18(CS7CAZ02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-3400-VM","wait":0}}] }
2016-11-25 23:11:12,971 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-1369daff job-45620/job-45621 ctx-09924a6b) (logid:7a41ca6b) Seq 18-8243839117901693056: Executing:  { Cmd , MgmtId: 144344642087, via: 18(CS7CAZ02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-3400-VM","wait":0}}] }
2016-11-25 23:11:12,990 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-1369daff job-45620/job-45621 ctx-09924a6b) (logid:7a41ca6b) Successfully released network resources for the vm VM[User|i-2-3400-VM]
2016-11-25 23:11:12,990 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-1369daff job-45620/job-45621 ctx-09924a6b) (logid:7a41ca6b) Successfully cleanued up resources for the vm VM[User|i-2-3400-VM] in Starting state
2016-11-25 23:11:13,021 ERROR [c.c.v.UserVmManagerImpl] (API-Job-Executor-12:ctx-643c244b job-45620 ctx-c015f536) (logid:7a41ca6b) VM VM[User|i-2-3400-VM] unexpectedly went to Stopped state
2016-11-25 23:11:13,022 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-12:ctx-643c244b job-45620 ctx-c015f536) (logid:7a41ca6b) Destroying vm VM[User|i-2-3400-VM] as it failed to create on Host with Id:null
com.cloud.exception.ConcurrentOperationException: Failed to deploy VM VM[User|i-2-3400-VM]
2016-11-25 23:11:13,108 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-643c244b job-45620) (logid:7a41ca6b) Complete async job-45620, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to deploy VM VM[User|i-2-3400-VM]"}

Best Regards,
EtQ, Inc.
Ghaith Bannoura
Senior System Administrator
MCT, MCSE (Messaging, Server Infrastructure)
MCSA (Windows Server 2008, 2012), MCP 

   Phone: +9626-537-0923 Ext. 376
P  Gbannoura@etq.com 
G   http://www.etq.com

-----Original Message-----
From: Dag Sonstebo [mailto:Dag.Sonstebo@shapeblue.com] 
Sent: Wednesday, November 23, 2016 4:31 PM
To: users@cloudstack.apache.org
Subject: Re: Basic and Advanced Zone

OK, as per Sergey’s comments can you provide a bit more comprehensive logs + give us some ideas which VRs and VMs you are trying to start.

The other thing you’ve mentioned is a connection refused error – this points to the new zone SSVM not being able to copy templates from your basic zone secondary NFS share to the new advanced zone share – so take a look at your NFS permissions. 

Regards,
Dag Sonstebo
Cloud Architect
ShapeBlue

On 23/11/2016, 14:12, "Ghaith Bannoura" <gb...@etq.com> wrote:

    Yes , I prepopulate the system VM templates and the SSVM and console proxy is running and the agent statues is running also 
    
    Best Regards,
    EtQ, Inc.
    Ghaith Bannoura
    Senior System Administrator
    MCT, MCSE (Messaging, Server Infrastructure)
    MCSA (Windows Server 2008, 2012), MCP 
    
       Phone: +9626-537-0923 Ext. 376
    P  Gbannoura@etq.com 
    G   http://www.etq.com
    
    -----Original Message-----
    From: Dag Sonstebo [mailto:Dag.Sonstebo@shapeblue.com] 
    Sent: Wednesday, November 23, 2016 4:09 PM
    To: users@cloudstack.apache.org
    Subject: Re: Basic and Advanced Zone
    
    Ghait,
    
    Did you prepopulate the system VM template on the secondary storage share for the new advanced zone? Are your system VMs – SSVM and CPVM – running and healthy?
    
    Regards,
    Dag Sonstebo
    Cloud Architect
    ShapeBlue
    
    On 23/11/2016, 13:59, "Ghaith Bannoura" <gb...@etq.com> wrote:
    
        Hi All,
        
        I have a basic zone with ACS 4.8 with xenserver 6.5 , I created a new advanced zone (Untagged for management , tagged for public and guest ) , after creating the advanced zone I tried to create an instance but an error appeared , I know that first vm once created it should be create a virtual router and I checked it and it was stopped and I can't start it , also I tried copy templates from basic zone to advanced zone with no luck ( failed to copy template I checked the logs and the error is connection refused ) .
        
        Below logs from management to create a new VM , can you please advise ?
        
        2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
        2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
        2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
        2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
        2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
        2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
        
        
        
        2016-11-23 12:46:19,109 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:a12b373b) Add job-44040 into job monitoring
        2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-10:ctx-cde514ac ctx-618855d1) (logid:7a08842b) submit async job-44040, details: AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
        2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Executing AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
        2016-11-23 12:46:19,136 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
        2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
        2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
        2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
        2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
        2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
        2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
        2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
        2016-11-23 12:46:20,906 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44042 execution on object VmWorkJobQueue.3307
        2016-11-23 12:46:22,895 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:56caed9e) Add job-44042 into job monitoring
        2016-11-23 12:46:22,907 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Executing AsyncJobVO {id:44042, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, cmdInfo: rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAADOt0ABVWTVNuYXBzaG90TWFuYWdlckltcGxw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:20 EET 2016}
        2016-11-23 12:46:22,907 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Run VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
        2016-11-23 12:46:22,908 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Execute VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
        2016-11-23 12:46:22,910 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
        2016-11-23 12:46:22,910 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Complete async job-44042, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
        2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Publish async job-44042 complete on message bus
        2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs related to job-44042
        2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Update db status for job-44042
        2016-11-23 12:46:22,912 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs joined with job-44042 and disjoin all subjobs created from job- 44042
        2016-11-23 12:46:22,916 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
        2016-11-23 12:46:22,916 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done executing com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-44042
        2016-11-23 12:46:22,917 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Remove job-44042 from job monitoring
        2016-11-23 12:46:22,928 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Error to Expunging with event: DestroyRequestedvm's original host id: null new host id: null host id before state transition: null
        2016-11-23 12:46:22,942 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44043 execution on object VmWorkJobQueue.3307
        2016-11-23 12:46:24,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:9d472300) Add job-44043 into job monitoring
        2016-11-23 12:46:24,886 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Executing AsyncJobVO {id:44043, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:22 EET 2016}
        2016-11-23 12:46:24,886 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:24,887 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:24,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Expunging
        2016-11-23 12:46:24,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:24,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Complete async job-44043, jobStatus: SUCCEEDED, resultCode: 0, result: null
        2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Publish async job-44043 complete on message bus
        2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs related to job-44043
        2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Update db status for job-44043
        2016-11-23 12:46:24,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs joined with job-44043 and disjoin all subjobs created from job- 44043
        2016-11-23 12:46:24,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:24,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44043
        2016-11-23 12:46:24,910 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Remove job-44043 from job monitoring
        2016-11-23 12:46:24,910 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Expunging to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null
        2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
        2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up NICS
        2016-11-23 12:46:24,910 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning network for vm: 3307
        2016-11-23 12:46:24,914 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Service SecurityGroup is not supported in the network id=209
        2016-11-23 12:46:24,917 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Asking VirtualRouter to release Nic[3307-3307-null-192.168.114.127]
        2016-11-23 12:46:24,923 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Deallocate network: networkId: 209, ip: 192.168.114.127
        2016-11-23 12:46:24,929 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) remove nic 3307 secondary ip
        2016-11-23 12:46:24,932 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed nic id=3307
        2016-11-23 12:46:24,933 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Revoving nic secondary ip entry ...
        2016-11-23 12:46:24,933 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage
        2016-11-23 12:46:24,934 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning storage for vm: 3307
        2016-11-23 12:46:24,936 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Expunged VM[User|i-2-3307-VM]
        2016-11-23 12:46:24,936 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Starting cleaning up vm VM[User|i-2-3307-VM] resources...
        2016-11-23 12:46:24,947 DEBUG [c.c.n.f.FirewallManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No firewall rules are found for vm id=3307
        2016-11-23 12:46:24,951 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Firewall rules are removed successfully as a part of vm id=3307 expunge
        2016-11-23 12:46:24,954 DEBUG [c.c.n.r.RulesManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No port forwarding rules are found for vm id=3307
        2016-11-23 12:46:24,954 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Port forwarding rules are removed successfully as a part of vm id=3307 expunge
        2016-11-23 12:46:24,956 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed vm id=3307 from all load balancers as a part of expunge process
        2016-11-23 12:46:24,957 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Successfully cleaned up vm VM[User|i-2-3307-VM] resources as a part of expunge process
        2016-11-23 12:46:24,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Complete async job-44040, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse/null/{"securitygroup":[],"nic":[],"tags":[],"affinitygroup":[]}
        2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Publish async job-44040 complete on message bus
        2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs related to job-44040
        2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Update db status for job-44040
        2016-11-23 12:46:24,977 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs joined with job-44040 and disjoin all subjobs created from job- 44040
        2016-11-23 12:46:24,983 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Done executing org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin for job-44040
        2016-11-23 12:46:24,983 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Remove job-44040 from job monitoring
        
        2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
        2016-11-23 12:46:20,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-7534d4fd) (logid:ca865d0b) Schedule queued job-44041
        2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
        2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
        2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
        2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
        2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
        2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
        
        
        
        Best Regards,
        EtQ, Inc.
        Ghaith Bannoura
        Senior System Administrator
        MCT, MCSE (Messaging, Server Infrastructure)
        MCSA (Windows Server 2008, 2012), MCP
        
        *  Phone: +9626-537-0923 Ext. 376
        *  Gbannoura@etq.com <ma...@etq.com>
        *   http://www.etq.com<http://www.etq.com/>
        
        
    
    
    Dag.Sonstebo@shapeblue.com
    www.shapeblue.com
    53 Chandos Place, Covent Garden, London  WC2N 4HSUK @shapeblue
      
     
    
    


Dag.Sonstebo@shapeblue.com
www.shapeblue.com
53 Chandos Place, Covent Garden, London  WC2N 4HSUK @shapeblue
  
 


Re: Basic and Advanced Zone

Posted by Dag Sonstebo <Da...@shapeblue.com>.
OK, as per Sergey’s comments can you provide a bit more comprehensive logs + give us some ideas which VRs and VMs you are trying to start.

The other thing you’ve mentioned is a connection refused error – this points to the new zone SSVM not being able to copy templates from your basic zone secondary NFS share to the new advanced zone share – so take a look at your NFS permissions. 

Regards,
Dag Sonstebo
Cloud Architect
ShapeBlue

On 23/11/2016, 14:12, "Ghaith Bannoura" <gb...@etq.com> wrote:

    Yes , I prepopulate the system VM templates and the SSVM and console proxy is running and the agent statues is running also 
    
    Best Regards,
    EtQ, Inc.
    Ghaith Bannoura
    Senior System Administrator
    MCT, MCSE (Messaging, Server Infrastructure)
    MCSA (Windows Server 2008, 2012), MCP 
    
       Phone: +9626-537-0923 Ext. 376
    P  Gbannoura@etq.com 
    G   http://www.etq.com
    
    -----Original Message-----
    From: Dag Sonstebo [mailto:Dag.Sonstebo@shapeblue.com] 
    Sent: Wednesday, November 23, 2016 4:09 PM
    To: users@cloudstack.apache.org
    Subject: Re: Basic and Advanced Zone
    
    Ghait,
    
    Did you prepopulate the system VM template on the secondary storage share for the new advanced zone? Are your system VMs – SSVM and CPVM – running and healthy?
    
    Regards,
    Dag Sonstebo
    Cloud Architect
    ShapeBlue
    
    On 23/11/2016, 13:59, "Ghaith Bannoura" <gb...@etq.com> wrote:
    
        Hi All,
        
        I have a basic zone with ACS 4.8 with xenserver 6.5 , I created a new advanced zone (Untagged for management , tagged for public and guest ) , after creating the advanced zone I tried to create an instance but an error appeared , I know that first vm once created it should be create a virtual router and I checked it and it was stopped and I can't start it , also I tried copy templates from basic zone to advanced zone with no luck ( failed to copy template I checked the logs and the error is connection refused ) .
        
        Below logs from management to create a new VM , can you please advise ?
        
        2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
        2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
        2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
        2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
        2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
        2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
        
        
        
        2016-11-23 12:46:19,109 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:a12b373b) Add job-44040 into job monitoring
        2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-10:ctx-cde514ac ctx-618855d1) (logid:7a08842b) submit async job-44040, details: AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
        2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Executing AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
        2016-11-23 12:46:19,136 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
        2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
        2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
        2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
        2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
        2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
        2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
        2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
        2016-11-23 12:46:20,906 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44042 execution on object VmWorkJobQueue.3307
        2016-11-23 12:46:22,895 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:56caed9e) Add job-44042 into job monitoring
        2016-11-23 12:46:22,907 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Executing AsyncJobVO {id:44042, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, cmdInfo: rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAADOt0ABVWTVNuYXBzaG90TWFuYWdlckltcGxw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:20 EET 2016}
        2016-11-23 12:46:22,907 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Run VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
        2016-11-23 12:46:22,908 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Execute VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
        2016-11-23 12:46:22,910 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
        2016-11-23 12:46:22,910 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Complete async job-44042, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
        2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Publish async job-44042 complete on message bus
        2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs related to job-44042
        2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Update db status for job-44042
        2016-11-23 12:46:22,912 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs joined with job-44042 and disjoin all subjobs created from job- 44042
        2016-11-23 12:46:22,916 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
        2016-11-23 12:46:22,916 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done executing com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-44042
        2016-11-23 12:46:22,917 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Remove job-44042 from job monitoring
        2016-11-23 12:46:22,928 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Error to Expunging with event: DestroyRequestedvm's original host id: null new host id: null host id before state transition: null
        2016-11-23 12:46:22,942 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44043 execution on object VmWorkJobQueue.3307
        2016-11-23 12:46:24,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:9d472300) Add job-44043 into job monitoring
        2016-11-23 12:46:24,886 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Executing AsyncJobVO {id:44043, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:22 EET 2016}
        2016-11-23 12:46:24,886 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:24,887 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:24,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Expunging
        2016-11-23 12:46:24,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:24,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Complete async job-44043, jobStatus: SUCCEEDED, resultCode: 0, result: null
        2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Publish async job-44043 complete on message bus
        2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs related to job-44043
        2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Update db status for job-44043
        2016-11-23 12:46:24,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs joined with job-44043 and disjoin all subjobs created from job- 44043
        2016-11-23 12:46:24,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:24,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44043
        2016-11-23 12:46:24,910 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Remove job-44043 from job monitoring
        2016-11-23 12:46:24,910 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Expunging to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null
        2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
        2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up NICS
        2016-11-23 12:46:24,910 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning network for vm: 3307
        2016-11-23 12:46:24,914 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Service SecurityGroup is not supported in the network id=209
        2016-11-23 12:46:24,917 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Asking VirtualRouter to release Nic[3307-3307-null-192.168.114.127]
        2016-11-23 12:46:24,923 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Deallocate network: networkId: 209, ip: 192.168.114.127
        2016-11-23 12:46:24,929 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) remove nic 3307 secondary ip
        2016-11-23 12:46:24,932 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed nic id=3307
        2016-11-23 12:46:24,933 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Revoving nic secondary ip entry ...
        2016-11-23 12:46:24,933 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage
        2016-11-23 12:46:24,934 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning storage for vm: 3307
        2016-11-23 12:46:24,936 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Expunged VM[User|i-2-3307-VM]
        2016-11-23 12:46:24,936 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Starting cleaning up vm VM[User|i-2-3307-VM] resources...
        2016-11-23 12:46:24,947 DEBUG [c.c.n.f.FirewallManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No firewall rules are found for vm id=3307
        2016-11-23 12:46:24,951 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Firewall rules are removed successfully as a part of vm id=3307 expunge
        2016-11-23 12:46:24,954 DEBUG [c.c.n.r.RulesManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No port forwarding rules are found for vm id=3307
        2016-11-23 12:46:24,954 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Port forwarding rules are removed successfully as a part of vm id=3307 expunge
        2016-11-23 12:46:24,956 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed vm id=3307 from all load balancers as a part of expunge process
        2016-11-23 12:46:24,957 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Successfully cleaned up vm VM[User|i-2-3307-VM] resources as a part of expunge process
        2016-11-23 12:46:24,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Complete async job-44040, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse/null/{"securitygroup":[],"nic":[],"tags":[],"affinitygroup":[]}
        2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Publish async job-44040 complete on message bus
        2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs related to job-44040
        2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Update db status for job-44040
        2016-11-23 12:46:24,977 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs joined with job-44040 and disjoin all subjobs created from job- 44040
        2016-11-23 12:46:24,983 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Done executing org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin for job-44040
        2016-11-23 12:46:24,983 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Remove job-44040 from job monitoring
        
        2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
        2016-11-23 12:46:20,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-7534d4fd) (logid:ca865d0b) Schedule queued job-44041
        2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
        2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
        2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
        2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
        2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
        2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
        2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
        2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
        2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
        2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
        
        
        
        Best Regards,
        EtQ, Inc.
        Ghaith Bannoura
        Senior System Administrator
        MCT, MCSE (Messaging, Server Infrastructure)
        MCSA (Windows Server 2008, 2012), MCP
        
        *  Phone: +9626-537-0923 Ext. 376
        *  Gbannoura@etq.com <ma...@etq.com>
        *   http://www.etq.com<http://www.etq.com/>
        
        
    
    
    Dag.Sonstebo@shapeblue.com
    www.shapeblue.com
    53 Chandos Place, Covent Garden, London  WC2N 4HSUK @shapeblue
      
     
    
    


Dag.Sonstebo@shapeblue.com 
www.shapeblue.com
53 Chandos Place, Covent Garden, London  WC2N 4HSUK
@shapeblue
  
 


RE: Basic and Advanced Zone

Posted by Ghaith Bannoura <gb...@etq.com>.
Yes , I prepopulate the system VM templates and the SSVM and console proxy is running and the agent statues is running also 

Best Regards,
EtQ, Inc.
Ghaith Bannoura
Senior System Administrator
MCT, MCSE (Messaging, Server Infrastructure)
MCSA (Windows Server 2008, 2012), MCP 

   Phone: +9626-537-0923 Ext. 376
P  Gbannoura@etq.com 
G   http://www.etq.com

-----Original Message-----
From: Dag Sonstebo [mailto:Dag.Sonstebo@shapeblue.com] 
Sent: Wednesday, November 23, 2016 4:09 PM
To: users@cloudstack.apache.org
Subject: Re: Basic and Advanced Zone

Ghait,

Did you prepopulate the system VM template on the secondary storage share for the new advanced zone? Are your system VMs – SSVM and CPVM – running and healthy?

Regards,
Dag Sonstebo
Cloud Architect
ShapeBlue

On 23/11/2016, 13:59, "Ghaith Bannoura" <gb...@etq.com> wrote:

    Hi All,
    
    I have a basic zone with ACS 4.8 with xenserver 6.5 , I created a new advanced zone (Untagged for management , tagged for public and guest ) , after creating the advanced zone I tried to create an instance but an error appeared , I know that first vm once created it should be create a virtual router and I checked it and it was stopped and I can't start it , also I tried copy templates from basic zone to advanced zone with no luck ( failed to copy template I checked the logs and the error is connection refused ) .
    
    Below logs from management to create a new VM , can you please advise ?
    
    2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
    2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
    2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
    2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
    2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
    2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
    
    
    
    2016-11-23 12:46:19,109 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:a12b373b) Add job-44040 into job monitoring
    2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-10:ctx-cde514ac ctx-618855d1) (logid:7a08842b) submit async job-44040, details: AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
    2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Executing AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
    2016-11-23 12:46:19,136 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
    2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
    2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
    2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
    2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
    2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
    2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
    2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
    2016-11-23 12:46:20,906 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44042 execution on object VmWorkJobQueue.3307
    2016-11-23 12:46:22,895 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:56caed9e) Add job-44042 into job monitoring
    2016-11-23 12:46:22,907 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Executing AsyncJobVO {id:44042, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, cmdInfo: rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAADOt0ABVWTVNuYXBzaG90TWFuYWdlckltcGxw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:20 EET 2016}
    2016-11-23 12:46:22,907 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Run VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
    2016-11-23 12:46:22,908 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Execute VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
    2016-11-23 12:46:22,910 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
    2016-11-23 12:46:22,910 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Complete async job-44042, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
    2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Publish async job-44042 complete on message bus
    2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs related to job-44042
    2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Update db status for job-44042
    2016-11-23 12:46:22,912 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs joined with job-44042 and disjoin all subjobs created from job- 44042
    2016-11-23 12:46:22,916 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
    2016-11-23 12:46:22,916 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done executing com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-44042
    2016-11-23 12:46:22,917 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Remove job-44042 from job monitoring
    2016-11-23 12:46:22,928 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Error to Expunging with event: DestroyRequestedvm's original host id: null new host id: null host id before state transition: null
    2016-11-23 12:46:22,942 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44043 execution on object VmWorkJobQueue.3307
    2016-11-23 12:46:24,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:9d472300) Add job-44043 into job monitoring
    2016-11-23 12:46:24,886 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Executing AsyncJobVO {id:44043, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:22 EET 2016}
    2016-11-23 12:46:24,886 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:24,887 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:24,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Expunging
    2016-11-23 12:46:24,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:24,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Complete async job-44043, jobStatus: SUCCEEDED, resultCode: 0, result: null
    2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Publish async job-44043 complete on message bus
    2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs related to job-44043
    2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Update db status for job-44043
    2016-11-23 12:46:24,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs joined with job-44043 and disjoin all subjobs created from job- 44043
    2016-11-23 12:46:24,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:24,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44043
    2016-11-23 12:46:24,910 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Remove job-44043 from job monitoring
    2016-11-23 12:46:24,910 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Expunging to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null
    2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
    2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up NICS
    2016-11-23 12:46:24,910 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning network for vm: 3307
    2016-11-23 12:46:24,914 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Service SecurityGroup is not supported in the network id=209
    2016-11-23 12:46:24,917 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Asking VirtualRouter to release Nic[3307-3307-null-192.168.114.127]
    2016-11-23 12:46:24,923 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Deallocate network: networkId: 209, ip: 192.168.114.127
    2016-11-23 12:46:24,929 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) remove nic 3307 secondary ip
    2016-11-23 12:46:24,932 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed nic id=3307
    2016-11-23 12:46:24,933 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Revoving nic secondary ip entry ...
    2016-11-23 12:46:24,933 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage
    2016-11-23 12:46:24,934 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning storage for vm: 3307
    2016-11-23 12:46:24,936 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Expunged VM[User|i-2-3307-VM]
    2016-11-23 12:46:24,936 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Starting cleaning up vm VM[User|i-2-3307-VM] resources...
    2016-11-23 12:46:24,947 DEBUG [c.c.n.f.FirewallManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No firewall rules are found for vm id=3307
    2016-11-23 12:46:24,951 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Firewall rules are removed successfully as a part of vm id=3307 expunge
    2016-11-23 12:46:24,954 DEBUG [c.c.n.r.RulesManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No port forwarding rules are found for vm id=3307
    2016-11-23 12:46:24,954 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Port forwarding rules are removed successfully as a part of vm id=3307 expunge
    2016-11-23 12:46:24,956 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed vm id=3307 from all load balancers as a part of expunge process
    2016-11-23 12:46:24,957 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Successfully cleaned up vm VM[User|i-2-3307-VM] resources as a part of expunge process
    2016-11-23 12:46:24,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Complete async job-44040, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse/null/{"securitygroup":[],"nic":[],"tags":[],"affinitygroup":[]}
    2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Publish async job-44040 complete on message bus
    2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs related to job-44040
    2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Update db status for job-44040
    2016-11-23 12:46:24,977 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs joined with job-44040 and disjoin all subjobs created from job- 44040
    2016-11-23 12:46:24,983 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Done executing org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin for job-44040
    2016-11-23 12:46:24,983 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Remove job-44040 from job monitoring
    
    2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
    2016-11-23 12:46:20,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-7534d4fd) (logid:ca865d0b) Schedule queued job-44041
    2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
    2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
    2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
    2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
    2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
    2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
    
    
    
    Best Regards,
    EtQ, Inc.
    Ghaith Bannoura
    Senior System Administrator
    MCT, MCSE (Messaging, Server Infrastructure)
    MCSA (Windows Server 2008, 2012), MCP
    
    *  Phone: +9626-537-0923 Ext. 376
    *  Gbannoura@etq.com <ma...@etq.com>
    *   http://www.etq.com<http://www.etq.com/>
    
    


Dag.Sonstebo@shapeblue.com
www.shapeblue.com
53 Chandos Place, Covent Garden, London  WC2N 4HSUK @shapeblue
  
 


Re: Basic and Advanced Zone

Posted by Dag Sonstebo <Da...@shapeblue.com>.
Ghait,

Did you prepopulate the system VM template on the secondary storage share for the new advanced zone? Are your system VMs – SSVM and CPVM – running and healthy?

Regards,
Dag Sonstebo
Cloud Architect
ShapeBlue

On 23/11/2016, 13:59, "Ghaith Bannoura" <gb...@etq.com> wrote:

    Hi All,
    
    I have a basic zone with ACS 4.8 with xenserver 6.5 , I created a new advanced zone (Untagged for management , tagged for public and guest ) , after creating the advanced zone I tried to create an instance but an error appeared , I know that first vm once created it should be create a virtual router and I checked it and it was stopped and I can't start it , also I tried copy templates from basic zone to advanced zone with no luck ( failed to copy template I checked the logs and the error is connection refused ) .
    
    Below logs from management to create a new VM , can you please advise ?
    
    2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
    2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
    2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
    2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
    2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
    2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
    
    
    
    2016-11-23 12:46:19,109 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:a12b373b) Add job-44040 into job monitoring
    2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-10:ctx-cde514ac ctx-618855d1) (logid:7a08842b) submit async job-44040, details: AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
    2016-11-23 12:46:19,117 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Executing AsyncJobVO {id:44040, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 3307, cmd: org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo: {"response":"json","id":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxDetails":"{\"interface com.cloud.vm.VirtualMachine\":\"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c\"}","cmdEventType":"VM.DESTROY","ctxUserId":"2","httpmethod":"GET","_":"1479897977373","uuid":"8e3862b3-c0cd-40f4-93b6-8bb99daaed3c","ctxAccountId":"2","expunge":"true","ctxStartEventId":"86061"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
    2016-11-23 12:46:19,136 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
    2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
    2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
    2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
    2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
    2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
    2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
    2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
    2016-11-23 12:46:20,906 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44042 execution on object VmWorkJobQueue.3307
    2016-11-23 12:46:22,895 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:56caed9e) Add job-44042 into job monitoring
    2016-11-23 12:46:22,907 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Executing AsyncJobVO {id:44042, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, cmdInfo: rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAADOt0ABVWTVNuYXBzaG90TWFuYWdlckltcGxw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:20 EET 2016}
    2016-11-23 12:46:22,907 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Run VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
    2016-11-23 12:46:22,908 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Execute VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
    2016-11-23 12:46:22,910 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":3307,"handlerName":"VMSnapshotManagerImpl"}
    2016-11-23 12:46:22,910 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Complete async job-44042, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
    2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Publish async job-44042 complete on message bus
    2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs related to job-44042
    2016-11-23 12:46:22,911 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Update db status for job-44042
    2016-11-23 12:46:22,912 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042 ctx-f30788ef) (logid:0cdaace9) Wake up jobs joined with job-44042 and disjoin all subjobs created from job- 44042
    2016-11-23 12:46:22,916 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 3307, job origin: 44040
    2016-11-23 12:46:22,916 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Done executing com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-44042
    2016-11-23 12:46:22,917 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-5:ctx-edab2aa5 job-44040/job-44042) (logid:0cdaace9) Remove job-44042 from job monitoring
    2016-11-23 12:46:22,928 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Error to Expunging with event: DestroyRequestedvm's original host id: null new host id: null host id before state transition: null
    2016-11-23 12:46:22,942 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44043 execution on object VmWorkJobQueue.3307
    2016-11-23 12:46:24,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:9d472300) Add job-44043 into job monitoring
    2016-11-23 12:46:24,886 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Executing AsyncJobVO {id:44043, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:22 EET 2016}
    2016-11-23 12:46:24,886 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:24,887 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:24,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Expunging
    2016-11-23 12:46:24,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:24,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Complete async job-44043, jobStatus: SUCCEEDED, resultCode: 0, result: null
    2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Publish async job-44043 complete on message bus
    2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs related to job-44043
    2016-11-23 12:46:24,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Update db status for job-44043
    2016-11-23 12:46:24,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043 ctx-800cc88d) (logid:0cdaace9) Wake up jobs joined with job-44043 and disjoin all subjobs created from job- 44043
    2016-11-23 12:46:24,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:24,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44043
    2016-11-23 12:46:24,910 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-4:ctx-b018f78d job-44040/job-44043) (logid:0cdaace9) Remove job-44043 from job monitoring
    2016-11-23 12:46:24,910 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) VM state transitted from :Expunging to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null
    2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Destroying vm VM[User|i-2-3307-VM]
    2016-11-23 12:46:24,910 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up NICS
    2016-11-23 12:46:24,910 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning network for vm: 3307
    2016-11-23 12:46:24,914 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Service SecurityGroup is not supported in the network id=209
    2016-11-23 12:46:24,917 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Asking VirtualRouter to release Nic[3307-3307-null-192.168.114.127]
    2016-11-23 12:46:24,923 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Deallocate network: networkId: 209, ip: 192.168.114.127
    2016-11-23 12:46:24,929 DEBUG [c.c.n.g.DirectNetworkGuru] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) remove nic 3307 secondary ip
    2016-11-23 12:46:24,932 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed nic id=3307
    2016-11-23 12:46:24,933 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Revoving nic secondary ip entry ...
    2016-11-23 12:46:24,933 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage
    2016-11-23 12:46:24,934 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Cleaning storage for vm: 3307
    2016-11-23 12:46:24,936 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Expunged VM[User|i-2-3307-VM]
    2016-11-23 12:46:24,936 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Starting cleaning up vm VM[User|i-2-3307-VM] resources...
    2016-11-23 12:46:24,947 DEBUG [c.c.n.f.FirewallManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No firewall rules are found for vm id=3307
    2016-11-23 12:46:24,951 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Firewall rules are removed successfully as a part of vm id=3307 expunge
    2016-11-23 12:46:24,954 DEBUG [c.c.n.r.RulesManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) No port forwarding rules are found for vm id=3307
    2016-11-23 12:46:24,954 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Port forwarding rules are removed successfully as a part of vm id=3307 expunge
    2016-11-23 12:46:24,956 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Removed vm id=3307 from all load balancers as a part of expunge process
    2016-11-23 12:46:24,957 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Successfully cleaned up vm VM[User|i-2-3307-VM] resources as a part of expunge process
    2016-11-23 12:46:24,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Complete async job-44040, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse/null/{"securitygroup":[],"nic":[],"tags":[],"affinitygroup":[]}
    2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Publish async job-44040 complete on message bus
    2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs related to job-44040
    2016-11-23 12:46:24,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Update db status for job-44040
    2016-11-23 12:46:24,977 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Wake up jobs joined with job-44040 and disjoin all subjobs created from job- 44040
    2016-11-23 12:46:24,983 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Done executing org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin for job-44040
    2016-11-23 12:46:24,983 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-35:ctx-110f9706 job-44040) (logid:0cdaace9) Remove job-44040 from job monitoring
    
    2016-11-23 12:46:19,143 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-35:ctx-110f9706 job-44040 ctx-02764119) (logid:0cdaace9) Sync job-44041 execution on object VmWorkJobQueue.3307
    2016-11-23 12:46:20,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-7534d4fd) (logid:ca865d0b) Schedule queued job-44041
    2016-11-23 12:46:20,877 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:c02108f7) Add job-44041 into job monitoring
    2016-11-23 12:46:20,884 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Executing AsyncJobVO {id:44041, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAM63QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 144344642087, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 23 12:46:19 EET 2016}
    2016-11-23 12:46:20,885 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Run VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,886 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Stopped called on VM[User|i-2-3307-VM] but the state is Error
    2016-11-23 12:46:20,890 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":3307,"handlerName":"VirtualMachineManagerImpl"}
    2016-11-23 12:46:20,890 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Complete async job-44041, jobStatus: SUCCEEDED, resultCode: 0, result: null
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Publish async job-44041 complete on message bus
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs related to job-44041
    2016-11-23 12:46:20,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Update db status for job-44041
    2016-11-23 12:46:20,892 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041 ctx-89e12346) (logid:0cdaace9) Wake up jobs joined with job-44041 and disjoin all subjobs created from job- 44041
    2016-11-23 12:46:20,896 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 3307, job origin: 44040
    2016-11-23 12:46:20,896 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Done executing com.cloud.vm.VmWorkStop for job-44041
    2016-11-23 12:46:20,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-6:ctx-8e326052 job-44040/job-44041) (logid:0cdaace9) Remove job-44041 from job monitoring
    
    
    
    Best Regards,
    EtQ, Inc.
    Ghaith Bannoura
    Senior System Administrator
    MCT, MCSE (Messaging, Server Infrastructure)
    MCSA (Windows Server 2008, 2012), MCP
    
    *  Phone: +9626-537-0923 Ext. 376
    *  Gbannoura@etq.com <ma...@etq.com>
    *   http://www.etq.com<http://www.etq.com/>
    
    


Dag.Sonstebo@shapeblue.com 
www.shapeblue.com
53 Chandos Place, Covent Garden, London  WC2N 4HSUK
@shapeblue
  
 


Re: Basic and Advanced Zone

Posted by Sergey Levitskiy <Se...@autodesk.com>.
You log is not complete. Can you extract the log that covers full period of job execution and publish it?