angeline shen created CLOUDSTACK-1587:
-----------------------------------------
Summary: Basic zone - CPVM fail to go to running state, Exception
while trying to start secondary storage vm
Key: CLOUDSTACK-1587
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-1587
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Management Server
Affects Versions: 4.1.0
Environment: MS rhel6.3 ASF 4.1 build 75 latest build
MArch 6 2013 10:52 PM
host xen 6.0.2
Reporter: angeline shen
Priority: Blocker
Fix For: 4.1.0
1. Create basic zone, CPVM fail to go to running state, Exception while
trying to start secondary storage vm
2013-03-07 16:41:17,921 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) VM is being created in podId: 1
2013-03-07 16:41:17,923 INFO [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Found a stopped console proxy, bring it up to running
pool. proxy vm id : 2
2013-03-07 16:41:17,926 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is acquired for network id 204 as a part of network
implement
2013-03-07 16:41:17,926 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Network id=204 is already implemented
2013-03-07 16:41:17,928 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is released for network id 204 as a part of network
implement
2013-03-07 16:41:17,939 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) VM state transitted from :Stopped to Starting with event:
StartRequestedvm's original host id: null new host id: null host id before
state transit
ion: null
2013-03-07 16:41:17,939 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully transitioned to start state for
VM[ConsoleProxy|v-2-VM] reservation id = 43a36eba-a6d9-4eaf-871a-1e8d7c87fce4
2013-03-07 16:41:17,985 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and podId: 1
2013-03-07 16:41:17,985 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2013-03-07 16:41:20,401 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-140:null) destoryVDIbyNameLabel failed due to there are 0 VDIs
with name cloud-8f369cd6-30d3-4999-9e0d-a7343d3cf5cb
2013-03-07 16:41:20,402 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-140:null) can not create vdi in sr
6c9dbc6e-4c8b-bb87-334d-e3dfc9f71868
2013-03-07 16:41:20,402 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-140:null) Catch Exception
com.cloud.utils.exception.CloudRuntimeException on
host:9b41daec-b1e5-4d9b-b762-99107f89433c for template:
nfs://10.223.110.232/export/home/angie/secondary/xen30/template/tmpl/1/1/ due
to com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
6c9dbc6e-4c8b-bb87-334d-e3dfc9f71868
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
6c9dbc6e-4c8b-bb87-334d-e3dfc9f71868
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2703)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2725)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:501)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
at
com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2013-03-07 16:41:20,402 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-140:null) Seq 1-1799225602: Response Received:
2013-03-07 16:41:20,403 DEBUG [agent.transport.Request] (DirectAgent-140:null)
Seq 1-1799225602: Processing: { Ans: , MgmtId: 6655051826959, via: 1, Ver: v1,
Flags: 110,
[{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Catch
Exception com.cloud.utils.exception.CloudRuntimeException on
host:9b41daec-b1e5-4d9b-b762-99107f89433c for template:
nfs://10.223.110.232/export/home/angie/secondary/xen30/template/tmpl/1/1/ due
to com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
6c9dbc6e-4c8b-bb87-334d-e3dfc9f71868","wait":0}}] }
2013-03-07 16:41:20,403 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1799225602: Received: { Ans: , MgmtId: 6655051826959, via: 1, Ver: v1,
Flags: 110, { PrimaryStorageDownloadAnswer } }
2013-03-07 16:41:20,403 DEBUG [agent.manager.AgentManagerImpl]
(secstorage-1:null) Details from executing class
com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception
com.cloud.utils.exception.CloudRuntimeException on
host:9b41daec-b1e5-4d9b-b762-99107f89433c for template:
nfs://10.223.110.232/export/home/angie/secondary/xen30/template/tmpl/1/1/ due
to com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
6c9dbc6e-4c8b-bb87-334d-e3dfc9f71868
2013-03-07 16:41:20,403 DEBUG [cloud.template.TemplateManagerImpl]
(secstorage-1:null) Template 1 download to pool 200 failed due to Catch
Exception com.cloud.utils.exception.CloudRuntimeException on
host:9b41daec-b1e5-4d9b-b762-99107f89433c for template:
nfs://10.223.110.232/export/home/angie/secondary/xen30/template/tmpl/1/1/ due
to com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
6c9dbc6e-4c8b-bb87-334d-e3dfc9f71868
2013-03-07 16:41:20,403 DEBUG [cloud.template.TemplateManagerImpl]
(secstorage-1:null) Downloading 1 via 1
2013-03-07 16:41:20,408 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1799225603: Waiting for Seq 1799225602 Scheduling: { Cmd , MgmtId:
6655051826959, via: 1, Ver: v1, Flags: 100111, [{"storage.PrimaryStor
2013-03-07 16:41:22,619 DEBUG [agent.manager.AgentAttache]
(DirectAgent-141:null) Seq 1-1799225603: No more commands found
2013-03-07 16:41:22,622 INFO [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:200] is
unreachable: Unable to create Vol[21|vm=21|ROOT]
at
com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3472)
at sun.reflect.GeneratedMethodAccessor205.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at
com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(TransactionContextBuilder.java:37)
at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at
org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy112.prepare(Unknown Source)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:738)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:461)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:454)
at sun.reflect.GeneratedMethodAccessor198.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at
com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(TransactionContextBuilder.java:37)
at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at
org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy192.start(Unknown Source)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:264)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:689)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
at
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
at
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
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$201(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
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:679)
2013-03-07 16:41:22,626 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Cleaning up resources for the vm
VM[SecondaryStorageVm|s-21-VM] in Starting state
2013-03-07 16:41:22,627 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1799225604: Sending { Cmd , MgmtId: 6655051826959, via: 1, Ver: v1, Flags:
100111, [{"StopCommand":{"isProxy":false,"vmName":"s-21-VM","wait":0}}] }
2013-03-07 16:41:22,628 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1799225604: Executing: { Cmd , MgmtId: 6655051826959, via: 1, Ver: v1,
Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"s-21-VM","wait":0}}] }
2013-03-07 16:41:22,628 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-31:null) Seq 1-1799225604: Executing request
2013-03-07 16:41:22,711 INFO [xen.resource.CitrixResourceBase]
(DirectAgent-31:null) VM does not exist on
XenServer9b41daec-b1e5-4d9b-b762-99107f89433c
2013-03-07 16:41:22,711 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-31:null) Seq 1-1799225604: Response Received:
2013-03-07 16:41:22,712 DEBUG [agent.transport.Request] (DirectAgent-31:null)
Seq 1-1799225604: Processing: { Ans: , MgmtId: 6655051826959, via: 1, Ver: v1,
Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM does not
exist","wait":0}}] }
2013-03-07 16:41:22,778 WARN [storage.secondary.SecondaryStorageManagerImpl]
(secstorage-1:null) Exception while trying to start secondary storage vm
java.lang.NullPointerException
at
com.cloud.agent.manager.allocator.impl.RecreateHostAllocator.allocateTo(RecreateHostAllocator.java:95)
at sun.reflect.GeneratedMethodAccessor155.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at
com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(TransactionContextBuilder.java:37)
at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at
org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy267.allocateTo(Unknown Source)
at
com.cloud.deploy.FirstFitPlanner.findSuitableHosts(FirstFitPlanner.java:713)
at
com.cloud.deploy.FirstFitPlanner.checkClustersforDestination(FirstFitPlanner.java:520)
at
com.cloud.deploy.FirstFitPlanner.scanClustersForDestinationInZoneOrPod(FirstFitPlanner.java:388)
at com.cloud.deploy.FirstFitPlanner.plan(FirstFitPlanner.java:278)
at sun.reflect.GeneratedMethodAccessor173.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at
com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(TransactionContextBuilder.java:37)
at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at
org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy290.plan(Unknown Source)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:699)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:461)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:454)
at sun.reflect.GeneratedMethodAccessor198.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at
com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(TransactionContextBuilder.java:37)
at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
