Here is some more output from ssvm itself. Perhaps I am reading it wrongly...
root@s-820-VM:~# /usr/local/cloud/systemvm/ssvm-check.sh ================================================ First DNS server is 192.168.169.254 PING 192.168.169.254 (192.168.169.254): 56 data bytes 64 bytes from 192.168.169.254: icmp_seq=0 ttl=64 time=0.934 ms 64 bytes from 192.168.169.254: icmp_seq=1 ttl=64 time=1.288 ms --- 192.168.169.254 ping statistics --- 2 packets transmitted, 2 packets received, 0% packet loss round-trip min/avg/max/stddev = 0.934/1.111/1.288/0.177 ms Good: Can ping DNS server ================================================ Good: DNS resolves download.cloud.com ================================================ NFS is currently mounted Mount point is /mnt/SecStorage/f2208ff1-bb78-352a-97e3-a7dda0506d0d Good: Can write to mount point ================================================ Management server is 192.168.169.250. Checking connectivity. Good: Can connect to management server port 8250 ================================================ Good: Java process is running ================================================ Tests Complete. Look for ERROR or WARNING above. root@s-820-VM:~# ps aux |grep agent root 3671 2.0 21.6 348004 55212 ? Sl Oct21 21:18 java -Djavax.net.ssl.trustStore=./certs/realhostip.keystore -Dlog.home=/var/log/cloud/ -mx168m -cp ./:./conf:activation-1.1.jar:antisamy-1.4.3.jar:aopalliance-1.0.jar:apache-log4j-extras-1.1.jar:aspectjrt-1.7.1.jar:aspectjweaver-1.7.1.jar:aws-java-sdk-1.3.22.jar: .......... Cheers ----- Original Message ----- From: "Nitin Mehta" <nitin.me...@citrix.com> To: users@cloudstack.apache.org Sent: Tuesday, 22 October, 2013 6:20:15 PM Subject: 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 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 Sync did not find centos53-x64 >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) Skip downloading template routing-10 >since current data center does not have hypervisor LXC >2013-10-22 14:31:44,264 INFO [storage.image.TemplateServiceImpl] >(AgentConnectTaskPool-3561:null) Skip downloading template routing-9 >since current data center does not have hypervisor Hyperv >2013-10-22 14:31:44,264 INFO [storage.image.TemplateServiceImpl] >(AgentConnectTaskPool-3561:null) Downloading template centos56-x86_64-xen >to image store 5ebcfa59-279e-461f-a7fc-9cfd42157798 >2013-10-22 14:31:44,329 ERROR [agent.manager.AgentManagerImpl] >(AgentConnectTaskPool-3561:null) Monitor DownloadListener says there is >an error in the connect process for 61 due to null >java.lang.NullPointerException >at >org.apache.cloudstack.storage.image.manager.ImageStoreProviderManagerImpl. >getImageStore(ImageStoreProviderManagerImpl.java:65) >at >org.apache.cloudstack.storage.datastore.DataStoreManagerImpl.getDataStore( >DataStoreManagerImpl.java:47) >at >org.apache.cloudstack.storage.image.TemplateDataFactoryImpl.getTemplate(Te >mplateDataFactoryImpl.java:90) >at >org.apache.cloudstack.storage.image.TemplateServiceImpl.handleTemplateSync >(TemplateServiceImpl.java:418) >at >com.cloud.storage.download.DownloadListener.processConnect(DownloadListene >r.java:309) >at >com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentM >anagerImpl.java:587) >at >com.cloud.agent.manager.AgentManagerImpl.handleConnectedAgent(AgentManager >Impl.java:1085) >at >com.cloud.agent.manager.AgentManagerImpl.access$100(AgentManagerImpl.java: >144) >at >com.cloud.agent.manager.AgentManagerImpl$HandleAgentConnectTask.run(AgentM >anagerImpl.java:1160) >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 14:31:44,330 INFO [agent.manager.AgentManagerImpl] >(AgentConnectTaskPool-3561:null) Host 61 is disconnecting with event >AgentDisconnected >2013-10-22 14:31:44,331 DEBUG [agent.manager.AgentManagerImpl] >(AgentConnectTaskPool-3561:null) The next status of agent 61is Alert, >current status is Connecting >2013-10-22 14:31:44,331 DEBUG [agent.manager.AgentManagerImpl] >(AgentConnectTaskPool-3561:null) Deregistering link for 61 with state >Alert >2013-10-22 14:31:44,331 DEBUG [agent.manager.AgentManagerImpl] >(AgentConnectTaskPool-3561:null) Remove Agent : 61 >2013-10-22 14:31:44,331 DEBUG [agent.manager.ConnectedAgentAttache] >(AgentConnectTaskPool-3561:null) Processing Disconnect. >2013-10-22 14:31:44,331 DEBUG [agent.manager.AgentManagerImpl] >(AgentConnectTaskPool-3561:null) Sending Disconnect to listener: >com.cloud.hypervisor.xen.discoverer.XcpServerDiscoverer_EnhancerByCloudSta >ck_c871fe36 > > >----- > >Host id 61 which the log refers to (2013-10-22 14:31:44,329) is the SSVM >instance. I've logged in to SSVM and run a check using >/usr/local/cloud/systemvm/ssvm-check.sh, which did not produce any >problems/warnings/errors. > >Any idea how to fix this issue? > >Thanks > >Andrei >
