cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Bjoern Teipel <bjoern.tei...@internetbrands.com>
Subject Re: 4.2.1-snapshot : com.cloud.exception.InsufficientServerCapacityException:
Date Wed, 23 Oct 2013 07:04:04 GMT
Yes I had and I changed the delay to 1h.
I also got link communication failures and the secondary storage was 
stuck during this time so I decided to rebuild the zone and change the 
NFS storage from Gluster to a standard NFS server removing the iptables 
rules etc. But I'm still rebuilding it and testing right now KVM with 
openvswitch though ...

Bjoern

On 10/22/2013 11:54 PM, Whyspirit wrote:
> Hello. Do you have any VMs that needs to be expunged. If it is the 
> case, please reduce number of them by changing parameters in 
> cloudstack UI (reduce expunge.delay and expunge. Interval).
>
>
> Envoyé avec AquaMail pour Android
> http://www.aqua-mail.com
>
>
> Le 21 octobre 2013 22:24:46 Bjoern Teipel 
> <bjoern.teipel@internetbrands.com> a écrit :
>> Hi,
>>
>> my cstk deployment stopped working and I can't figure out why, 
>> because all capacity related metrics are ok.
>>
>> 2013-10-21 13:17:51,412 INFO  [user.vm.DeployVMCmd] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> com.cloud.exception.InsufficientServerCapacityException: Unable to 
>> create a deployment for
>> VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a]Scope=interface 
>> com.cloud.dc.DataCenter; id=1
>> 2013-10-21 13:17:51,412 INFO  [user.vm.DeployVMCmd] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Unable to create a deployment for 
>> VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a]
>> com.cloud.exception.InsufficientServerCapacityException: Unable to 
>> create a deployment for 
>> VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a]Scope=interface 
>> com.cloud.dc.DataCenter; id=1
>>          at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:841)

>>
>>          at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)

>>
>>          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:209)

>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3404) 
>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2964) 
>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2950) 
>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)

>>
>>          at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>>          at
>> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>>          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:679)
>> 2013-10-21 13:17:51,413 DEBUG [cloud.async.AsyncJobManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Complete async job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ], 
>> jobStatus: 2
>> , resultCode: 530, result: Error Code: 533 Error text: Unable to 
>> create a deployment for VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a]
>>
>> but this is what I saw before this error:
>>
>>
>> 2013-10-21 13:17:50,617 DEBUG [cloud.server.StatsCollector] 
>> (StatsCollector-1:null) StorageCollector is running...
>> 2013-10-21 13:17:50,620 INFO 
>> [storage.endpoint.DefaultEndPointSelector] (StatsCollector-1:null) No 
>> running ssvm is found, so command will be sent to LocalHostEndPoint
>> 2013-10-21 13:17:50,674 DEBUG [agent.transport.Request] 
>> (StatsCollector-1:null) Seq 1-531890650: Received:  { Ans: , MgmtId: 
>> 110493122496, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
>> 2013-10-21 13:17:50,946 DEBUG [agent.transport.Request] 
>> (StatsCollector-1:null) Seq 1-531890651: Received:  { Ans: , MgmtId: 
>> 110493122496, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
>> 2013-10-21 13:17:51,142 DEBUG [agent.transport.Request] 
>> (AgentManager-Handler-15:null) Seq 1-531890647: Processing:  { Ans: , 
>> MgmtId: 110493122496, via: 1, Ver: v1, Flags: 110, 
>> [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"3000605a-b528-400c-8ff2-a894c20b0705","id":0,"format":"QCOW2","accountId":0,"hvm":false}},"result":true,"wait":0}}]

>> }
>> 2013-10-21 13:17:51,142 DEBUG [agent.transport.Request] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Seq 1-531890647: Received:  { Ans: , MgmtId: 110493122496, via: 1, 
>> Ver: v1, Flags: 110, { CopyCmdAnswer } }
>> 2013-10-21 13:17:51,142 DEBUG [agent.manager.AgentAttache] 
>> (AgentManager-Handler-15:null) Seq 1-531890647: No more commands found
>> 2013-10-21 13:17:51,143 DEBUG [image.store.TemplateObject] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> failed to process event and answer
>> com.cloud.utils.exception.CloudRuntimeException: DB Exception on: 
>> com.mysql.jdbc.JDBC4PreparedStatement@5cdcbeb5: SELECT 
>> template_spool_ref.id, template_spool_ref.pool_id, 
>> template_spool_ref.template_id, template_spool_ref.created, 
>> template_spool_ref.last_updated, template_spool_ref.download_pct, 
>> template_spool_ref.download_state, template_spool_ref.local_path, 
>> template_spool_ref.error_str, template_spool_ref.job_id, 
>> template_spool_ref.install_path, template_spool_ref.template_size, 
>> template_spool_ref.marked_for_gc, template_spool_ref.update_count, 
>> template_spool_ref.updated, template_spool_ref.state FROM 
>> template_spool_ref WHERE template_spool_ref.pool_id = 2  AND 
>> template_spool_ref.template_id = 209  ORDER BY RAND() LIMIT 1
>>          at
>> com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:414)

