cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sailaja Mada (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CLOUDSTACK-3844) System VMs are failed to start first time
Date Fri, 26 Jul 2013 07:17:48 GMT
Sailaja Mada created CLOUDSTACK-3844:
----------------------------------------

             Summary: System VMs are failed to start first time 
                 Key: CLOUDSTACK-3844
                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3844
             Project: CloudStack
          Issue Type: Bug
      Security Level: Public (Anyone can view this level - this is the default.)
          Components: VMware
    Affects Versions: 4.2.0
            Reporter: Sailaja Mada
         Attachments: apilog.log, management-server.log

Setup: VMWARE 5.1 , Zone wide primary storage , Adv networking Zone

1. Configure Adv Zone with zone wide primary storage
2. Add VMWARE 5.1 host 

3.After Zone configuration is completed CloudStack started to bring up system VM's (SSVM/CPVM)

Observation:

For the first time system VM's failed to start with NPE. But later they started with no issues.

Details :

2013-07-26 12:33:55,906 INFO  [vmware.resource.VmwareResource] (DirectAgent-8:10.102.192.19)
Executing resource StartCommand: {"vm":{"id":2,"name":"v-2-VM","bootloader":"HVM","type":"ConsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"i686","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy host=10.102.192.184 port=8250
name=v-2-VM premium=true zone=1 pod=1 guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=10.102.197.221
eth2mask=255.255.255.0 gateway=10.102.197.1 eth0ip=0.0.0.0 eth0mask=0.0.0.0 eth1ip=10.102.195.134
eth1mask=255.255.252.0 mgmtcidr=10.102.192.0/22 localgw=10.102.192.1 internaldns1=10.103.128.15
dns1=10.103.128.15","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"8823662ee1fe9390","params":{"nicAdapter":"E1000"},"uuid":"82d53a61-c755-461c-8d80-34116e72cc8e","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0954dc10-510a-4fa7-b842-332bbbf09faf","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a5d175a7-fc4b-3184-879a-9c1c475311c0","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/vmware51ps1","port":2049}},"name":"ROOT-2","size":0,"path":"ROOT-2-2","volumeId":2,"vmName":"v-2-VM","accountId":1,"format":"OVA","id":2,"hypervisorType":"None"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"uuid":"e8c43cf4-e017-4d3b-8072-5aaf8053caf5","ip":"10.102.197.221","netmask":"255.255.255.0","gateway":"10.102.197.1","mac":"06:83:92:00:00:08","dns1":"10.103.128.15","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://101","isolationUri":"vlan://101","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"bbe64574-9fc6-4f4f-a8ab-31728491825e","mac":"02:00:5d:95:00:02","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"f6ddb54a-5890-4c95-8ba1-06ce75ff5b70","ip":"10.102.195.134","netmask":"255.255.252.0","gateway":"10.102.192.1","mac":"06:31:e8:00:00:05","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false}]},"hostIp":"10.102.192.19","executeInSequence":false,"wait":0}
2013-07-26 12:33:55,906 DEBUG [vmware.resource.VmwareResource] (DirectAgent-8:10.102.192.19)
VM v-2-VM will be started with NIC device type: E1000
2013-07-26 12:33:55,965 DEBUG [vmware.mo.HostMO] (DirectAgent-8:10.102.192.19) find VM v-2-VM
on host
2013-07-26 12:33:55,965 DEBUG [vmware.mo.HostMO] (DirectAgent-8:10.102.192.19) load VM cache
on host
2013-07-26 12:33:56,003 INFO  [vmware.mo.HypervisorHostHelper] (DirectAgent-8:10.102.192.19)
Create blank VM. cpuCount: 1, cpuSpeed(MHz): 500, mem(Mb): 1024
2013-07-26 12:33:56,499 DEBUG [vmware.mo.HostMO] (DirectAgent-8:10.102.192.19) find VM v-2-VM
on host
2013-07-26 12:33:56,499 DEBUG [vmware.mo.HostMO] (DirectAgent-8:10.102.192.19) load VM cache
on host
2013-07-26 12:33:56,503 INFO  [storage.resource.VmwareStorageProcessor] (DirectAgent-7:10.102.192.19)
detach disks from volume-wrapper VM ROOT-1-1
2013-07-26 12:33:56,541 WARN  [vmware.resource.VmwareResource] (DirectAgent-8:10.102.192.19)
StartCommand failed due to Exception: java.lang.NullPointerException
Message: null

java.lang.NullPointerException
        at com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.createBlankVm(HypervisorHostHelper.java:1165)
        at com.cloud.hypervisor.vmware.mo.HostMO.createBlankVm(HostMO.java:700)
        at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2638)
        at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:520)
        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-07-26 12:33:56,547 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-8:null) Seq
