Re: ACS 4.2 secondary storage strangeness

2013-10-22 Thread Andrei Mikhailovsky
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

2013-10-22 Thread Nitin Mehta
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