>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:349)

>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> com.cloud.utils.db.GenericDaoBase.findOneIncludingRemovedBy(GenericDaoBase.java:859)

>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> com.cloud.storage.dao.VMTemplatePoolDaoImpl.findByPoolTemplate(VMTemplatePoolDaoImpl.java:128)

>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> org.apache.cloudstack.storage.image.store.TemplateObject.processEvent(TemplateObject.java:182)

>>
>>          at
>> org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyBaseImageCallback(VolumeServiceImpl.java:478)

>>
>>          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:616)
>>          at
>> org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.dispatch(AsyncCallbackDispatcher.java:142)

>>
>>          at
>> org.apache.cloudstack.framework.async.InplaceAsyncCallbackDriver.performCompletionCallback(InplaceAsyncCallbackDriver.java:26)

>>
>>          at
>> org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.complete(AsyncCallbackDispatcher.java:120)

>>
>>          at
>> org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:423)

>>
>>          at
>> org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:58)

>>
>>          at
>> org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:446)

>>
>>          at
>> org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:575)

>>
>>          at
>> com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2567) 
>>
>>          at
>> com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2631)
>>          at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)

>>
>>          at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)

>>
>>          at
>> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)

>>
>>          at
>> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)

>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3404) 
>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2964) 
>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2950) 
>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)

>>
>>          at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>>          at
>> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>>          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:679)
>> Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: 
>> Communications link failure
>>
>> The last packet successfully received from the server was 35,117 
>> milliseconds ago.  The last packet sent successfully to the server 
>> was 1 milliseconds ago.
>>          at
>> sun.reflect.GeneratedConstructorAccessor149.newInstance(Unknown Source)
>>          at
>> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

>>
>>          at 
>> java.lang.reflect.Constructor.newInstance(Constructor.java:532)
>>          at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
>>          at
>> com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1117) 
>>
>>          at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3567)
>>          at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3456)
>>          at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3997)
>>          at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468)
>>          at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629)
>>          at 
>> com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2719)
>>          at
>> com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155) 
>>
>>          at
>> com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2318) 
>>
>>          at
>> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)

>>
>>          at
>> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)

>>
>>          at
>> com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:408)

>>
>>          ... 59 more
>> Caused by: java.io.EOFException: Can not read response from server. 
>> Expected to read 4 bytes, read 0 bytes before connection was 
>> unexpectedly lost.
>>          ... 74 more
>> 2013-10-21 13:17:51,153 DEBUG [storage.volume.VolumeServiceImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> failed to create template on storage
>> java.lang.RuntimeException: InvocationTargetException when invoking 
>> RPC callback for command: copyBaseImageCallback
>>          at
>> org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.dispatch(AsyncCallbackDispatcher.java:148)

>>
>>          at
>> org.apache.cloudstack.framework.async.InplaceAsyncCallbackDriver.performCompletionCallback(InplaceAsyncCallbackDriver.java:26)

>>
>>          at
>> org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.complete(AsyncCallbackDispatcher.java:120)

>>
>>          at
>> org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:423)

>>
>>          at
>> org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:58)

>>
>>          at
>> org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:446)

>>
>>          at
>> org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:575)

>>
>>          at
>> com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2567) 
>>
>>          at
>> com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2631)
>>          at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)

>>
>>          at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)

>>
>>          at
>> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)

>>
>>          at
>> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)

>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3404) 
>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2964) 
>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2950) 
>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)

>>
>>          at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>>          at
>> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>>          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:679)
>> Caused by: java.lang.reflect.InvocationTargetException
>>          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:616)
>>          at
>> org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.dispatch(AsyncCallbackDispatcher.java:142)

>>
>>          ... 29 more
>> Caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to 
>> process event
>>          at
>> org.apache.cloudstack.storage.image.store.TemplateObject.processEvent(TemplateObject.java:226)

