You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users-cn@cloudstack.apache.org by 以落。 <31...@qq.com> on 2015/11/10 09:27:31 UTC
ssvm 和cpvm 都无法启动
ssvm 和cpvm 都无法启动 感觉像是在无限循环了 看不出问题处在哪里
哪位大神帮我看看吧 下面是 log
INFO [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-e39320da) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 12, will recycle it and start a new one
INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-e39320da) Primary secondary storage is not even started, wait until next turn
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-7:ctx-cfe772e5 job-102/job-108) Remove job-108 from job monitoring
INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-29d0c34a) No running secondary storage vms found in datacenter id=1, starting one
INFO [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-29d0c34a) Found a stopped secondary storage vm, bring it up to running pool. secStorageVm vm id : 12
WARN [c.c.u.d.Merovingian2] (secstorage-1:ctx-29d0c34a) Was unable to find lock for the key vm_instance12 and thread id 1371007373
INFO [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-8:ctx-a268d7da job-103/job-109 ctx-5821245d) Unable to acquire lock on VMTemplateStoragePool 20
ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-8:ctx-a268d7da job-103/job-109 ctx-5821245d) Failed to start instance VM[ConsoleProxy|v-8-VM]
com.cloud.utils.exception.CloudRuntimeException: Unable to acquire lock on VMTemplateStoragePool: 20
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:486)
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:745)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1200)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1264)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:988)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5201)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5346)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-7:ctx-94f9dbc8) VM does not exist on XenServerb129251d-2108-4673-8838-d925ba3f0479
ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-8:ctx-a268d7da job-103/job-109 ctx-5821245d) Invocation exception, caused by: com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to acquire lock on VMTemplateStoragePool: 20
INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-8:ctx-a268d7da job-103/job-109 ctx-5821245d) Rethrow exception com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to acquire lock on VMTemplateStoragePool: 20
ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-8:ctx-a268d7da job-103/job-109) Unable to complete AsyncJobVO {id:109, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAACHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 159090355862550, completeMsid: null, lastUpdated: null, lastPolled: null, created: Tue Nov 10 16:09:55 CST 2015}, job origin:103
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to acquire lock on VMTemplateStoragePool: 20
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1109)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5201)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5346)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: com.cloud.utils.exception.CloudRuntimeException: Unable to acquire lock on VMTemplateStoragePool: 20
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:486)
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:745)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1200)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1264)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:988)
... 20 more
WARN [c.c.v.SystemVmLoadScanner] (consoleproxy-1:ctx-222f56f0) Unexpected exception Job failed due to exception Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to acquire lock on VMTemplateStoragePool: 20
java.lang.RuntimeException: Job failed due to exception Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to acquire lock on VMTemplateStoragePool: 20
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:114)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-8:ctx-a268d7da job-103/job-109) Remove job-109 from job monitoring
INFO [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-76544270) Found a stopped console proxy, bring it up to running pool. proxy vm id : 8
WARN [c.c.u.d.Merovingian2] (consoleproxy-1:ctx-76544270) Was unable to find lock for the key vm_instance8 and thread id 1446320224
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-9:ctx-f7012812 job-102/job-110) Add job-110 into job monitoring
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-10:ctx-0807e6eb job-103/job-111) Add job-111 into job monitoring
INFO [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-10:ctx-0807e6eb job-103/job-111 ctx-90e65a40) lock is acquired for VMTemplateStoragePool 21
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-c2089bc8) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-c2089bc8) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (DirectAgent-15:ctx-96794019) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-3:ctx-903b1ab8) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-3:ctx-903b1ab8) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-cdbaa06e) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-cdbaa06e) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (DirectAgent-9:ctx-e9071a80) not building log message for '[{}]', _cmds.length == 1
WARN [o.a.c.f.j.i.AsyncJobMonitor] (Timer-1:ctx-2adf5b71) Task (job-110) has been pending for 96 seconds
WARN [o.a.c.f.j.i.AsyncJobMonitor] (Timer-1:ctx-2adf5b71) Task (job-111) has been pending for 96 seconds
INFO [c.c.v.VirtualMachineManagerImpl] (DirectAgentCronJob-5:ctx-c97cfd42) There is pending job or HA tasks working on the VM. vm id: 8, postpone power-change report by resetting power-change counters
INFO [c.c.v.VirtualMachineManagerImpl] (DirectAgentCronJob-5:ctx-c97cfd42) There is pending job or HA tasks working on the VM. vm id: 12, postpone power-change report by resetting power-change counters
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-140cd554) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-140cd554) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (DirectAgent-17:ctx-4d95eace) not building log message for '[{}]', _cmds.length == 1
WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-16:ctx-4b1ce10b) GetStorageStats Exception:SR_BACKEND_FAILURE_40The SR scan failed [opterr=uuid=5e81f518-d0ef-40cc-ad47-3092b44ee13b]host:b129251d-2108-4673-8838-d925ba3f0479storageid: 2b9c085f-28fc-3e67-bd67-fed9c73de391
INFO [c.c.a.t.Request] (DirectAgent-16:ctx-4b1ce10b) not building log message for '[{}]', _cmds.length == 1
WARN [o.a.c.f.j.i.AsyncJobMonitor] (Timer-1:ctx-1a0a2acc) Task (job-110) has been pending for 156 seconds
WARN [o.a.c.f.j.i.AsyncJobMonitor] (Timer-1:ctx-1a0a2acc) Task (job-111) has been pending for 156 seconds
WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-14:ctx-728ef2df) failed to dd /var/run/cloud_mount/e5f7af61-726f-4088-aa09-c89f0c9ab969//cc0c4380-5926-48c4-a09b-58a2f21d42f3.vhd to /var/run/sr-mount/1f02bdf4-6b29-9ba4-deca-1f5caff59c18/42bd3965-0622-4085-a142-ed42a773b123.vhd
WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-14:ctx-728ef2df) Catch Exception com.cloud.utils.exception.CloudRuntimeException for template + due to com.cloud.utils.exception.CloudRuntimeException: failed to dd /var/run/cloud_mount/e5f7af61-726f-4088-aa09-c89f0c9ab969//cc0c4380-5926-48c4-a09b-58a2f21d42f3.vhd to /var/run/sr-mount/1f02bdf4-6b29-9ba4-deca-1f5caff59c18/42bd3965-0622-4085-a142-ed42a773b123.vhd
com.cloud.utils.exception.CloudRuntimeException: failed to dd /var/run/cloud_mount/e5f7af61-726f-4088-aa09-c89f0c9ab969//cc0c4380-5926-48c4-a09b-58a2f21d42f3.vhd to /var/run/sr-mount/1f02bdf4-6b29-9ba4-deca-1f5caff59c18/42bd3965-0622-4085-a142-ed42a773b123.vhd
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.copy_vhd_from_secondarystorage(XenServerStorageProcessor.java:846)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.copyTemplateToPrimaryStorage(XenServerStorageProcessor.java:962)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:77)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:52)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:542)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:308)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
INFO [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-10:ctx-0807e6eb job-103/job-111 ctx-90e65a40) releasing lock for VMTemplateStoragePool 21
WARN [c.c.u.d.Merovingian2] (Work-Job-Executor-10:ctx-0807e6eb job-103/job-111 ctx-90e65a40) Was unable to find lock for the key template_spool_ref21 and thread id 1121758754
INFO [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-10:ctx-0807e6eb job-103/job-111 ctx-90e65a40) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[8|vm=8|ROOT]:Catch Exception com.cloud.utils.exception.CloudRuntimeException for template + due to com.cloud.utils.exception.CloudRuntimeException: failed to dd /var/run/cloud_mount/e5f7af61-726f-4088-aa09-c89f0c9ab969//cc0c4380-5926-48c4-a09b-58a2f21d42f3.vhd to /var/run/sr-mount/1f02bdf4-6b29-9ba4-deca-1f5caff59c18/42bd3965-0622-4085-a142-ed42a773b123.vhd
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1212)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1264)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:988)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5201)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5346)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-3:ctx-36ab038c) VM does not exist on XenServerb129251d-2108-4673-8838-d925ba3f0479
ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-10:ctx-0807e6eb job-103/job-111 ctx-90e65a40) Invocation exception, caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-8-VM]Scope=interface com.cloud.dc.DataCenter; id=1
INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-10:ctx-0807e6eb job-103/job-111 ctx-90e65a40) Rethrow exception com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-8-VM]Scope=interface com.cloud.dc.DataCenter; id=1
ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-10:ctx-0807e6eb job-103/job-111) Unable to complete AsyncJobVO {id:111, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAACHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 159090355862550, completeMsid: null, lastUpdated: null, lastPolled: null, created: Tue Nov 10 16:12:42 CST 2015}, job origin:103
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-8-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:947)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5201)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5346)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
WARN [c.c.v.SystemVmLoadScanner] (consoleproxy-1:ctx-76544270) Unexpected exception Job failed due to exception Unable to create a deployment for VM[ConsoleProxy|v-8-VM]
java.lang.RuntimeException: Job failed due to exception Unable to create a deployment for VM[ConsoleProxy|v-8-VM]
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:114)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-10:ctx-0807e6eb job-103/job-111) Remove job-111 from job monitoring
INFO [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-e5d3d6a5) Found a stopped console proxy, bring it up to running pool. proxy vm id : 8
WARN [c.c.u.d.Merovingian2] (consoleproxy-1:ctx-e5d3d6a5) Was unable to find lock for the key vm_instance8 and thread id 1446320224
INFO [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-9:ctx-f7012812 job-102/job-110 ctx-3a6d29ad) Unable to acquire lock on VMTemplateStoragePool 21
ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-9:ctx-f7012812 job-102/job-110 ctx-3a6d29ad) Failed to start instance VM[SecondaryStorageVm|s-12-VM]
com.cloud.utils.exception.CloudRuntimeException: Unable to acquire lock on VMTemplateStoragePool: 21
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:486)
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:745)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1200)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1264)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:988)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5201)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5346)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-4:ctx-ea4d1f81) VM does not exist on XenServerb129251d-2108-4673-8838-d925ba3f0479
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-11:ctx-f435f359 job-103/job-112) Add job-112 into job monitoring
ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-9:ctx-f7012812 job-102/job-110 ctx-3a6d29ad) Invocation exception, caused by: com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to acquire lock on VMTemplateStoragePool: 21
INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-9:ctx-f7012812 job-102/job-110 ctx-3a6d29ad) Rethrow exception com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to acquire lock on VMTemplateStoragePool: 21
ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-9:ctx-f7012812 job-102/job-110) Unable to complete AsyncJobVO {id:110, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAADHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 159090355862550, completeMsid: null, lastUpdated: null, lastPolled: null, created: Tue Nov 10 16:12:42 CST 2015}, job origin:102
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to acquire lock on VMTemplateStoragePool: 21
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1109)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5201)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5346)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: com.cloud.utils.exception.CloudRuntimeException: Unable to acquire lock on VMTemplateStoragePool: 21
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:486)
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:745)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1200)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1264)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:988)
... 20 more
WARN [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-29d0c34a) Exception while trying to start secondary storage vm
java.lang.RuntimeException: Job failed due to exception Resource [Host:1] is unreachable: Host 1: Unable to start instance due to Unable to acquire lock on VMTemplateStoragePool: 21
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:114)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
INFO [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-29d0c34a) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 12, will recycle it and start a new one
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-9:ctx-f7012812 job-102/job-110) Remove job-110 from job monitoring
WARN [c.c.u.d.Merovingian2] (secstorage-1:ctx-29d0c34a) Was unable to find lock for the key vm_instance12 and thread id 1371007373
INFO [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-11:ctx-f435f359 job-103/job-112 ctx-ddd6a538) lock is acquired for VMTemplateStoragePool 22
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-12:ctx-8a717c03 job-102/job-113) Add job-113 into job monitoring
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-12:ctx-8a717c03 job-102/job-113) Remove job-113 from job monitoring
INFO [o.a.c.s.v.VolumeServiceImpl] (secstorage-1:ctx-29d0c34a) Expunge volume with no data store specified
INFO [o.a.c.s.v.VolumeServiceImpl] (secstorage-1:ctx-29d0c34a) Volume 12 is not referred anywhere, remove it from volumes table
INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-29d0c34a) Primary secondary storage is not even started, wait until next turn
INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-ccfc02d7) No running secondary storage vms found in datacenter id=1, starting one
INFO [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-ccfc02d7) No stopped secondary storage vm is available, need to allocate a new secondary storage vm
WARN [c.c.u.d.Merovingian2] (secstorage-1:ctx-ccfc02d7) Was unable to find lock for the key vm_instance13 and thread id 1371007373
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-13:ctx-6408a4e1 job-102/job-114) Add job-114 into job monitoring
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-bf5ecc34) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-bf5ecc34) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (DirectAgent-18:ctx-a68f9bf6) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-3:ctx-8e0f6fa4) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-3:ctx-8e0f6fa4) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Worker-0:ctx-090a8498 work-1) Processing HAWork[1-HA-11-Starting-Investigating]
INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Worker-2:ctx-9820301f work-2) Processing HAWork[2-HA-8-Starting-Investigating]
INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Worker-0:ctx-090a8498 work-1) Unable to find vm: 11
INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Worker-0:ctx-090a8498 work-1) Completed HAWork[1-HA-11-Starting-Investigating]
INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Worker-2:ctx-9820301f work-2) HA on VM[ConsoleProxy|v-8-VM]
INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Worker-2:ctx-9820301f work-2) VM VM[ConsoleProxy|v-8-VM] has been changed. Current State = Starting Previous State = Starting last updated = 38 previous updated = 23
INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Worker-2:ctx-9820301f work-2) Completed HAWork[2-HA-8-Starting-Investigating]
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-6fa60d7e) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (StatsCollector-1:ctx-6fa60d7e) not building log message for '[{}]', _cmds.length == 1
INFO [c.c.a.t.Request] (DirectAgent-19:ctx-69c54356) not building log message for '[{}]', _cmds.length == 1
WARN [o.a.c.f.j.i.AsyncJobMonitor] (Timer-1:ctx-cd84b77d) Task (job-112) has been pending for 114 seconds
WARN [o.a.c.f.j.i.AsyncJobMonitor] (Timer-1:ctx-cd84b77d) Task (job-114) has been pending for 110 seconds