Just to update on the status.
This 200GB templates, was eventually copied over to CEPH, and base image
was created I guess.
So after 1-2h I tried to deploy new VM from this template, and since the
differential/linked-clone disk was used as usual... new VM was deployed
fine.
So, is there any global timeout that I would need to increae - since VM did
timeout after ~ 30min as client reported, but the Storage/Network is
obviously kind of slow and it takes more than 30min or so, to transfer from
Secondary to Primary...
Please advise.
Thanks,
Andrija
On 26 February 2015 at 12:26, Andrija Panic <andrija.pa...@gmail.com> wrote:
> Hi,
>
> I just had client upload 200GB volume/template, and tried to deploy new VM
> from it.
>
> GUI timeout after ~ 30min - saying VM is now in Error state, but for some
> time after th VM error out, I coul see ROOT-xxx volume being created on
> CEPH - and timestamp updated regularry in "volumes" table in database - and
> after this, ROOT-xxx went into destroyed state.
>
> From MGMT logs I could see almost hunderds of messages like the first 2
> lines from the log below, and then complete failure as can be seen from
> MGMT logs.
>
> Any help would be really appreciated since this is LIVE enviroment, ACS
> 4.3.0.
>
> Thanks,
>
> 2015-02-26 12:07:05,238 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Job-Executor-145:ctx-3609c7c0 ctx-b101c9c8) Waiting some more to make sure
> there's no activity on VM[User|DNG-ACC]
> 2015-02-26 12:07:05,303 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Job-Executor-140:ctx-0f9aa245 ctx-7db9ecb6) Waiting some more to make sure
> there's no activity on VM[User|DNG-ACC]
> 2015-02-26 12:07:05,305 WARN [c.c.v.VirtualMachineManagerImpl]
> (Job-Executor-140:ctx-0f9aa245 ctx-7db9ecb6) The task item for vm
> VM[User|DNG-ACC] has been inactive for 3660
> 2015-02-26 12:07:05,360 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Job-Executor-145:ctx-3609c7c0 ctx-b101c9c8) Waiting some more to make sure
> there's no activity on VM[User|DNG-ACC]
> 2015-02-26 12:07:05,382 ERROR [c.c.a.ApiAsyncJobDispatcher]
> (Job-Executor-140:ctx-0f9aa245) Unexpected exception while executing
> org.apache.cloudstack.api.command.user.vm.StartVMCmd
> com.cloud.utils.exception.CloudRuntimeException: Unable to start a VM due
> to concurrent operation
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:603)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:207)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3581)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2043)
> 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:622)
> at
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at
> com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
> at
> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at com.sun.proxy.$Proxy169.startVirtualMachine(Unknown Source)
> at
> org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:121)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
> at
> com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
> at
> com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
> 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
> com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:509)
> 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$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:701)
> Caused by: com.cloud.exception.ConcurrentOperationException: There are
> concurrent operations on VM[User|DNG-ACC]
> at
> com.cloud.vm.VirtualMachineManagerImpl.changeToStartState(VirtualMachineManagerImpl.java:701)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:800)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:601)
> ... 37 more
> 2015-02-26 12:07:05,384 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Job-Executor-140:ctx-0f9aa245) Complete async job-20629, jobStatus:
> FAILED, resultCode: 530, result:
> org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable
> to start a VM due to concurrent operation"}
> 2015-02-26 12:07:05,385 DEBUG [c.c.a.t.Request]
> (AgentManager-Handler-2:null) Seq 22-1291533430: Processing: { Ans: ,
> MgmtId: 161344838950, via: 22, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.NetworkUsageAnswer":{"routerName":"r-1210-VM","bytesSent":5871992,"bytesReceived":5502153,"result":true,"details":"","wait":0}}]
> }
> 2015-02-26 12:07:05,385 DEBUG [c.c.a.t.Request]
> (RouterMonitor-1:ctx-98de907f) Seq 22-1291533430: Received: { Ans: ,
> MgmtId: 161344838950, via: 22, Ver: v1, Flags: 10, { NetworkUsageAnswer } }
> 2015-02-26 12:07:05,385 DEBUG [c.c.a.m.AgentManagerImpl]
> (RouterMonitor-1:ctx-98de907f) Details from executing class
> com.cloud.agent.api.NetworkUsageCommand:
> 2015-02-26 12:07:05,415 DEBUG [c.c.a.t.Request]
> (AgentManager-Handler-10:null) Seq 22-1291533431: Processing: { Ans: ,
> MgmtId: 161344838950, via: 22, Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.CheckS2SVpnConnectionsAnswer":{"ipToConnected":{},"ipToDetail":{},"details":"CheckS2SVpnConneciontsCommand
> failed","result":false,"wait":0}}] }
> 2015-02-26 12:07:05,415 DEBUG [c.c.a.m.AgentAttache]
> (AgentManager-Handler-10:null) Seq 22-1291533431: No more commands found
> 2015-02-26 12:07:05,415 DEBUG [c.c.a.t.Request]
> (RouterStatusMonitor-1:ctx-7173341a) Seq 22-1291533431: Received: { Ans: ,
> MgmtId: 161344838950, via: 22, Ver: v1, Flags: 110, {
> CheckS2SVpnConnectionsAnswer } }
> 2015-02-26 12:07:05,415 DEBUG [c.c.a.m.AgentManagerImpl]
> (RouterStatusMonitor-1:ctx-7173341a) Details from executing class
> com.cloud.agent.api.CheckS2SVpnConnectionsCommand:
> CheckS2SVpnConneciontsCommand failed
> 2015-02-26 12:07:05,415 WARN [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-7173341a) Unable to update router r-1996-VM's
> VPN connection status
> 2015-02-26 12:07:05,416 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-7173341a) Found 0 networks to update RvR status.
> 2015-02-26 12:07:05,430 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Job-Executor-140:ctx-0f9aa245) Done executing
> org.apache.cloudstack.api.command.user.vm.StartVMCmd for job-20629
> 2015-02-26 12:07:05,433 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Job-Executor-140:ctx-0f9aa245) Remove job-20629 from job monitoring
> 2015-02-26 12:07:05,482 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Job-Executor-145:ctx-3609c7c0 ctx-b101c9c8) Waiting some more to make sure
> there's no activity on VM[User|DNG-ACC]
> 2015-02-26 12:07:05,484 WARN [c.c.v.VirtualMachineManagerImpl]
> (Job-Executor-145:ctx-3609c7c0 ctx-b101c9c8) The task item for vm
> VM[User|DNG-ACC] has been inactive for 3660
> 2015-02-26 12:07:05,519 ERROR [c.c.a.ApiAsyncJobDispatcher]
> (Job-Executor-145:ctx-3609c7c0) Unexpected exception while executing
> org.apache.cloudstack.api.command.user.vm.StartVMCmd
> com.cloud.utils.exception.CloudRuntimeException: Unable to start a VM due
> to concurrent operation
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:603)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:207)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3581)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2043)
> 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:622)
> at
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at
> com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
> at
> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at com.sun.proxy.$Proxy169.startVirtualMachine(Unknown Source)
> at
> org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:121)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
> at
> com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
> at
> com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
> 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
> com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:509)
> 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$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> Caused by: com.cloud.exception.ConcurrentOperationException: There are
> concurrent operations on VM[User|DNG-ACC]
> at
> com.cloud.vm.VirtualMachineManagerImpl.changeToStartState(VirtualMachineManagerImpl.java:701)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:800)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:601)
> ... 37 more
> 2015-02-26 12:07:05,520 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Job-Executor-145:ctx-3609c7c0) Complete async job-20635, jobStatus:
> FAILED, resultCode: 530, result:
> org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable
> to start a VM due to concurrent operation"}
>
> --
>
> Andrija Panić
>
--
Andrija Panić