>>
>>          at
>> org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyBaseImageCallback(VolumeServiceImpl.java:478)

>>
>>          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>          ... 33 more
>> Caused by: com.cloud.utils.exception.CloudRuntimeException: DB 
>> Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5cdcbeb5: SELECT 
>> template_spool_ref.id, template_spool_ref.pool_id, 
>> template_spool_ref.template_id, template_spool_ref.created, 
>> template_spool_ref.last_updated, template_spool_ref.download_pct, 
>> template_spool_ref.download_state, template_spool_ref.local_path, 
>> template_spool_ref.error_str, template_spool_ref.job_id, 
>> template_spool_ref.install_path, template_spool_ref.template_size, 
>> template_spool_ref.marked_for_gc, template_spool_ref.update_count, 
>> template_spool_ref.updated, template_spool_ref.state FROM 
>> template_spool_ref WHERE template_spool_ref.pool_id = 2  AND 
>> template_spool_ref.template_id = 209  ORDER BY RAND() LIMIT 1
>>          at
>> com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:414)

>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:349)

>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> com.cloud.utils.db.GenericDaoBase.findOneIncludingRemovedBy(GenericDaoBase.java:859)

>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> com.cloud.storage.dao.VMTemplatePoolDaoImpl.findByPoolTemplate(VMTemplatePoolDaoImpl.java:128)

>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> org.apache.cloudstack.storage.image.store.TemplateObject.processEvent(TemplateObject.java:182)

>>
>>          ... 35 more
>> Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: 
>> Communications link failure
>>
>> The last packet successfully received from the server was 35,117 
>> milliseconds ago.  The last packet sent successfully to the server 
>> was 1 milliseconds ago.
>>          at
>> sun.reflect.GeneratedConstructorAccessor149.newInstance(Unknown Source)
>>          at
>> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

>>
>>          at 
>> java.lang.reflect.Constructor.newInstance(Constructor.java:532)
>>          at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
>>          at
>> com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1117) 
>>
>>          at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3567)
>>          at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3456)
>>          at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3997)
>>          at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468)
>>          at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629)
>>          at 
>> com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2719)
>>          at
>> com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155) 
>>
>>          at
>> com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2318) 
>>
>>          at
>> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)

>>
>>          at
>> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)

>>
>>          at
>> com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:408)

>>
>>          ... 59 more
>> Caused by: java.io.EOFException: Can not read response from server. 
>> Expected to read 4 bytes, read 0 bytes before connection was 
>> unexpectedly lost.
>>          ... 74 more
>> 2013-10-21 13:17:51,156 WARN 
>> [storage.datastore.ObjectInDataStoreManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Template 209 is not found on storage pool 2, so no need to delete
>> 2013-10-21 13:17:51,157 INFO [storage.volume.VolumeServiceImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> releasing lock for VMTemplateStoragePool 9
>> 2013-10-21 13:17:51,157 ERROR [cloud.vm.VirtualMachineManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Failed to start instance VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a]
>> com.cloud.utils.exception.CloudRuntimeException: can't find mapping 
>> in ObjectInDataStore table for: 
>> org.apache.cloudstack.storage.image.store.TemplateObject@616b3665
>>          at
>> org.apache.cloudstack.storage.datastore.ObjectInDataStoreManagerImpl.update(ObjectInDataStoreManagerImpl.java:293)

>>
>>          at
>> org.apache.cloudstack.storage.image.store.TemplateObject.processEvent(TemplateObject.java:162)

>>
>>          at
>> org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:449)

>>
>>          at
>> org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:575)

>>
>>          at
>> com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2567) 
>>
>>          at
>> com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2631)
>>          at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)

>>
>>          at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)

>>
>>          at
>> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)

>>
>>          at
>> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)

>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3404) 
>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2964) 
>>
>>          at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2950) 
>>
>>          at
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)

>>
>>          at
>> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)