1-107151372: Cancelling because one of the answers is false and it is stop on error.
2013-07-26 12:33:56,547 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-8:null) Seq
1-107151372: Response Received:
2013-07-26 12:33:56,551 DEBUG [agent.transport.Request] (DirectAgent-8:null) Seq 1-107151372:
Processing:  { Ans: , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":2,"name":"v-2-VM","bootloader":"HVM","type":"ConsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"i686","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy host=10.102.192.184 port=8250
name=v-2-VM premium=true zone=1 pod=1 guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=10.102.197.221
eth2mask=255.255.255.0 gateway=10.102.197.1 eth0ip=0.0.0.0 eth0mask=0.0.0.0 eth1ip=10.102.195.134
eth1mask=255.255.252.0 mgmtcidr=10.102.192.0/22 localgw=10.102.192.1 internaldns1=10.103.128.15
dns1=10.103.128.15","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"8823662ee1fe9390","params":{"nicAdapter":"E1000"},"uuid":"82d53a61-c755-461c-8d80-34116e72cc8e","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0954dc10-510a-4fa7-b842-332bbbf09faf","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a5d175a7-fc4b-3184-879a-9c1c475311c0","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/vmware51ps1","port":2049}},"name":"ROOT-2","size":0,"path":"ROOT-2-2","volumeId":2,"vmName":"v-2-VM","accountId":1,"format":"OVA","id":2,"hypervisorType":"None"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"uuid":"e8c43cf4-e017-4d3b-8072-5aaf8053caf5","ip":"10.102.197.221","netmask":"255.255.255.0","gateway":"10.102.197.1","mac":"06:83:92:00:00:08","dns1":"10.103.128.15","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://101","isolationUri":"vlan://101","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"bbe64574-9fc6-4f4f-a8ab-31728491825e","mac":"02:00:5d:95:00:02","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"f6ddb54a-5890-4c95-8ba1-06ce75ff5b70","ip":"10.102.195.134","netmask":"255.255.252.0","gateway":"10.102.192.1","mac":"06:31:e8:00:00:05","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false}]},"result":false,"details":"StartCommand
failed due to Exception: java.lang.NullPointerException\nMessage: null\n","wait":0}}] }
2013-07-26 12:33:56,552 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-107151372:
Received:  { Ans: , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 10, { StartAnswer } }
2013-07-26 12:33:56,560 INFO  [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Unable
to start VM on Host[-1-Routing] due to StartCommand failed due to Exception: java.lang.NullPointerException
Message: null




2013-07-26 12:33:56,725 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) release
cpu from host: 1, old used: 1000,reserved: 0, actual total: 9572, total with overprovisioning:
9572; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-07-26 12:33:56,725 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) release
mem from host: 1, old used: 1342177280,reserved: 0, total: 17166258176; new used: 268435456,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2013-07-26 12:33:56,735 WARN  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Exception while trying to start console proxy
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for
VM[ConsoleProxy|v-2-VM]Scope=interface com.cloud.dc.DataCenter; id=1
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:882)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:618)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:611)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:927)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1664)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
        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-07-26 12:33:56,761 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Zone 1 is ready to launch console proxy
2013-07-26 12:33:56,762 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Expand console proxy standby capacity for zone vmware51zone
2013-07-26 12:33:56,766 INFO  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Found a stopped console proxy, bring it up to running pool. proxy vm id : 2
2013-07-26 12:33:56,777 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 transition: null
2013-07-26 12:33:56,777 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully
transitioned to start state for VM[ConsoleProxy|v-2-VM] reservation id = 98765ac3-4250-415d-924b-a54fbe1b36a5



2013-07-26 12:34:15,601 INFO  [vmware.resource.VmwareResource] (DirectAgent-9:10.102.192.19)
Prepare NIC device based on NicTO: {"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"uuid":"004bab44-a130-4777-8a52-ae1a1f623966","ip":"10.102.197.220","netmask":"255.255.255.0","gateway":"10.102.197.1","mac":"06:77:ae:00:00:07","dns1":"10.103.128.15","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://101","isolationUri":"vlan://101","isSecurityGroupEnabled":false}
2013-07-26 12:34:15,607 INFO  [vmware.resource.VmwareResource] (DirectAgent-9:10.102.192.19)
Prepare network on vmwaresvs P[vSwitch0:untagged] with name prefix: cloud.public
2013-07-26 12:34:15,726 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 0 routers to update status.
2013-07-26 12:34:15,728 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null)
Found 0 networks to update RvR status.
2013-07-26 12:34:17,370 INFO  [vmware.mo.HypervisorHostHelper] (DirectAgent-10:10.102.192.19)
Waiting for network cloud.public.101.0.1-vSwitch0 to be ready
2013-07-26 12:34:17,625 WARN  [vmware.resource.VmwareResource] (DirectAgent-9:10.102.192.19)
StartCommand failed due to Exception: com.vmware.vim25.AlreadyExists
message: []

com.vmware.vim25.AlreadyExistsFaultMsg: The specified key, name, or identifier already exists.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:532)
        at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:130)
        at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:108)
        at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:78)
        at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:107)
        at $Proxy90.addPortGroup(Unknown Source)
        at com.cloud.hypervisor.vmware.mo.HostNetworkSystemMO.addPortGroup(HostNetworkSystemMO.java:38)
        at com.cloud.hypervisor.vmware.mo.HostMO.createPortGroup(HostMO.java:389)
        at com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.prepareNetwork(HypervisorHostHelper.java:961)
        at com.cloud.hypervisor.vmware.resource.VmwareResource.prepareNetworkFromNicInfo(VmwareResource.java:3227)
        at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2853)
        at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:520)
        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-07-26 12:34:17,631 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-9:null) Seq
