[ 
https://issues.apache.org/jira/browse/CLOUDSTACK-7623?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14146587#comment-14146587
 ] 

Anthony Xu commented on CLOUDSTACK-7623:
----------------------------------------

> Waited for 0seconds
The cause is it is trying to acquire DB table lock with timeout 0, if there is 
any contention for the lock, the lock acquisition will fail due to timeout, the 
code doesn't check if it acquires the lock successfully, and continues the 
execution, it means without the checkout, the code will execute without getting 
the lock, which is wrong. looks like "return false" hide this issue, which may 
cause other DB issue later, and is very hard debug, 
I'll remove the exception to unblock QA, call stack trace will be still logged.

                _vmDao.lockInLockTable(String.valueOf(vm.getId()), 
Integer.MAX_VALUE);
                try {
                    List<VmWorkJobVO> pendingWorkJobs = 
_workJobDao.listPendingWorkJobs(VirtualMachine.Type.Instance,
                            vm.getId(), VmWorkStart.class.getName());


> SystemVMs not starting
> ----------------------
>
>                 Key: CLOUDSTACK-7623
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7623
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the 
> default.) 
>          Components: SystemVM
>    Affects Versions: 4.5.0
>            Reporter: Pavan Kumar Bandarupally
>            Priority: Blocker
>             Fix For: 4.5.0
>
>         Attachments: management-server.log
>
>
> After installing latest Management Server and zone creation, system VMs are 
> not getting created. The following exception is being generated:
> 2014-09-24 17:37:17,918 WARN  [c.c.u.d.Merovingian2] 
> (consoleproxy-1:ctx-bc88696c) Timed out on acquiring lock vm_instance1 .  
> Waited for 0seconds
> 2014-09-24 17:37:17,919 WARN  [c.c.c.ConsoleProxyManagerImpl] 
> (consoleproxy-1:ctx-bc88696c) Runtime Exception while trying to start console 
> proxy
> com.cloud.utils.exception.CloudRuntimeException: Timed out on acquiring lock 
> vm_instance1 .  Waited for 0seconds
>         at com.cloud.utils.db.Merovingian2.acquire(Merovingian2.java:143)
>         at 
> com.cloud.utils.db.TransactionLegacy.lock(TransactionLegacy.java:389)
>         at 
> com.cloud.utils.db.GenericDaoBase.lockInLockTable(GenericDaoBase.java:1057)
>         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:601)
>         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.utils.db.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:34)
>         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 $Proxy53.lockInLockTable(Unknown Source)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl$3.doInTransaction(VirtualMachineManagerImpl.java:3927)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl$3.doInTransaction(VirtualMachineManagerImpl.java:3922)
>         at 
> com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.java:49)
>         at com.cloud.utils.db.Transaction.execute(Transaction.java:37)
>         at com.cloud.utils.db.Transaction.execute(Transaction.java:46)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.startVmThroughJobQueue(VirtualMachineManagerImpl.java:3922)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:769)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:748)
>         at 
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:540)
>         at 
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:919)
>         at 
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1640)
>         at 
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
>         at 
> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:120)
>         at 
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
>         at 
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:90)
>         at 
> com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:81)
>         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.innerRunAndReset(FutureTask.java:351)
>         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>         at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>         at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>         at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:722)



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to