>>
>>          at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>>          at
>> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>>          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:679)
>> 2013-10-21 13:17:51,160 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Cleaning up resources for the vm 
>> VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a] in Starting state
>> 2013-10-21 13:17:51,161 DEBUG [agent.transport.Request] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Seq 1-531890652: Sending  { Cmd , MgmtId: 110493122496, via: 1, Ver: 
>> v1, Flags: 100111, 
>> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-23-VM","wait":0}}]

>> }
>> 2013-10-21 13:17:51,308 DEBUG [agent.transport.Request] 
>> (AgentManager-Handler-1:null) Seq 1-531890652: Processing:  { Ans: , 
>> MgmtId: 110493122496, via: 1, Ver: v1, Flags: 110, 
>> [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"wait":0}}] 
>> }
>> 2013-10-21 13:17:51,308 DEBUG [agent.manager.AgentAttache] 
>> (AgentManager-Handler-1:null) Seq 1-531890652: No more commands found
>> 2013-10-21 13:17:51,308 DEBUG [agent.transport.Request] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Seq 1-531890652: Received:  { Ans: , MgmtId: 110493122496, via: 1, 
>> Ver: v1, Flags: 110, { StopAnswer } }
>> 2013-10-21 13:17:51,308 DEBUG [cloud.api.ApiServlet] 
>> (catalina-exec-23:null) ===START===  172.16.7.249 -- GET 
>> command=queryAsyncJobResult&jobId=fed97281-7904-427c-b450-80fb32210cbc&response=json&sessionkey=F4HGUE031dGxlvEQUFnGYGQT6ZI%3D&_=1382386671305
>> 2013-10-21 13:17:51,319 DEBUG [cloud.network.NetworkModelImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Service SecurityGroup is not supported in the network id=210
>> 2013-10-21 13:17:51,322 DEBUG [cloud.network.NetworkManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Changing active number of nics for network id=210 on -1
>> 2013-10-21 13:17:51,326 DEBUG [cloud.api.ApiServlet] 
>> (catalina-exec-23:null) ===END===  172.16.7.249 -- GET 
>> command=queryAsyncJobResult&jobId=fed97281-7904-427c-b450-80fb32210cbc&response=json&sessionkey=F4HGUE031dGxlvEQUFnGYGQT6ZI%3D&_=1382386671305
>> 2013-10-21 13:17:51,328 DEBUG [cloud.network.NetworkManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Asking VirtualRouter to release 
>> Nic[46-23-88b03bb7-eb52-4d02-a24b-37f5aac4669b-10.1.1.249]
>> 2013-10-21 13:17:51,329 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Successfully released network resources for the vm 
>> VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a]
>> 2013-10-21 13:17:51,329 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Successfully cleanued up resources for the vm 
>> VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a] in Starting state
>> 2013-10-21 13:17:51,332 DEBUG [cloud.capacity.CapacityManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> VM state transitted from :Starting to Stopped with event: 
>> OperationFailedvm's original host id: null new host id: null host id 
>> before state transition: 1
>> 2013-10-21 13:17:51,338 DEBUG [cloud.capacity.CapacityManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Hosts's actual total CPU: 42544 and CPU after applying 
>> overprovisioning: 42544
>> 2013-10-21 13:17:51,338 DEBUG [cloud.capacity.CapacityManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Hosts's actual total RAM: 126843064320 and RAM after applying 
>> overprovisioning: 126843060224
>> 2013-10-21 13:17:51,338 DEBUG [cloud.capacity.CapacityManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> release cpu from host: 1, old used: 6000,reserved: 0, actual total: 
>> 42544, total with overprovisioning: 42544; new used: 5500,reserved:0; 
>> movedfromreserved: false,moveToReserveredfalse
>> 2013-10-21 13:17:51,338 DEBUG [cloud.capacity.CapacityManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> release mem from host: 1, old used: 4160749568,reserved: 0, total: 
>> 126843060224; new used: 3623878656,reserved:0; movedfromreserved: 
>> false,moveToReserveredfalse
>> 2013-10-21 13:17:51,349 DEBUG [cloud.capacity.CapacityManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> 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-10-21 13:17:51,349 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Successfully transitioned to start state for 
>> VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a] reservation id = 
>> 6fe9aa6f-30f4-455b-9196-39b96ace239f
>> 2013-10-21 13:17:51,351 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Trying to deploy VM, vm has dcId: 1 and podId: 1
>> 2013-10-21 13:17:51,351 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Deploy avoids pods: [], clusters: [], hosts: [1]
>> 2013-10-21 13:17:51,357 DEBUG 
>> [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-126 
>> = [ fed97281-7904-427c-b450-80fb32210cbc ]) Deploy avoids pods: [], 
>> clusters: [], hosts: [1]
>> 2013-10-21 13:17:51,358 DEBUG 
>> [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-126 
>> = [ fed97281-7904-427c-b450-80fb32210cbc ]) DeploymentPlanner 
>> allocation algorithm: 
>> com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_26f423f7@1d892dc8
>> 2013-10-21 13:17:51,358 DEBUG 
>> [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-126 
>> = [ fed97281-7904-427c-b450-80fb32210cbc ]) Trying to allocate a host 
>> and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, 
>> requested ram: 536870912
>> 2013-10-21 13:17:51,358 DEBUG 
>> [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-126 
>> = [ fed97281-7904-427c-b450-80fb32210cbc ]) Is ROOT volume READY 
>> (pool already allocated)?: No
>> 2013-10-21 13:17:51,358 DEBUG [cloud.deploy.FirstFitPlanner] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Searching resources only under specified Pod: 1
>> 2013-10-21 13:17:51,358 DEBUG [cloud.deploy.FirstFitPlanner] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Listing clusters in order of aggregate capacity, that have (atleast 
>> one host with) enough CPU and RAM capacity under this Pod: 1
>> 2013-10-21 13:17:51,361 DEBUG [cloud.deploy.FirstFitPlanner] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Removing from the clusterId list these clusters from avoid set: []
>> 2013-10-21 13:17:51,366 DEBUG 
>> [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-126 
>> = [ fed97281-7904-427c-b450-80fb32210cbc ]) Checking resources in 
>> Cluster: 1 under Pod: 1
>> 2013-10-21 13:17:51,366 DEBUG [allocator.impl.FirstFitAllocator] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ] 
>> FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1 cluster:1
>> 2013-10-21 13:17:51,368 DEBUG [allocator.impl.FirstFitAllocator] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ] 
>> FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for 
>> allocation: [Host[-1-Routing]]
>> 2013-10-21 13:17:51,370 DEBUG [allocator.impl.FirstFitAllocator] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ] 
>> FirstFitRoutingAllocator) Found 1 hosts for allocation after 
>> prioritization: [Host[-1-Routing]]
>> 2013-10-21 13:17:51,370 DEBUG [allocator.impl.FirstFitAllocator] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ] 
>> FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
>> 2013-10-21 13:17:51,370 DEBUG [allocator.impl.FirstFitAllocator] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ] 
>> FirstFitRoutingAllocator) Host name: hq-kvmhv-002.internetbrands.com, 
>> hostId: 1 is in avoid set, skipping this and trying other available 
>> hosts
>> 2013-10-21 13:17:51,370 DEBUG [allocator.impl.FirstFitAllocator] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ] 
>> FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
>> 2013-10-21 13:17:51,370 DEBUG 
>> [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-126 
>> = [ fed97281-7904-427c-b450-80fb32210cbc ]) No suitable hosts found
>> 2013-10-21 13:17:51,370 DEBUG 
>> [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-126 
>> = [ fed97281-7904-427c-b450-80fb32210cbc ]) No suitable hosts found 
>> under this Cluster: 1
>> 2013-10-21 13:17:51,372 DEBUG 
>> [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-8:job-126 
>> = [ fed97281-7904-427c-b450-80fb32210cbc ]) Could not find suitable 
>> Deployment Destination for this VM under any clusters, returning.
>> 2013-10-21 13:17:51,372 DEBUG [cloud.deploy.FirstFitPlanner] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Searching resources only under specified Pod: 1
>> 2013-10-21 13:17:51,372 DEBUG [cloud.deploy.FirstFitPlanner] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Listing clusters in order of aggregate capacity, that have (atleast 
>> one host with) enough CPU and RAM capacity under this Pod: 1
>> 2013-10-21 13:17:51,374 DEBUG [cloud.deploy.FirstFitPlanner] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Removing from the clusterId list these clusters from avoid set: [1]
>> 2013-10-21 13:17:51,374 DEBUG [cloud.deploy.FirstFitPlanner] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> No clusters found after removing disabled clusters and clusters in 
>> avoid list, returning.
>> 2013-10-21 13:17:51,378 DEBUG [cloud.capacity.CapacityManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> VM state transitted from :Starting to Stopped with event: 
>> OperationFailedvm's original host id: null new host id: null host id 
>> before state transition: null
>> 2013-10-21 13:17:51,386 DEBUG [cloud.vm.UserVmManagerImpl] 
>> (Job-Executor-8:job-126 = [ fed97281-7904-427c-b450-80fb32210cbc ]) 
>> Destroying vm VM[User|d0bc4ffd-7850-4503-a62b-482895b4b08a] as it 
>> failed to create on Host with Id:null
>>
>>
>>
>
>
>


Mime
View raw message