Re: ACS 4.2 secondary storage strangeness
Also, Template creation from a snapshot doesn't work. Perhaps related? I've double checked that ssvm is up and running and the check script does not produce any errors. Here is the error while trying to create a template: 2013-10-22 17:13:28,474 DEBUG [cloud.network.NetworkUsageManagerImpl] (AgentConnectTaskPool-3979:null) Disconnected called on 61 with status Alert 2013-10-22 17:13:28,474 DEBUG [agent.manager.AgentManagerImpl] (AgentConnectTaskPool-3979:null) Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener 2013-10-22 17:13:28,476 DEBUG [cloud.host.Status] (AgentConnectTaskPool-3979:null) Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id = 61, name = s-820-VM] 2013-10-22 17:13:28,593 DEBUG [cloud.host.Status] (AgentConnectTaskPool-3979:null) Agent status update: [id = 61; name = s-820-VM; old status = Connecting; event = AgentDisconnected; new status = Alert; old update count = 5283; new update count = 5284] 2013-10-22 17:13:28,593 DEBUG [agent.manager.ClusteredAgentManagerImpl] (AgentConnectTaskPool-3979:null) Notifying other nodes of to disconnect 2013-10-22 17:13:28,594 DEBUG [agent.manager.AgentManagerImpl] (AgentConnectTaskPool-3979:null) Failed to handle host connection: com.cloud.utils.exception.CloudRuntimeException: Unable to connect 61 2013-10-22 17:13:28,594 DEBUG [agent.manager.AgentManagerImpl] (AgentConnectTaskPool-3979:null) Can not send command com.cloud.agent.api.ReadyCommand due to Host 61 is not up 2013-10-22 17:13:28,649 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-103:job-6828 = [ 992cbb95-38ec-497e-bddc-1e90b67bcdb9 ]) Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: Failed to send command, due to Agent:61, com.cloud.exception.OperationTimedoutException: Commands 1024262150 to Host 61 timed out after 21600 2013-10-22 17:13:28,764 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-103:job-6828 = [ 992cbb95-38ec-497e-bddc-1e90b67bcdb9 ]) Unexpected exception while executing org.apache.cloudstack.api.command.user.template.CreateTemplateCmd com.cloud.utils.exception.CloudRuntimeException: Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: Failed to send command, due to Agent:61, com.cloud.exception.OperationTimedoutException: Commands 1024262150 to Host 61 timed out after 21600 at com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManagerImpl.java:1395) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at org.apache.cloudstack.api.command.user.template.CreateTemplateCmd.execute(CreateTemplateCmd.java:263) 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-22 17:13:28,765 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-103:job-6828 = [ 992cbb95-38ec-497e-bddc-1e90b67bcdb9 ]) Complete async job-6828 = [ 992cbb95-38ec-497e-bddc-1e90b67bcdb9 ], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: Failed to send command, due to Agent:61, com.cloud.exception.OperationTimedoutException: Commands 1024262150 to Host 61 timed out after 21600 Thanks Andrei - Original Message - From: Andrei Mikhailovsky and...@arhont.com To: users@cloudstack.apache.org Sent: Tuesday, 22 October, 2013 2:35:15 PM Subject: ACS 4.2 secondary storage strangeness Hello guys, I am having an issue after upgrading from 4.1.1 to 4.2.0. Every minute or so I have the following exception in my management server logs: - 2013-10-22 14:31:43,921 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-3561:null) Template Sync found routing-8 already in the image store 2013-10-22 14:31:44,070 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-3561:null) Template Sync found routing-1 already in the image store 2013-10-22 14:31:44,167 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-3561:null) Template Sync found centos55-x86_64 already in the image store 2013-10-22 14:31:44,263 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-3561:null) Template Sync did not find centos56-x86_64-xen on image store 42, may request download based on available hypervisor types 2013-10-22 14:31:44,264 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-3561:null) Template
Re: ACS 4.2 secondary storage strangeness
What does the agent state in the UI for SSVM - is it up ? As per me the ssvm check scripts shouldn't have succeeded for you. Following log message hints that to me. Agent status update: [id = 61; name = s-820-VM; old status = Connecting; event = AgentDisconnected; new status = Alert; old update count = 5283; new update count = 5284] On 22/10/13 9:21 AM, Andrei Mikhailovsky and...@arhont.com wrote: Also, Template creation from a snapshot doesn't work. Perhaps related? I've double checked that ssvm is up and running and the check script does not produce any errors. Here is the error while trying to create a template: 2013-10-22 17:13:28,474 DEBUG [cloud.network.NetworkUsageManagerImpl] (AgentConnectTaskPool-3979:null) Disconnected called on 61 with status Alert 2013-10-22 17:13:28,474 DEBUG [agent.manager.AgentManagerImpl] (AgentConnectTaskPool-3979:null) Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener 2013-10-22 17:13:28,476 DEBUG [cloud.host.Status] (AgentConnectTaskPool-3979:null) Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id = 61, name = s-820-VM] 2013-10-22 17:13:28,593 DEBUG [cloud.host.Status] (AgentConnectTaskPool-3979:null) Agent status update: [id = 61; name = s-820-VM; old status = Connecting; event = AgentDisconnected; new status = Alert; old update count = 5283; new update count = 5284] 2013-10-22 17:13:28,593 DEBUG [agent.manager.ClusteredAgentManagerImpl] (AgentConnectTaskPool-3979:null) Notifying other nodes of to disconnect 2013-10-22 17:13:28,594 DEBUG [agent.manager.AgentManagerImpl] (AgentConnectTaskPool-3979:null) Failed to handle host connection: com.cloud.utils.exception.CloudRuntimeException: Unable to connect 61 2013-10-22 17:13:28,594 DEBUG [agent.manager.AgentManagerImpl] (AgentConnectTaskPool-3979:null) Can not send command com.cloud.agent.api.ReadyCommand due to Host 61 is not up 2013-10-22 17:13:28,649 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-103:job-6828 = [ 992cbb95-38ec-497e-bddc-1e90b67bcdb9 ]) Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: Failed to send command, due to Agent:61, com.cloud.exception.OperationTimedoutException: Commands 1024262150 to Host 61 timed out after 21600 2013-10-22 17:13:28,764 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-103:job-6828 = [ 992cbb95-38ec-497e-bddc-1e90b67bcdb9 ]) Unexpected exception while executing org.apache.cloudstack.api.command.user.template.CreateTemplateCmd com.cloud.utils.exception.CloudRuntimeException: Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: Failed to send command, due to Agent:61, com.cloud.exception.OperationTimedoutException: Commands 1024262150 to Host 61 timed out after 21600 at com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManag erImpl.java:1395) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorD ispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at org.apache.cloudstack.api.command.user.template.CreateTemplateCmd.execute( CreateTemplateCmd.java:263) 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-22 17:13:28,765 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-103:job-6828 = [ 992cbb95-38ec-497e-bddc-1e90b67bcdb9 ]) Complete async job-6828 = [ 992cbb95-38ec-497e-bddc-1e90b67bcdb9 ], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: Failed to send command, due to Agent:61, com.cloud.exception.OperationTimedoutException: Commands 1024262150 to Host 61 timed out after 21600 Thanks Andrei - Original Message - From: Andrei Mikhailovsky and...@arhont.com To: users@cloudstack.apache.org Sent: Tuesday, 22 October, 2013 2:35:15 PM Subject: ACS 4.2 secondary storage strangeness Hello guys, I am having an issue after upgrading from 4.1.1 to 4.2.0. Every minute or so I have the following exception in my management server logs: - 2013-10-22 14:31:43,921 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-3561:null) Template Sync found routing-8 already in the image store 2013-10-22 14:31:44,070 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-3561:null) Template Sync found routing-1 already in the image store 2013-10-22 14:31:44,167 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-3561:null) Template Sync found centos55-x86_64 already