cloudstack-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Abhinav Roy <abhinav....@citrix.com>
Subject RE: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04
Date Thu, 27 Sep 2012 15:50:48 GMT
Hi,

I tried the install with Ubuntu KVM once again and here are my findings ,


1.       The cloud-scripts package was installed with install.sh scripts. So, that issue is fixed.

2.       I still see multiple instances of packages in the tarball. There are rc1, rc2 and beta versions of the same package

root@MS-ubuntu12:~/CloudStack-oss-4.0.0-208# ls

cloud-agent_4.0.0-beta1_amd64.deb       cloud-client_4.0.0-beta1_amd64.deb     cloud-python_4.0.0-beta1_amd64.deb   cloud-system-iso_4.0.0-beta1_amd64.deb

cloud-agent_4.0.0-rc1_amd64.deb         cloud-client_4.0.0-rc1_amd64.deb       cloud-python_4.0.0-rc1_amd64.deb     cloud-system-iso_4.0.0-rc1_amd64.deb

cloud-agent_4.0.0-rc2_amd64.deb         cloud-client_4.0.0-rc2_amd64.deb       cloud-python_4.0.0-rc2_amd64.deb     cloud-system-iso_4.0.0-rc2_amd64.deb

cloud-agent-deps_4.0.0-beta1_amd64.deb  cloud-client-ui_4.0.0-beta1_amd64.deb  cloud-scripts_4.0.0-beta1_amd64.deb  cloud-usage_4.0.0-beta1_amd64.deb

cloud-agent-deps_4.0.0-rc1_amd64.deb    cloud-client-ui_4.0.0-rc1_amd64.deb    cloud-scripts_4.0.0-rc1_amd64.deb    cloud-usage_4.0.0-rc1_amd64.deb

cloud-agent-deps_4.0.0-rc2_amd64.deb    cloud-client-ui_4.0.0-rc2_amd64.deb    cloud-scripts_4.0.0-rc2_amd64.deb    cloud-usage_4.0.0-rc2_amd64.deb

cloud-agent-libs_4.0.0-beta1_amd64.deb  cloud-core_4.0.0-beta1_amd64.deb       cloud-server_4.0.0-beta1_amd64.deb   cloud-utils_4.0.0-beta1_amd64.deb

cloud-agent-libs_4.0.0-rc1_amd64.deb    cloud-core_4.0.0-rc1_amd64.deb         cloud-server_4.0.0-rc1_amd64.deb     cloud-utils_4.0.0-rc1_amd64.deb

cloud-agent-libs_4.0.0-rc2_amd64.deb    cloud-core_4.0.0-rc2_amd64.deb         cloud-server_4.0.0-rc2_amd64.deb     cloud-utils_4.0.0-rc2_amd64.deb

cloud-cli_4.0.0-beta1_amd64.deb         cloud-deps_4.0.0-beta1_amd64.deb       cloud-setup_4.0.0-beta1_amd64.deb    install.sh

cloud-cli_4.0.0-rc1_amd64.deb           cloud-deps_4.0.0-rc1_amd64.deb         cloud-setup_4.0.0-rc1_amd64.deb      Packages.gz

cloud-cli_4.0.0-rc2_amd64.deb           cloud-deps_4.0.0-rc2_amd64.deb         cloud-setup_4.0.0-rc2_amd64.deb



We need to get rid of redundant packages.


3.       I also see a new issue with the latest build. Now, the management server installation is failing

Welcome to the Apache CloudStack (Incubating) Installer.  What would you like to do?



    M) Install the Management Server

    A) Install the Agent

    S) Install the Usage Monitor

    D) Install the database server

    Q) Quit



    > m

Installing the Management Server...

The following NEW packages will be installed:

  cloud-client cloud-client-ui{a} cloud-core{a} cloud-deps{a} cloud-python{a} cloud-scripts{a} cloud-server{a} cloud-setup{a} cloud-system-iso{a} cloud-utils{a}

0 packages upgraded, 10 newly installed, 0 to remove and 39 not upgraded.

Need to get 0 B/20.9 MB of archives. After unpacking 27.6 MB will be used.

Do you want to continue? [Y/n/?] y

WARNING: untrusted versions of the following packages will be installed!



Untrusted packages could compromise your system's security.

You should only proceed with the installation if you are certain that

this is what you want to do.



  cloud-client-ui cloud-setup cloud-system-iso cloud-python cloud-deps cloud-utils cloud-scripts cloud-core



Do you want to ignore this warning and proceed anyway?

To continue, enter "Yes"; to abort, enter "No": yes

91% [Working]Selecting previously unselected package cloud-deps.

(Reading database ... 55658 files and directories currently installed.)

Unpacking cloud-deps (from .../cloud-deps_4.0.0-beta1_amd64.deb) ...

Selecting previously unselected package cloud-utils.

Unpacking cloud-utils (from .../cloud-utils_4.0.0-beta1_amd64.deb) ...

Selecting previously unselected package cloud-core.

Unpacking cloud-core (from .../cloud-core_4.0.0-beta1_amd64.deb) ...

Selecting previously unselected package cloud-scripts.

Unpacking cloud-scripts (from .../cloud-scripts_4.0.0-beta1_amd64.deb) ...

Selecting previously unselected package cloud-server.

Unpacking cloud-server (from .../cloud-server_4.0.0-beta1_amd64.deb) ...

Selecting previously unselected package cloud-client-ui.

Unpacking cloud-client-ui (from .../cloud-client-ui_4.0.0-beta1_amd64.deb) ...

Selecting previously unselected package cloud-python.

Unpacking cloud-python (from .../cloud-python_4.0.0-beta1_amd64.deb) ...

Selecting previously unselected package cloud-setup.

Unpacking cloud-setup (from .../cloud-setup_4.0.0-beta1_amd64.deb) ...

Selecting previously unselected package cloud-system-iso.

Unpacking cloud-system-iso (from .../cloud-system-iso_4.0.0-beta1_amd64.deb) ...

Selecting previously unselected package cloud-client.

Unpacking cloud-client (from .../cloud-client_4.0.0-beta1_amd64.deb) ...

Processing triggers for ureadahead ...

Setting up cloud-deps (1:4.0.0-beta1) ...

Setting up cloud-utils (1:4.0.0-beta1) ...

Setting up cloud-core (1:4.0.0-beta1) ...

Setting up cloud-scripts (1:4.0.0-beta1) ...

Setting up cloud-server (1:4.0.0-beta1) ...

Setting up cloud-python (1:4.0.0-beta1) ...

Setting up cloud-setup (1:4.0.0-beta1) ...

Setting up cloud-system-iso (1:4.0.0-beta1) ...

Setting up cloud-client-ui (1:4.0.0-beta1) ...

