[ https://issues.apache.org/jira/browse/CLOUDSTACK-1587?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
angeline shen updated CLOUDSTACK-1587: -------------------------------------- Attachment: management-server.log.gz Screenshot-CloudStack - Mozilla Firefox-2.png Screenshot-CloudStack - Mozilla Firefox-1.png Screenshot-CloudStack - Mozilla Firefox.png > 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 > > Attachments: management-server.log.gz, Screenshot-CloudStack - > Mozilla Firefox-1.png, Screenshot-CloudStack - Mozilla Firefox-2.png, > Screenshot-CloudStack - Mozilla Firefox.png > > > 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