1-107151375: Cancelling because one of the answers is false and it is stop on error.
2013-07-26 12:34:17,631 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-9:null) Seq
1-107151375: Response Received:
2013-07-26 12:34:17,635 DEBUG [agent.transport.Request] (DirectAgent-9:null) Seq 1-107151375:
Processing:  { Ans: , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":1,"name":"s-1-VM","bootloader":"HVM","type":"SecondaryStorageVm","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"arch":"i686","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=secstorage host=10.102.192.184 port=8250
name=s-1-VM zone=1 pod=1 guid=s-1-VM resource=com.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=true role=templateProcessor mtu=1500 eth2ip=10.102.197.220 eth2mask=255.255.255.0
gateway=10.102.197.1 public.network.device=eth2 eth0mask=0.0.0.0 eth0ip=0.0.0.0 eth1ip=10.102.195.131
eth1mask=255.255.252.0 mgmtcidr=10.102.192.0/22 localgw=10.102.192.1 private.network.device=eth1
eth3ip=10.102.195.132 eth3mask=255.255.252.0 storageip=10.102.195.132 storagenetmask=255.255.252.0
storagegateway=10.102.192.1 internaldns1=10.103.128.15 dns1=10.103.128.15","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"335ab3de528f823f","params":{"nicAdapter":"E1000"},"uuid":"22ec4ee1-38be-4881-b66b-c301e09570f6","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"4f3e9847-16e0-45b6-8e76-191d6597d530","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a5d175a7-fc4b-3184-879a-9c1c475311c0","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/vmware51ps1","port":2049}},"name":"ROOT-1","size":0,"path":"ROOT-1-1","volumeId":1,"vmName":"s-1-VM","accountId":1,"format":"OVA","id":1,"hypervisorType":"None"}},"diskSeq":0,"type":"ROOT"}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"uuid":"004bab44-a130-4777-8a52-ae1a1f623966","ip":"10.102.197.220","netmask":"255.255.255.0","gateway":"10.102.197.1","mac":"06:77:ae:00:00:07","dns1":"10.103.128.15","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://101","isolationUri":"vlan://101","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"603100b5-b362-4e9e-97f0-301418b3cc71","mac":"02:00:73:4a:00:01","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"b9f565be-fc33-43c0-84a2-150c05815b45","ip":"10.102.195.131","netmask":"255.255.252.0","gateway":"10.102.192.1","mac":"06:9f:c6:00:00:02","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false},{"deviceId":3,"networkRateMbps":-1,"defaultNic":false,"uuid":"fb21b81b-11cc-4141-960e-86e8c1c3fcd1","ip":"10.102.195.132","netmask":"255.255.252.0","gateway":"10.102.192.1","mac":"06:9d:24:00:00:03","broadcastType":"Native","type":"Storage","isSecurityGroupEnabled":false}]},"result":false,"details":"StartCommand
failed due to Exception: com.vmware.vim25.AlreadyExists\nmessage: []\n","wait":0}}] }
2013-07-26 12:34:17,636 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-107151375:
Received:  { Ans: , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 10, { StartAnswer } }
2013-07-26 12:34:17,650 INFO  [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Unable
to start VM on Host[-1-Routing] due to StartCommand failed due to Exception: com.vmware.vim25.AlreadyExists
message: []

2013-07-26 12:34:17,659 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Cleaning
up resources for the vm VM[SecondaryStorageVm|s-1-VM] in Starting state
2013-07-26 12:34:17,662 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-107151377:
Sending  { Cmd , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-1-VM","wait":0}}]
}
2013-07-26 12:34:17,662 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-107151377:
Executing:  { Cmd , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-1-VM","wait":0}}]
}


2013-07-26 12:34:17,896 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) release
mem from host: 1, old used: 1342177280,reserved: 0, total: 17166258176; new used: 1073741824,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2013-07-26 12:34:17,906 WARN  [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Exception while trying to start secondary storage vm
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for
VM[SecondaryStorageVm|s-1-VM]Scope=interface com.cloud.dc.DataCenter; id=1
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:882)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:618)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:611)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:265)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:690)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1297)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
        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-07-26 12:34:17,911 INFO  [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 1, will recycle
it and start a new one
2013-07-26 12:34:17,911 INFO  [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null)
Primary secondary storage is not even started, wait until next turn
2013-07-26 12:34:17,964 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Zone 1 is ready to launch secondary storage VM
2013-07-26 12:34:17,972 INFO  [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null)
No running secondary storage vms found in datacenter id=1, starting one
2013-07-26 12:34:17,984 INFO  [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Found a stopped secondary storage vm, bring it up to running pool. secStorageVm vm id : 1
2013-07-26 12:34:17,998 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-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 transition: null
2013-07-26 12:34:17,998 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Successfully
transitioned to start state for VM[SecondaryStorageVm|s-1-VM] reservation id = 7b15e385-2e98-4681-bcbe-e106a673efab




--
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

Mime
View raw message