Setting up cloud-client (1:4.0.0-beta1) ...

chmod: cannot access `/etc/cloud/management/db.properties': No such file or directory

dpkg: error processing cloud-client (--configure):

subprocess installed post-installation script returned error exit status 1

No apport report written because MaxReports is reached already

                                                              Errors were encountered while processing:

cloud-client

E: Sub-process /usr/bin/dpkg returned an error code (1)

A package failed to install.  Trying to recover:

Setting up cloud-client (1:4.0.0-beta1) ...

chmod: cannot access `/etc/cloud/management/db.properties': No such file or directory

dpkg: error processing cloud-client (--configure):

subprocess installed post-installation script returned error exit status 1

Errors were encountered while processing:

cloud-client



Done



Have filed a bug to track this https://issues.apache.org/jira/browse/CLOUDSTACK-224

Thanks and regards,
Abhinav

From: Rohit Yadav
Sent: Thursday, September 27, 2012 2:10 PM
To: Abhinav Roy
Cc: Edison Su; Prasanna Santhanam
Subject: Re: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04


On 27-Sep-2012, at 1:43 PM, Abhinav Roy <abhinav.roy@citrix.com<mailto:abhinav.roy@citrix.com>> wrote:


Hi Rohit,

I am using install.sh for installing but it doesn't install the cloud-scripts package. So only the installation of cloud-scripts package I need to do manually.


Hi, it was fixed by Wido yesterday; so cloud-server has cloud-scripts dependency now. Please try with the new/latest nonoss/oss build. If it is still a problem, let's ask Pradeep to fix this as he maintains the install.sh script.

commit 6839f7020c4458457589927198afc0866ae7eecc
Author: Wido den Hollander <wido@widodh.nl<mailto:wido@widodh.nl>>
Date:   Wed Sep 26 21:13:48 2012 +0200


Thanks and regards,
Abhinav

From: Rohit Yadav
Sent: Thursday, September 27, 2012 11:31 AM
To: Edison Su
Cc: Abhinav Roy; Prasanna Santhanam
Subject: Re: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04

+Prasanna

Abhinav/Edison;

Sorry almost missed this email. Will check the ubuntu build today.

@Edison, would it make sense to upload these debs [0], as soon as jenkins builds them successfully, to some server that sets up a small debian repository; like an unstable daily debian ppa? May be same for rpms... This way QA won't have to download, untar etc. they can only add the repo url once and apt-get install <> or yum install should work?

@Prasanna comments?

@Abhinav, you use install.sh for installing or manually install (dpkg -i) the debs?

Wido has fixed dependency of cloud-scripts on cloud-server:
commit ef48250bd99dc4f1180aadaadbd609facddaf3ca
Author:     Wido den Hollander <wido@widodh.nl<mailto:wido@widodh.nl>>
AuthorDate: Wed Sep 26 19:46:50 2012 +0200
Commit:     Wido den Hollander <wido@widodh.nl<mailto:wido@widodh.nl>>
CommitDate: Wed Sep 26 19:46:50 2012 +0200

[0] http://wiki.debian.org/HowToSetupADebianRepository

Regards.

On 26-Sep-2012, at 5:58 AM, edison su <edison.su@citrix.com<mailto:edison.su@citrix.com>> wrote:



Could you help to take a look at ubuntu installation? Basically, the installation step is wrong.
We'd better use the steps documented by wido: en-US/configure-package-repository.xml and en-US/hypervisor-host-install-agent.xml.

From: Abhinav Roy
Sent: Tuesday, September 25, 2012 2:59 PM
To: Edison Su; Rohit Yadav; cloudstack-dev@incubator.apache.org<mailto:cloudstack-dev@incubator.apache.org>
Cc: Sudha Ponnaganti; Sowmya Krishnan; Sailaja Mada; Suresh Sadhu; Shweta Agarwal; Prashant Kumar Mishra; Srinivas Vejalla
Subject: RE: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04

Sure Edison. We will take care of that.

From: Edison Su
Sent: Wednesday, September 26, 2012 3:18 AM
To: Abhinav Roy; Rohit Yadav; cloudstack-dev@incubator.apache.org<mailto:cloudstack-dev@incubator.apache.org>
Cc: Sudha Ponnaganti; Sowmya Krishnan; Sailaja Mada; Suresh Sadhu; Shweta Agarwal; Prashant Kumar Mishra; Srinivas Vejalla
Subject: RE: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04

I think the procedure you are doing is not correct.
As I said, all you need to do:
1.       Install agent
2.       Add agent into mgt server from UI.
3.       If add agent failed, then failed. Fire a bug for it. Don't need to start/stop cloud-agent manually.

From: Abhinav Roy
Sent: Tuesday, September 25, 2012 2:46 PM
To: Edison Su; Rohit Yadav; cloudstack-dev@incubator.apache.org<mailto:cloudstack-dev@incubator.apache.org>
Cc: Sudha Ponnaganti; Sowmya Krishnan; Sailaja Mada; Suresh Sadhu; Shweta Agarwal; Prashant Kumar Mishra; Srinivas Vejalla
Subject: RE: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04

Hi Edison,

Actually what happens exactly is after installing the agent I was not able to see the agent logs before adding it to the host, logs were seen only after starting the cloud-agent manually.
So I have not actually tried adding host to MS without starting cloud-agent manually.


Thanks and regards,
Abhinav
From: Edison Su
Sent: Wednesday, September 26, 2012 3:10 AM
To: Abhinav Roy; Rohit Yadav; cloudstack-dev@incubator.apache.org<mailto:cloudstack-dev@incubator.apache.org>
Cc: Sudha Ponnaganti; Sowmya Krishnan; Sailaja Mada; Suresh Sadhu; Shweta Agarwal; Prashant Kumar Mishra; Srinivas Vejalla
Subject: RE: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04

Need to install agent on kvm host(./install.sh), then add the host into mgt server from UI. Doesn't work during this procedure?

From: Abhinav Roy
Sent: Tuesday, September 25, 2012 2:34 PM
To: Edison Su; Rohit Yadav; cloudstack-dev@incubator.apache.org<mailto:cloudstack-dev@incubator.apache.org>
Cc: Sudha Ponnaganti; Sowmya Krishnan; Sailaja Mada; Suresh Sadhu; Shweta Agarwal; Prashant Kumar Mishra; Srinivas Vejalla
Subject: RE: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04

For the last exception in step 5, I forgot to mention this. We need to start cloud-agent service after installing the agent in case of both Ubuntu and Rhel KVM otherwise we don't see the
Agent logs at the location /var/log/cloud/agent.

From: Edison Su
Sent: Wednesday, September 26, 2012 2:56 AM
To: Abhinav Roy; Rohit Yadav; cloudstack-dev@incubator.apache.org<mailto:cloudstack-dev@incubator.apache.org>
Cc: Sudha Ponnaganti; Sowmya Krishnan; Sailaja Mada; Suresh Sadhu; Shweta Agarwal; Prashant Kumar Mishra; Srinivas Vejalla
Subject: RE: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04



From: Abhinav Roy
Sent: Tuesday, September 25, 2012 2:17 PM
To: Rohit Yadav; Edison Su; cloudstack-dev@incubator.apache.org<mailto:cloudstack-dev@incubator.apache.org>
Cc: Sudha Ponnaganti; Sowmya Krishnan; Sailaja Mada; Suresh Sadhu; Shweta Agarwal; Prashant Kumar Mishra; Srinivas Vejalla
Subject: Few observations while installing agent on KVM host (ubuntu 12.04) and Management server on ubuntu 12.04

Hi Rohit,

I had the following observation while installing agent on KVM host (Ubuntu) and adding it to the management server (Ubuntu) [it was a fresh install] :

1.       I had used the build http://jenkins.cloudstack.org/job/build-4.0-ubuntu1204/154/artifact/CloudStack-oss-4.0.0-154.tar.bz2 . There I saw multiple instances of the same package after untarring

cloud-agent_4.0.0-rc1_amd64.deb       cloud-cli_4.0.0-rc2_amd64.deb        cloud-deps_4.0.0-rc1_amd64.deb     cloud-server_4.0.0-rc2_amd64.deb      cloud-utils_4.0.0-rc1_amd64.deb
cloud-agent_4.0.0-rc2_amd64.deb       cloud-client_4.0.0-rc1_amd64.deb     cloud-deps_4.0.0-rc2_amd64.deb     cloud-setup_4.0.0-rc1_amd64.deb       cloud-utils_4.0.0-rc2_amd64.deb
cloud-agent-deps_4.0.0-rc1_amd64.deb  cloud-client_4.0.0-rc2_amd64.deb     cloud-python_4.0.0-rc1_amd64.deb   cloud-setup_4.0.0-rc2_amd64.deb       install.sh
cloud-agent-deps_4.0.0-rc2_amd64.deb  cloud-client-ui_4.0.0-rc1_amd64.deb  cloud-python_4.0.0-rc2_amd64.deb   cloud-system-iso_4.0.0-rc1_amd64.deb  Packages.gz
cloud-agent-libs_4.0.0-rc1_amd64.deb  cloud-client-ui_4.0.0-rc2_amd64.deb  cloud-scripts_4.0.0-rc1_amd64.deb  cloud-system-iso_4.0.0-rc2_amd64.deb
cloud-agent-libs_4.0.0-rc2_amd64.deb  cloud-core_4.0.0-rc1_amd64.deb       cloud-scripts_4.0.0-rc2_amd64.deb  cloud-usage_4.0.0-rc1_amd64.deb
cloud-cli_4.0.0-rc1_amd64.deb         cloud-core_4.0.0-rc2_amd64.deb       cloud-server_4.0.0-rc1_amd64.deb   cloud-usage_4.0.0-rc2_amd64.deb

Is this the new way of packaging?

[Edison] The packaging is wrong. Need to remove the old debs.

2.       I did the agent install using install.sh script but this script doesn't install the cloud-scripts package, so after running install.sh I had to install scripts package manually. So, do we need to do this always?
[Edison] Need to be fixed in install.sh
3.       The script for copying the systemvm-template to secondary storage is located at /usr/lib/cloud/common/scripts/storage/secondary/cloud-install-sys-tmplt while for Rhel 6.3 it is stored at/usr/lib64/cloud/common/scripts/storage/secondary/cloud-install-sys-tmplt. Is this going to be documented?
[Edison] Need to be documented.
4.       After management server and DB server installation was done and I was going to configure the CS through UI, I was not able to login to the UI with the default admin/password credentials. I saw these errors in the logs......

2012-09-25 15:29:33,568 DEBUG [utils.script.Script] (main:null) Looking for vms/systemvm.iso in /usr/lib/cloud/common/vms/systemvm.iso
2012-09-25 15:29:33,570 ERROR [cloud.servlet.CloudStartupServlet] (main:null) Exception starting management server
com.cloud.utils.exception.CloudRuntimeException: Unable to find key inject script scripts/vm/systemvm/injectkeys.sh
        at com.cloud.server.ConfigurationServerImpl.updateKeyPairs(ConfigurationServerImpl.java:675)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)        at com.cloud.server.ConfigurationServerImpl.persistDefaultValues(ConfigurationServerImpl.java:265)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)        at com.cloud.servlet.CloudStartupServlet.init(CloudStartupServlet.java:47)
        at javax.servlet.GenericServlet.init(GenericServlet.java:212)
        at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1206)
        at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1026)
        at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4421)
        at org.apache.catalina.core.StandardContext.start(StandardContext.java:4734)        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:799)        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:779)        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:601)        at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1079)        at org.apache.catalina.startup.HostConfig.deployDirectories(HostConfig.java:1002)        at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:506)
        at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1317)
        at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:324)
        at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:142)
        at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1065)        at org.apache.catalina.core.StandardHost.start(StandardHost.java:840)        at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1057)        at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:463)        at org.apache.catalina.core.StandardService.start(StandardService.java:525)
        at org.apache.catalina.core.StandardServer.start(StandardServer.java:754)
        at org.apache.catalina.startup.Catalina.start(Catalina.java:595)
        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.catalina.startup.Bootstrap.start(Bootstrap.java:289)
        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.commons.daemon.support.DaemonLoader.start(DaemonLoader.java:243)

but after restarting the management server , I was able to login with the default credentials. Is this expected and is going to be documented?

[Edison] I think it's due to cloud-scripts package is not installed.

5.       Now while adding the host I got the following exception, though the host got added successfully , but this exception was found in the management server logs

2012-09-25 15:57:45,074 DEBUG [agent.manager.AgentManagerImpl] (AgentTaskPool-1:null) Sending Disconnect to listener: com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener
2012-09-25 15:57:45,074 DEBUG [cloud.network.NetworkUsageManagerImpl] (AgentTaskPool-1:null) Disconnected called on 1 with status Disconnected
2012-09-25 15:57:45,074 DEBUG [cloud.host.Status] (AgentTaskPool-1:null) Transition:[Resource state = Enabled, Agent event = ShutdownRequested, Host id = 1, name = BAND-CLOUD-19]
2012-09-25 15:57:45,076 DEBUG [cloud.ha.HighAvailabilityManagerImpl] (secstorage-1:null) Scheduled HAWork[1-CheckStop-1-Starting-Scheduled]
2012-09-25 15:57:45,082 INFO  [cloud.ha.HighAvailabilityManagerImpl] (HA-Worker-0:work-1) Processing HAWork[1-CheckStop-1-Starting-Scheduled]
2012-09-25 15:57:45,084 INFO  [cloud.ha.HighAvailabilityManagerImpl] (HA-Worker-0:work-1) Stopping VM[SecondaryStorageVm|s-1-VM]
2012-09-25 15:57:45,085 DEBUG [cloud.vm.VirtualMachineManagerImpl] (HA-Worker-0:work-1) Found an outstanding work item for this vm VM[SecondaryStorageVm|s-1-VM] with state:Starting, work id:54d69a61-135d-4cd1-add5-3ed6265c71dc
2012-09-25 15:57:45,092 ERROR [cloud.ha.HighAvailabilityManagerImpl] (HA-Worker-0:work-1) Terminating HAWork[1-CheckStop-1-Starting-Scheduled]
com.cloud.utils.exception.CloudRuntimeException: We cannot stop VM[SecondaryStorageVm|s-1-VM] when it is in state Starting
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1030)
        at com.cloud.ha.HighAvailabilityManagerImpl.stopVM(HighAvailabilityManagerImpl.java:645)
        at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:837)
2012-09-25 15:57:45,092 WARN  [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Exception while trying to start secondary storage vm
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is unreachable: Host 1: Unable to start s-1-VM
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:825)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:257)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:684)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1310)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:119)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:106)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
       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)
Caused by: com.cloud.exception.OperationTimedoutException: Commands 1514209300 to Host 1 timed out after 3600
        at com.cloud.agent.manager.AgentAttache.send(AgentAttache.java:429)
        at com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:505)
        at com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:1026)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:778)
        ... 20 more
2012-09-25 15:57:45,097 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
2012-09-25 15:57:45,097 INFO  [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null) Primary secondary storage is not even started, wait until next turn
2012-09-25 15:57:45,099 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,121 DEBUG [cloud.host.Status] (AgentTaskPool-1:null) Agent status update: [id = 1; name = BAND-CLOUD-19; old status = Up; event = ShutdownRequested; new status = Disconnected; old update count = 2; new update count = 3]
2012-09-25 15:57:45,121 DEBUG [agent.manager.ClusteredAgentManagerImpl] (AgentTaskPool-1:null) Notifying other nodes of to disconnect
2012-09-25 15:57:45,124 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,126 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,128 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,130 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,132 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,138 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,140 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,142 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,150 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,151 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:57:45,153 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:58:10,801 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:58:10,959 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2012-09-25 15:58:11,469 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Snapshot scheduler.poll is being called at 2012-09-25 10:28:11 GMT
2012-09-25 15:58:11,470 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Got 0 snapshots to be executed at 2012-09-25 10:28:11 GMT
2012-09-25 15:58:11,503 DEBUG [cloud.network.ExternalLoadBalancerUsageManagerImpl] (ExternalNetworkMonitor-1:null) External load balancer devices stats collector is running...
2012-09-25 15:58:11,546 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) Found 0 running routers.
2012-09-25 15:58:11,548 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers.
2012-09-25 15:58:16,191 DEBUG [utils.ssh.SSHCmdHelper] (catalina-exec-13:null) cloud-setup-agent  -m 10.102.125.241 -z 1 -p 1 -c 1 -g d8830471-0deb-31e3-aef0-30a145f93689 -a --pubNic=cloudbr0 --prvNic=cloudbr0 --guestNic=cloudbr0 output:CloudStack Agent setup is done!
   [OK]
Configure cloudAgent ...
2012-09-25 15:58:19,404 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-0: Processing the first command  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 1, [{"StartupRoutingCommand":{"cpus":8,"speed":2394,"memory":16814125056,"dom0MinMemory":805306368,"poolSync":false,"vms":{"v-2-VM":{"state":"Running"},"s-1-VM":{"state":"Running"}},"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS":"Ubuntu","Host.OS.Kernel.Version":"3.2.0-23-generic","Host.OS.Version":"12.04"},"type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"d8830471-0deb-31e3-aef0-30a145f93689-LibvirtComputingResource","name":"BAND-CLOUD-19","id":1,"version":"2.2.20120925090538","publicIpAddress":"10.102.125.19","publicNetmask":"255.255.255.0","publicMacAddress":"78:2b:cb:5e:d1:cb","privateIpAddress":"10.102.125.19","privateMacAddress":"78:2b:cb:5e:d1:cb","privateNetmask":"255.255.255.0","storageIpAddress":"10.102.125.19","storageNetmask":"255.255.255.0","storageMacAddress":"78:2b:cb:5e:d1:cb","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.102.125.1","wait":0}},{"StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"b0581710-be0b-4818-9869-ff12bd9fe08e","host":"10.102.125.19","localPath":"/var/lib/libvirt/images/","hostPath":"/var/lib/libvirt/images/","poolType":"Filesystem","capacityBytes":481872109568,"availableBytes":8612806656},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","pod":"1","guid":"d8830471-0deb-31e3-aef0-30a145f93689-LibvirtComputingResource","name":"BAND-CLOUD-19","id":1,"version":"2.2.20120925090538","resourceName":"LibvirtComputingResource","wait":0}}] }
2012-09-25 15:58:19,415 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-13:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to NiciraNvpElement$$EnhancerByCGLIB$$3eb29c70
2012-09-25 15:58:19,415 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-13:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to XcpServerDiscoverer$$EnhancerByCGLIB$$cb61f98
2012-09-25 15:58:19,415 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-13:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to PxeServerManagerImpl$$EnhancerByCGLIB$$803542e0
2012-09-25 15:58:19,415 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-13:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to ConsoleProxyManagerImpl$$EnhancerByCGLIB$$7666f719
2012-09-25 15:58:19,415 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-13:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to ExternalDhcpManagerImpl$$EnhancerByCGLIB$$b1df3ce6
2012-09-25 15:58:19,416 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-13:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to PremiumSecondaryStorageManagerImpl$$EnhancerByCGLIB$$b40686c1
2012-09-25 15:58:19,416 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-13:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to NetworkUsageManagerImpl$$EnhancerByCGLIB$$913212a8
2012-09-25 15:58:19,416 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-13:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to KvmServerDiscoverer$$EnhancerByCGLIB$$20bb7634
2012-09-25 15:58:19,448 DEBUG [cloud.resource.ResourceState] (AgentManager-Handler-13:null) Resource state update: [id = 1; name = BAND-CLOUD-19; old state = Enabled; event = InternalCreated; new state = Enabled]
2012-09-25 15:58:19,449 DEBUG [cloud.host.Status] (AgentManager-Handler-13:null) Transition:[Resource state = Enabled, Agent event = AgentConnected, Host id = 1, name = BAND-CLOUD-19]
2012-09-25 15:58:19,454 DEBUG [cloud.host.Status] (AgentManager-Handler-13:null) Agent status update: [id = 1; name = BAND-CLOUD-19; old status = Disconnected; event = AgentConnected; new status = Connecting; old update count = 3; new update count = 4]
2012-09-25 15:58:19,454 DEBUG [agent.manager.ClusteredAgentManagerImpl] (AgentManager-Handler-13:null) create ClusteredAgentAttache for 1
2012-09-25 15:58:19,456 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: XcpServerDiscoverer$$EnhancerByCGLIB$$cb61f98
2012-09-25 15:58:19,456 DEBUG [xen.discoverer.XcpServerDiscoverer] (AgentManager-Handler-13:null) Not XenServer so moving on.
2012-09-25 15:58:19,456 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: ClusteredVirtualMachineManagerImpl$$EnhancerByCGLIB$$7c5727bd
2012-09-25 15:58:19,472 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) Found 2 VMs for host 1
2012-09-25 15:58:19,478 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM s-1-VM: cs state = Starting and realState = Running
2012-09-25 15:58:19,480 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM s-1-VM: cs state = Starting and realState = Running
2012-09-25 15:58:19,481 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM state is starting on full sync so updating it to running
2012-09-25 15:58:19,488 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) Found an outstanding work item for this vm VM[SecondaryStorageVm|s-1-VM] in state:Starting, work id:54d69a61-135d-4cd1-add5-3ed6265c71dc
2012-09-25 15:58:19,504 DEBUG [cloud.capacity.CapacityManagerImpl] (AgentManager-Handler-13:null) VM state transitted from :Starting to Running with event: AgentReportRunningvm's original host id: null new host id: 1 host id before state transition: 1
2012-09-25 15:58:19,504 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM's VM[SecondaryStorageVm|s-1-VM] state is starting on full sync so updating it to Running
2012-09-25 15:58:19,514 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) Finalizing commands that need to be send to complete Start process for the vm VM[SecondaryStorageVm|s-1-VM]
2012-09-25 15:58:19,521 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493889: Sending  { Cmd , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 100011, [{"check.CheckSshCommand":{"ip":"169.254.2.123","port":3922,"interval":6,"retries":100,"name":"s-1-VM","wait":0}}] }
2012-09-25 15:58:19,640 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-14:null) Ping from 1
2012-09-25 15:58:25,554 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running...
2012-09-25 15:58:27,145 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-15:null) Ping from 3
2012-09-25 15:58:31,006 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) HostStatsCollector is running...
2012-09-25 15:58:36,692 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
2012-09-25 15:58:36,695 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) There is no secondary storage VM for secondary storage host nfs://10.102.123.240/cloudstack/abhinav/SS-ubuntu
2012-09-25 15:58:40,801 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
2012-09-25 15:58:40,965 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2012-09-25 15:58:41,446 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Running Capacity Checker ...
2012-09-25 15:58:41,446 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) recalculating system capacity
2012-09-25 15:58:41,446 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Executing cpu/ram capacity update
2012-09-25 15:58:41,451 DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:null) Found 2 VMs on host 1
2012-09-25 15:58:41,452 DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:null) Found 0 VM, not running on host 1
2012-09-25 15:58:41,454 DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:null) No need to calibrate cpu capacity, host:1 usedCpu: 1000 reservedCpu: 0
2012-09-25 15:58:41,454 DEBUG [cloud.capacity.CapacityManagerImpl] (CapacityChecker:null) No need to calibrate memory capacity, host:1 usedMem: 1342177280 reservedMem: 0
2012-09-25 15:58:41,454 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done executing cpu/ram capacity update
2012-09-25 15:58:41,454 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Executing storage capacity update
2012-09-25 15:58:41,461 DEBUG [cloud.storage.StorageManagerImpl] (CapacityChecker:null) Successfully set Capacity - 15739424079872 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 200, PodId 1
2012-09-25 15:58:41,461 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done executing storage capacity update
2012-09-25 15:58:41,461 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Executing capacity updates for public ip and Vlans
2012-09-25 15:58:41,477 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done capacity updates for public ip and Vlans
2012-09-25 15:58:41,477 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Executing capacity updates for private ip
2012-09-25 15:58:41,483 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done executing capacity updates for private ip
2012-09-25 15:58:41,483 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done recalculating system capacity
2012-09-25 15:58:41,496 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done running Capacity Checker ...
2012-09-25 15:58:41,549 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers.
2012-09-25 15:59:08,578 DEBUG [agent.transport.Request] (AgentManager-Handler-1:null) Seq 1-195493889: Processing:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 10, [{"check.CheckSshAnswer":{"result":true,"wait":0}}] }
2012-09-25 15:59:08,578 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493889: Received:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 10, { CheckSshAnswer } }
2012-09-25 15:59:08,588 DEBUG [cloud.capacity.CapacityManagerImpl] (AgentManager-Handler-13:null) VM state transitted from :Running to Running with event: AgentReportRunningvm's original host id: null new host id: 1 host id before state transition: 1
2012-09-25 15:59:08,588 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) Updating outstanding work item to Done, id:54d69a61-135d-4cd1-add5-3ed6265c71dc
2012-09-25 15:59:08,592 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM v-2-VM: cs state = Running and realState = Running
2012-09-25 15:59:08,592 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM v-2-VM: cs state = Running and realState = Running
2012-09-25 15:59:08,592 DEBUG [cloud.vm.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) Both states are Running for VM[ConsoleProxy|v-2-VM]
2012-09-25 15:59:08,605 DEBUG [cloud.capacity.CapacityManagerImpl] (AgentManager-Handler-13:null) VM state transitted from :Running to Running with event: AgentReportRunningvm's original host id: 1 new host id: 1 host id before state transition: 1
2012-09-25 15:59:08,605 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: SecurityGroupListener
2012-09-25 15:59:08,605 INFO  [network.security.SecurityGroupListener] (AgentManager-Handler-13:null) Received a host startup notification
2012-09-25 15:59:08,608 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493890: Sending  { Cmd , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 100011, [{"CleanupNetworkRulesCmd":{"interval":1976,"wait":0}}] }
2012-09-25 15:59:08,609 INFO  [network.security.SecurityGroupListener] (AgentManager-Handler-13:null) Scheduled network rules cleanup, interval=1976
2012-09-25 15:59:08,609 INFO  [network.security.SecurityGroupListener] (AgentManager-Handler-13:null) Received a host startup notification
2012-09-25 15:59:08,609 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: StoragePoolMonitor
2012-09-25 15:59:08,610 DEBUG [storage.listener.StoragePoolMonitor] (AgentManager-Handler-13:null) Host 1 connected, sending down storage pool information ...
2012-09-25 15:59:08,610 DEBUG [cloud.storage.StorageManagerImpl] (AgentManager-Handler-13:null) Adding pool p1 to  host 1
2012-09-25 15:59:08,612 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493891: Sending  { Cmd , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 100011, [{"ModifyStoragePoolCommand":{"add":true,"pool":{"id":200,"uuid":"ef0bdc65-34ea-3472-a4a4-82f605f01593","host":"10.102.123.240","path":"/cloudstack/abhinav/PS-ubuntu","port":2049,"type":"NetworkFilesystem"},"localPath":"/mnt//ef0bdc65-34ea-3472-a4a4-82f605f01593","wait":0}}] }
2012-09-25 15:59:08,614 DEBUG [agent.transport.Request] (AgentManager-Handler-3:null) Seq 1-195493890: Processing:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 10, [{"Answer":{"result":true,"wait":0}}] }
2012-09-25 15:59:08,674 DEBUG [agent.transport.Request] (AgentManager-Handler-5:null) Seq 1-195493891: Processing:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 10, [{"ModifyStoragePoolAnswer":{"poolInfo":{"host":"10.102.123.240","localPath":"/mnt//ef0bdc65-34ea-3472-a4a4-82f605f01593","hostPath":"/cloudstack/abhinav/PS-ubuntu","poolType":"NetworkFilesystem","capacityBytes":7869712039936,"availableBytes":4545246789632},"templateInfo":{},"result":true,"wait":0}}] }
2012-09-25 15:59:08,674 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493891: Received:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 10, { ModifyStoragePoolAnswer } }
2012-09-25 15:59:08,680 INFO  [cloud.storage.StorageManagerImpl] (AgentManager-Handler-13:null) Connection established between Pool[200|NetworkFilesystem] host + 1
2012-09-25 15:59:08,681 DEBUG [cloud.storage.StorageManagerImpl] (AgentManager-Handler-13:null) Successfully set Capacity - 15739424079872 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 200, PodId 1
2012-09-25 15:59:08,681 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: SecondaryStorageListener
2012-09-25 15:59:08,681 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: NetworkManagerImpl$$EnhancerByCGLIB$$a11338d9
2012-09-25 15:59:08,682 DEBUG [cloud.network.NetworkManagerImpl] (AgentManager-Handler-13:null) Host's hypervisorType is: KVM
2012-09-25 15:59:08,687 DEBUG [cloud.network.NetworkManagerImpl] (AgentManager-Handler-13:null) Sending CheckNetworkCommand to check the Network is setup correctly on Agent
2012-09-25 15:59:08,688 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493892: Sending  { Cmd , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 100111, [{"CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":200}],"wait":0}}] }
2012-09-25 15:59:08,710 DEBUG [agent.transport.Request] (AgentManager-Handler-4:null) Seq 1-195493890: Processing:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 10, [{"Answer":{"result":true,"details":"","wait":0}}] }
2012-09-25 15:59:08,749 DEBUG [agent.transport.Request] (AgentManager-Handler-7:null) Seq 1-195493892: Processing:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 110, [{"CheckNetworkAnswer":{"_reconnect":false,"result":true,"wait":0}}] }
2012-09-25 15:59:08,750 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-7:null) Seq 1-195493892: No more commands found
2012-09-25 15:59:08,750 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493892: Received:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 110, { CheckNetworkAnswer } }
2012-09-25 15:59:08,750 DEBUG [cloud.network.NetworkManagerImpl] (AgentManager-Handler-13:null) Network setup is correct on Agent
2012-09-25 15:59:08,750 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: AgentMonitor$$EnhancerByCGLIB$$11a88b39
2012-09-25 15:59:08,750 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: DownloadListener
2012-09-25 15:59:08,752 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: UploadListener
2012-09-25 15:59:08,752 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: LocalStoragePoolListener$$EnhancerByCGLIB$$a3a4d76d
2012-09-25 15:59:08,752 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: StorageCapacityListener
2012-09-25 15:59:08,752 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: ComputeCapacityListener
2012-09-25 15:59:08,755 DEBUG [cloud.capacity.CapacityManagerImpl] (AgentManager-Handler-13:null) Found 2 VMs on host 1
2012-09-25 15:59:08,764 DEBUG [cloud.capacity.CapacityManagerImpl] (AgentManager-Handler-13:null) Found 0 VM, not running on host 1
2012-09-25 15:59:08,767 DEBUG [cloud.capacity.CapacityManagerImpl] (AgentManager-Handler-13:null) No need to calibrate cpu capacity, host:1 usedCpu: 1000 reservedCpu: 0
2012-09-25 15:59:08,767 DEBUG [cloud.capacity.CapacityManagerImpl] (AgentManager-Handler-13:null) No need to calibrate memory capacity, host:1 usedMem: 1342177280 reservedMem: 0
2012-09-25 15:59:08,767 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: ConsoleProxyListener
2012-09-25 15:59:08,767 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: SshKeysDistriMonitor
2012-09-25 15:59:08,771 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493893: Sending  { Cmd , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 100011, [{"ModifySshKeysCommand":{"wait":0}}] }
2012-09-25 15:59:08,771 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: VpcVirtualNetworkApplianceManagerImpl$$EnhancerByCGLIB$$ad9d1c61
2012-09-25 15:59:08,773 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Sending Connect to listener: DirectNetworkStatsListener
2012-09-25 15:59:08,775 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493894: Sending  { Cmd , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 100111, [{"ReadyCommand":{"dcId":1,"wait":0}}] }
2012-09-25 15:59:08,783 DEBUG [agent.transport.Request] (AgentManager-Handler-8:null) Seq 1-195493893: Processing:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 10, [{"Answer":{"result":true,"wait":0}}] }
2012-09-25 15:59:08,821 DEBUG [agent.transport.Request] (AgentManager-Handler-2:null) Seq 1-195493894: Processing:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 110, [{"ReadyAnswer":{"result":true,"wait":0}}] }
2012-09-25 15:59:08,821 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-2:null) Seq 1-195493894: No more commands found
2012-09-25 15:59:08,822 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 1-195493894: Received:  { Ans: , MgmtId: 165676482560269, via: 1, Ver: v1, Flags: 110, { ReadyAnswer } }
2012-09-25 15:59:08,822 DEBUG [cloud.host.Status] (AgentManager-Handler-13:null) Transition:[Resource state = Enabled, Agent event = Ready, Host id = 1, name = BAND-CLOUD-19]
2012-09-25 15:59:08,825 DEBUG [cloud.host.Status] (AgentManager-Handler-13:null) Agent status update: [id = 1; name = BAND-CLOUD-19; old status = Connecting; event = Ready; new status = Up; old update count = 4; new update count = 5]
2012-09-25 15:59:10,427 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq -1-0: Processing the first command  { Cmd , MgmtId: -1, via: -1, Ver: v1, Flags: 101, [{"StartupSecondaryStorageCommand":{"type":"SecondaryStorage","dataCenter":"1","pod":"1","guid":"s-1-VM-NfsSecondaryStorageResource","name":"s-1-VM","version":"2.2.20120925090538","iqn":"NoIqn","publicIpAddress":"10.102.125.67","publicNetmask":"255.255.255.0","publicMacAddress":"06:39:4c:00:00:07","privateIpAddress":"10.102.125.62","privateMacAddress":"06:2b:3e:00:00:02","privateNetmask":"255.255.255.0","storageIpAddress":"10.102.125.62","storageNetmask":"255.255.255.0","storageMacAddress":"06:2b:3e:00:00:02","resourceName":"NfsSecondaryStorageResource","wait":0}}] }
2012-09-25 15:59:10,431 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-9:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to NiciraNvpElement$$EnhancerByCGLIB$$3eb29c70
2012-09-25 15:59:10,431 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-9:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to XcpServerDiscoverer$$EnhancerByCGLIB$$cb61f98
2012-09-25 15:59:10,431 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-9:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to PxeServerManagerImpl$$EnhancerByCGLIB$$803542e0
2012-09-25 15:59:10,431 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-9:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to ConsoleProxyManagerImpl$$EnhancerByCGLIB$$7666f719
2012-09-25 15:59:10,431 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-9:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to ExternalDhcpManagerImpl$$EnhancerByCGLIB$$b1df3ce6
2012-09-25 15:59:10,431 DEBUG [cloud.resource.ResourceManagerImpl] (AgentManager-Handler-9:null) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to PremiumSecondaryStorageManagerImpl$$EnhancerByCGLIB$$b40686c1
2012-09-25 15:59:10,437 DEBUG [cloud.resource.ResourceState] (AgentManager-Handler-9:null) Resource state update: [id = 4; name = s-1-VM; old state = Creating; event = InternalCreated; new state = Enabled]
2012-09-25 15:59:10,437 DEBUG [cloud.host.Status] (AgentManager-Handler-9:null) Transition:[Resource state = Enabled, Agent event = AgentConnected, Host id = 4, name = s-1-VM]
2012-09-25 15:59:10,460 DEBUG [cloud.host.Status] (AgentManager-Handler-9:null) Agent status update: [id = 4; name = s-1-VM; old status = Creating; event = AgentConnected; new status = Connecting; old update count = 0; new update count = 1]
2012-09-25 15:59:10,460 DEBUG [agent.manager.ClusteredAgentManagerImpl] (AgentManager-Handler-9:null) create ClusteredAgentAttache for 4
2012-09-25 15:59:10,462 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: XcpServerDiscoverer$$EnhancerByCGLIB$$cb61f98
2012-09-25 15:59:10,462 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: ClusteredVirtualMachineManagerImpl$$EnhancerByCGLIB$$7c5727bd
2012-09-25 15:59:10,462 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: SecurityGroupListener
2012-09-25 15:59:10,462 INFO  [network.security.SecurityGroupListener] (AgentManager-Handler-9:null) Received a host startup notification
2012-09-25 15:59:10,463 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: StoragePoolMonitor
2012-09-25 15:59:10,463 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: SecondaryStorageListener
2012-09-25 15:59:10,463 INFO  [storage.secondary.SecondaryStorageListener] (AgentManager-Handler-9:null) Received a host startup notification com.cloud.agent.api.StartupSecondaryStorageCommand
2012-09-25 15:59:10,472 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998081: Sending  { Cmd , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 100111, [{"SecStorageSetupCommand":{"secUrl":"nfs://10.102.123.240/cloudstack/abhinav/SS-ubuntu","certs":{},"wait":0}}] }
2012-09-25 15:59:10,566 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:null) Ping from 4
2012-09-25 15:59:10,804 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2012-09-25 15:59:10,965 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
2012-09-25 15:59:11,549 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers.
2012-09-25 15:59:12,430 DEBUG [agent.transport.Request] (AgentManager-Handler-11:null) Seq 4-173998081: Processing:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, [{"SecStorageSetupAnswer":{"_dir":"d24c72b9-3fe8-34b1-ad54-af523e0cfdb0","result":true,"details":"success","wait":0}}] }
2012-09-25 15:59:12,431 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998081: Received:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, { SecStorageSetupAnswer } }
2012-09-25 15:59:12,431 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Details from executing class com.cloud.agent.api.SecStorageSetupCommand: success
2012-09-25 15:59:12,433 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-11:null) Seq 4-173998081: No more commands found
2012-09-25 15:59:12,444 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (AgentManager-Handler-9:null) Successfully programmed secondary storage nfs://10.102.123.240/cloudstack/abhinav/SS-ubuntu in secondary storage VM s-1-VM
2012-09-25 15:59:12,450 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998082: Sending  { Cmd , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 100011, [{"SecStorageFirewallCfgCommand":{"isAppendAIp":false,"wait":0}}] }
2012-09-25 15:59:12,514 DEBUG [agent.transport.Request] (AgentManager-Handler-12:null) Seq 4-173998082: Processing:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 10, [{"Answer":{"result":true,"wait":0}}] }
2012-09-25 15:59:12,514 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998082: Received:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 10, { Answer } }
2012-09-25 15:59:12,514 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (AgentManager-Handler-9:null) Successfully programmed firewall rules into s-1-VM
2012-09-25 15:59:12,519 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998083: Sending  { Cmd , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 100111, [{"SecStorageVMSetupCommand":{"allowedInternalSites":[],"copyUserName":"cloud","copyPassword":"kB5dcuwbyfpjvwr","wait":0}}] }
2012-09-25 15:59:12,630 DEBUG [agent.transport.Request] (AgentManager-Handler-14:null) Seq 4-173998083: Processing:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, [{"Answer":{"result":true,"details":"","wait":0}}] }
2012-09-25 15:59:12,630 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-14:null) Seq 4-173998083: No more commands found
2012-09-25 15:59:12,630 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998083: Received:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, { Answer } }
2012-09-25 15:59:12,630 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Details from executing class com.cloud.agent.api.SecStorageVMSetupCommand:
2012-09-25 15:59:12,630 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (AgentManager-Handler-9:null) Successfully programmed http auth into s-1-VM
2012-09-25 15:59:12,630 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: NetworkManagerImpl$$EnhancerByCGLIB$$a11338d9
2012-09-25 15:59:12,630 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: AgentMonitor$$EnhancerByCGLIB$$11a88b39
2012-09-25 15:59:12,631 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: DownloadListener
2012-09-25 15:59:12,635 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998084: Sending  { Cmd , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 100111, [{"storage.ListTemplateCommand":{"secUrl":"nfs://10.102.123.240/cloudstack/abhinav/SS-ubuntu","wait":0}}] }
2012-09-25 15:59:12,783 DEBUG [agent.transport.Request] (AgentManager-Handler-15:null) Seq 4-173998084: Processing:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, [{"storage.ListTemplateAnswer":{"secUrl":"nfs://10.102.123.240/cloudstack/abhinav/SS-ubuntu","templateInfos":{"routing-3":{"templateName":"routing-3","installPath":"template/tmpl/1/3//9929242b-4048-4b3b-9d36-1052dc442d01.qcow2","size":725811200,"physicalSize":725811200,"id":3,"isPublic":true,"isCorrupted":false}},"result":true,"details":"success","wait":0}}] }
2012-09-25 15:59:12,783 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-15:null) Seq 4-173998084: No more commands found
2012-09-25 15:59:12,783 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998084: Received:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, { ListTemplateAnswer } }
2012-09-25 15:59:12,783 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Details from executing class com.cloud.agent.api.storage.ListTemplateCommand: success
2012-09-25 15:59:12,789 INFO  [storage.download.DownloadMonitorImpl] (AgentManager-Handler-9:null) Template Sync found routing-3 already in the template host table
2012-09-25 15:59:12,798 INFO  [storage.download.DownloadMonitorImpl] (AgentManager-Handler-9:null) Template Sync did not find centos55-x86_64 on the server 2, will request download shortly
2012-09-25 15:59:12,819 INFO  [storage.download.DownloadMonitorImpl] (AgentManager-Handler-9:null) Template Sync did not find centos56-x86_64-xen on the server 2, will request download shortly
2012-09-25 15:59:12,828 INFO  [storage.download.DownloadMonitorImpl] (AgentManager-Handler-9:null) Template Sync did not find centos53-x64 on the server 2, will request download shortly
2012-09-25 15:59:12,858 DEBUG [storage.download.DownloadMonitorImpl] (AgentManager-Handler-9:null) Template CentOS 5.5(64-bit) no GUI (KVM) needs to be downloaded to nfs://10.102.123.240/cloudstack/abhinav/SS-ubuntu
2012-09-25 15:59:12,869 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998085: Sending  { Cmd , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 100011, [{"storage.DownloadCommand":{"hvm":false,"description":"CentOS 5.5(64-bit) no GUI (KVM)","checksum":"ed0e788280ff2912ea40f7f91ca7a249","maxDownloadSizeInBytes":53687091200,"id":4,"resourceType":"TEMPLATE","url":"http://download.cloud.com/releases/2.2.0/eec2209b-9875-3c8d-92be-c001bd8a0faf.qcow2.bz2","format":"QCOW2","accountId":1,"name":"centos55-x86_64","secUrl":"nfs://10.102.123.240/cloudstack/abhinav/SS-ubuntu","wait":0}}] }
2012-09-25 15:59:12,872 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998086: Sending  { Cmd , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 100111, [{"storage.ListVolumeCommand":{"secUrl":"nfs://10.102.123.240/cloudstack/abhinav/SS-ubuntu","wait":0}}] }
2012-09-25 15:59:12,904 DEBUG [agent.transport.Request] (AgentManager-Handler-1:null) Seq 4-173998086: Processing:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, [{"storage.ListVolumeAnswer":{"secUrl":"nfs://10.102.123.240/cloudstack/abhinav/SS-ubuntu","templateInfos":{},"result":true,"details":"success","wait":0}}] }
2012-09-25 15:59:12,905 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-1:null) Seq 4-173998086: No more commands found
2012-09-25 15:59:12,905 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998086: Received:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, { ListVolumeAnswer } }
2012-09-25 15:59:12,905 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Details from executing class com.cloud.agent.api.storage.ListVolumeCommand: success
2012-09-25 15:59:12,912 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: UploadListener
2012-09-25 15:59:12,913 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: LocalStoragePoolListener$$EnhancerByCGLIB$$a3a4d76d
2012-09-25 15:59:12,913 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: StorageCapacityListener
2012-09-25 15:59:12,913 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: ComputeCapacityListener
2012-09-25 15:59:12,913 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: ConsoleProxyListener
2012-09-25 15:59:12,913 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: SshKeysDistriMonitor
2012-09-25 15:59:12,913 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: VpcVirtualNetworkApplianceManagerImpl$$EnhancerByCGLIB$$ad9d1c61
2012-09-25 15:59:12,914 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) Sending Connect to listener: DirectNetworkStatsListener
2012-09-25 15:59:12,916 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998087: Sending  { Cmd , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 100111, [{"ReadyCommand":{"dcId":1,"wait":0}}] }
2012-09-25 15:59:12,997 DEBUG [agent.transport.Request] (AgentManager-Handler-3:null) Seq 4-173998087: Processing:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, [{"ReadyAnswer":{"result":true,"wait":0}}] }
2012-09-25 15:59:12,998 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-3:null) Seq 4-173998087: No more commands found
2012-09-25 15:59:12,998 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 4-173998087: Received:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 110, { ReadyAnswer } }
2012-09-25 15:59:12,998 DEBUG [cloud.host.Status] (AgentManager-Handler-9:null) Transition:[Resource state = Enabled, Agent event = Ready, Host id = 4, name = s-1-VM]
2012-09-25 15:59:13,011 DEBUG [cloud.host.Status] (AgentManager-Handler-9:null) Agent status update: [id = 4; name = s-1-VM; old status = Connecting; event = Ready; new status = Up; old update count = 1; new update count = 2]
2012-09-25 15:59:18,632 DEBUG [agent.transport.Request] (AgentManager-Handler-5:null) Seq 4-173998085: Processing:  { Ans: , MgmtId: 165676482560269, via: 4, Ver: v1, Flags: 10, [{"storage.DownloadAnswer":{"jobId":"8b863298-6a81-45b3-b1b5-686e21639ede","downloadPct":0,"errorString":" ","downloadStatus":"DOWNLOAD_IN_PROGRESS","downloadPath":"/mnt/SecStorage/d24c72b9-3fe8-34b1-ad54-af523e0cfdb0/template/tmpl/1/4/dnld4739241109688436760tmp_","templateSize":0,"templatePhySicalSize":0,"checkSum":"ed0e788280ff2912ea40f7f91ca7a249","result":false,"details":" ","wait":0}}] }

[Edison] adding host is ok, system vm is started, template is downloading. Did you stop/start cloud-agent manually?
Please let us know if these are expected and if they are then are they going to be documented somewhere.

NOTE : This install was done on a freshly installed KVM host with Ubuntu running on it and a fresh Ubuntu management server.


Thanks and regards,
Abhinav


Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message