Sung Ho Kim created CLOUDSTACK-569:
--------------------------------------
Summary: Host remains in Connecting states after host
restarted(Xenserver 6.0.2)
Key: CLOUDSTACK-569
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-569
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Environment: Xenserver 6.0.2, Apache Cloudstack 4.0.0-incubating
Basic Networking
Reporter: Sung Ho Kim
Priority: Blocker
Attachments: screenshot-1.jpg, screenshot-2.jpg
After host reboot it remains in Connecting states.
In Xencenter it looks ok.
012-11-30 17:34:50,109 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-251:null) Seq 5-247660797: Executing request
2012-11-30 17:34:50,389 DEBUG [xen.resource.XenServerConnectionPool]
(DirectAgent-361:null) XmlRpcException for method: host.call_plugin due to
Failed to create input stream: Read timed out. Reconnecting...retry=1
2012-11-30 17:34:50,389 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-361:null) callHostPlugin failed for cmd: setLinkLocalIP with args
brName: xapi2, due to Failed to create input stream: Read timed out
2012-11-30 17:34:50,389 WARN [agent.manager.DirectAgentAttache]
(DirectAgent-361:null) Seq 1-1342439431: Exception Caught while executing
command
com.cloud.utils.exception.CloudRuntimeException: callHostPlugin failed for cmd:
setLinkLocalIP with args brName: xapi2, due to Failed to create input stream:
Read timed out
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPlugin(CitrixResourceBase.java:3749)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.setupLinkLocalNetwork(CitrixResourceBase.java:4417)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2917)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:433)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
at
com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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)
2012-11-30 17:34:50,390 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-361:null) Seq 1-1342439431: Response Received:
2012-11-30 17:34:50,390 DEBUG [agent.transport.Request] (DirectAgent-361:null)
Seq 1-1342439431: Processing: { Ans: , MgmtId: 27114220232708, via: 1, Ver:
v1, Flags: 110,
[{"Answer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException:
callHostPlugin failed for cmd: setLinkLocalIP with args brName: xapi2, due to
Failed to create input stream: Read timed out","wait":0}}] }
2012-11-30 17:34:50,390 DEBUG [agent.manager.AgentAttache]
(DirectAgent-361:null) Seq 1-1342439431: No more commands found
2012-11-30 17:34:50,390 DEBUG [agent.transport.Request] (AgentTaskPool-8:null)
Seq 1-1342439431: Received: { Ans: , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 110, { Answer } }
2012-11-30 17:34:50,391 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Details from executing class
com.cloud.agent.api.ReadyCommand:
com.cloud.utils.exception.CloudRuntimeException: callHostPlugin failed for cmd:
setLinkLocalIP with args brName: xapi2, due to Failed to create input stream:
Read timed out
2012-11-30 17:34:50,391 INFO [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Host 1 is disconnecting with event AgentDisconnected
2012-11-30 17:34:50,393 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) The next status of agent 1is Alert, current status is
Connecting
2012-11-30 17:34:50,393 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Deregistering link for 1 with state Alert
2012-11-30 17:34:50,393 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Remove Agent : 1
2012-11-30 17:34:50,393 DEBUG [agent.manager.DirectAgentAttache]
(AgentTaskPool-8:null) Processing disconnect 1
2012-11-30 17:34:50,393 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.hypervisor.xen.discoverer.XcpServerDiscoverer$$EnhancerByCGLIB$$1baae760
2012-11-30 17:34:50,393 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.hypervisor.vmware.manager.VmwareManagerImpl$$EnhancerByCGLIB$$4d87e44b
2012-11-30 17:34:50,393 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.vm.ClusteredVirtualMachineManagerImpl$$EnhancerByCGLIB$$18737205
2012-11-30 17:34:50,393 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.network.security.SecurityGroupListener
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.storage.listener.StoragePoolMonitor
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.storage.secondary.SecondaryStorageListener
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.network.NetworkManagerImpl$$EnhancerByCGLIB$$c2335121
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.agent.manager.AgentMonitor$$EnhancerByCGLIB$$32d3d381
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.storage.download.DownloadListener
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.storage.upload.UploadListener
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.storage.LocalStoragePoolListener$$EnhancerByCGLIB$$c2c1f9b5
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.capacity.StorageCapacityListener
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.capacity.ComputeCapacityListener
2012-11-30 17:34:50,394 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.consoleproxy.ConsoleProxyListener
2012-11-30 17:34:50,396 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.network.SshKeysDistriMonitor
2012-11-30 17:34:50,396 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl$$EnhancerByCGLIB$$c52c78a9
2012-11-30 17:34:50,396 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-8:null) Sending Disconnect to listener:
com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener
2012-11-30 17:34:50,396 DEBUG [cloud.network.NetworkUsageManagerImpl]
(AgentTaskPool-8:null) Disconnected called on 1 with status Alert
2012-11-30 17:34:50,396 DEBUG [cloud.host.Status] (AgentTaskPool-8:null)
Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id
= 1, name = xenserver-mercury]
2012-11-30 17:34:50,459 DEBUG [cloud.host.Status] (AgentTaskPool-8:null) Agent
status update: [id = 1; name = xenserver-mercury; old status = Connecting;
event = AgentDisconnected; new status = Alert; old update count = 72; new
update count = 73]
2012-11-30 17:34:50,459 DEBUG [agent.manager.ClusteredAgentManagerImpl]
(AgentTaskPool-8:null) Notifying other nodes of to disconnect
2012-11-30 17:34:50,462 DEBUG [cloud.host.Status] (AgentTaskPool-8:null)
Transition:[Resource state = Enabled, Agent event = Ready, Host id = 1, name =
xenserver-mercury]
2012-11-30 17:34:50,468 DEBUG [cloud.host.Status] (AgentTaskPool-8:null) Unable
to update host for event:Ready. Name=xenserver-mercury;
New=[status=Up:msid=null:lastpinged=1322523028];
Old=[status=Connecting:msid=null:lastpinged=1322523028];
DB=[status=Connecting:msid=27114220232708:lastpinged=1322523323:old update
count=73]
2012-11-30 17:34:50,862 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-251:null) Seq 5-247660797: Response Received:
2012-11-30 17:34:50,863 DEBUG [agent.transport.Request] (StatsCollector-3:null)
Seq 5-247660797: Received: { Ans: , MgmtId: 27114220232708, via: 5, Ver: v1,
Flags: 10, { GetStorageStatsAnswer } }
2012-11-30 17:35:00,361 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2012-11-30 17:35:02,087 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) HostStatsCollector is running...
2012-11-30 17:35:02,099 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-224:null) Seq 5-247660798: Executing request
2012-11-30 17:35:02,311 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-224:null) Seq 5-247660798: Response Received:
2012-11-30 17:35:02,312 DEBUG [agent.transport.Request] (StatsCollector-3:null)
Seq 5-247660798: Received: { Ans: , MgmtId: 27114220232708, via: 5, Ver: v1,
Flags: 10, { GetHostStatsAnswer } }
2012-11-30 17:35:06,165 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2012-11-30 17:35:11,058 DEBUG [agent.manager.ClusteredAgentManagerImpl]
(ClusteredAgentManager Timer:null) Found 1 unmanaged direct hosts, processing
connect for them...
2012-11-30 17:35:11,058 DEBUG [agent.manager.ClusteredAgentManagerImpl]
(ClusteredAgentManager Timer:null) Loading directly connected host
1(xenserver-mercury)
2012-11-30 17:35:11,145 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Simulating start for resource
7a888894-c79a-412a-b454-333b7c443d83 id 1
2012-11-30 17:35:11,372 DEBUG [xen.resource.CitrixResourceBase]
(AgentTaskPool-9:null) Management network is on
pif=507ee037-a330-e2cc-9a6b-129e4c501c56
2012-11-30 17:35:11,402 DEBUG [xen.resource.CitrixResourceBase]
(AgentTaskPool-9:null) Found a network called mgmt on host=192.168.22.100;
Network=204f664d-e6f8-a47b-8358-d7ebce6672dd;
pif=507ee037-a330-e2cc-9a6b-129e4c501c56
2012-11-30 17:35:11,402 INFO [xen.resource.CitrixResourceBase]
(AgentTaskPool-9:null) Private Network is mgmt for host 192.168.22.100
2012-11-30 17:35:11,402 INFO [xen.resource.CitrixResourceBase]
(AgentTaskPool-9:null) Guest Network is mgmt for host 192.168.22.100
2012-11-30 17:35:11,402 INFO [xen.resource.CitrixResourceBase]
(AgentTaskPool-9:null) Public Network is mgmt for host 192.168.22.100
2012-11-30 17:35:11,446 DEBUG [xen.resource.CitrixResourceBase]
(AgentTaskPool-9:null) Total Ram: 64430763264 dom0 Ram: 3084124160
2012-11-30 17:35:13,229 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq -1--1: Startup request from directly connected host: { Cmd , MgmtId: -1,
via: -1, Ver: v1, Flags: 11,
[{"cpus":8,"speed":2400,"memory":64430763264,"dom0MinMemory":3084124160,"poolSync":false,"caps":"xen-3.0-x86_64
, xen-3.0-x86_32p , hvm-3.0-x86_32 , hvm-3.0-x86_32p ,
hvm-3.0-x86_64","pool":"fb9b37b3-b336-87b6-0dac-89b88b996d83","hypervisorType":"XenServer","hostDetails":{"product_version":"6.0.2","private.network.device":"mgmt","com.cloud.network.Networks.RouterPrivateIpStrategy":"DcGlobal","product_brand":"XenServer","product_version_text_short":"6.0.2","can_bridge_firewall":"false"},"hypervisorVersion":"6.0.2","type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"7a888894-c79a-412a-b454-333b7c443d83","name":"xenserver-mercury","version":"4.0.0.20121024012150","iqn":"iqn.2005-03.org.open-iscsi:fa1c355fa1d","publicIpAddress":"192.168.22.100","publicNetmask":"255.255.254.0","publicMacAddress":"e0:db:55:07:eb:37","privateIpAddress":"192.168.22.100","privateMacAddress":"e0:db:55:07:eb:37","privateNetmask":"255.255.254.0","storageIpAddress":"192.168.22.100","storageNetmask":"255.255.254.0","storageMacAddress":"e0:db:55:07:eb:37","wait":0},{"totalSize":0,"poolInfo":{"uuid":"18dfc1f2-ff0c-449a-34f8-098d0475501e","host":"192.168.22.100","localPath":"lvm","hostPath":"lvm","poolType":"LVM","capacityBytes":137510256640,"availableBytes":137506062336},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","guid":"7a888894-c79a-412a-b454-333b7c443d83","wait":0}]
}
2012-11-30 17:35:13,235 DEBUG [cloud.resource.ResourceManagerImpl]
(AgentTaskPool-9:null) Dispatching resource state event
CREATE_HOST_VO_FOR_DIRECT_CONNECT to NetscalerElement$$EnhancerByCGLIB$$a66a29ab
2012-11-30 17:35:13,235 DEBUG [cloud.resource.ResourceManagerImpl]
(AgentTaskPool-9:null) Dispatching resource state event
CREATE_HOST_VO_FOR_DIRECT_CONNECT to
PxeServerManagerImpl$$EnhancerByCGLIB$$2b8d2ea8
2012-11-30 17:35:13,235 DEBUG [cloud.resource.ResourceManagerImpl]
(AgentTaskPool-9:null) Dispatching resource state event
CREATE_HOST_VO_FOR_DIRECT_CONNECT to
JuniperSRXExternalFirewallElement$$EnhancerByCGLIB$$eb1ee513
2012-11-30 17:35:13,235 DEBUG [cloud.resource.ResourceManagerImpl]
(AgentTaskPool-9:null) Dispatching resource state event
CREATE_HOST_VO_FOR_DIRECT_CONNECT to
NetworkUsageManagerImpl$$EnhancerByCGLIB$$375b6270
2012-11-30 17:35:13,236 DEBUG [cloud.resource.ResourceManagerImpl]
(AgentTaskPool-9:null) Dispatching resource state event
CREATE_HOST_VO_FOR_DIRECT_CONNECT to
XcpServerDiscoverer$$EnhancerByCGLIB$$1baae760
2012-11-30 17:35:13,236 INFO [xen.discoverer.XcpServerDiscoverer]
(AgentTaskPool-9:null) Host: xenserver-mercury connected with hypervisor type:
XenServer. Checking CIDR...
2012-11-30 17:35:13,357 DEBUG [cloud.resource.ResourceState]
(AgentTaskPool-9:null) Resource state update: [id = 1; name =
xenserver-mercury; old state = Enabled; event = InternalCreated; new state =
Enabled]
2012-11-30 17:35:13,357 DEBUG [cloud.host.Status] (AgentTaskPool-9:null)
Transition:[Resource state = Enabled, Agent event = AgentConnected, Host id =
1, name = xenserver-mercury]
2012-11-30 17:35:13,422 DEBUG [cloud.host.Status] (AgentTaskPool-9:null) Agent
status update: [id = 1; name = xenserver-mercury; old status = Alert; event =
AgentConnected; new status = Connecting; old update count = 73; new update
count = 74]
2012-11-30 17:35:13,422 DEBUG [agent.manager.ClusteredAgentManagerImpl]
(AgentTaskPool-9:null) create ClusteredDirectAgentAttache for 1
2012-11-30 17:35:13,422 INFO [agent.manager.DirectAgentAttache]
(AgentTaskPool-9:null) StartupAnswer received 1 Interval = 60
2012-11-30 17:35:13,424 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener:
XcpServerDiscoverer$$EnhancerByCGLIB$$1baae760
2012-11-30 17:35:13,428 DEBUG [xen.discoverer.XcpServerDiscoverer]
(AgentTaskPool-9:null) Setting up host 1
2012-11-30 17:35:13,430 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572481: Sending { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100111,
[{"SetupCommand":{"env":{},"multipath":false,"needSetup":false,"wait":0}}] }
2012-11-30 17:35:13,430 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572481: Executing: { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100111,
[{"SetupCommand":{"env":{},"multipath":false,"needSetup":false,"wait":0}}] }
2012-11-30 17:35:13,437 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-35:null) Seq 1-855572481: Executing request
2012-11-30 17:35:13,671 INFO [xen.resource.CitrixResourceBase]
(DirectAgent-35:null) Host 192.168.22.100
OpaqueRef:fbf8d32c-c065-342e-ea3c-14852b4fa2b1: Host 192.168.22.100 is already
setup.
2012-11-30 17:35:18,374 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-35:null) Seq 1-855572481: Response Received:
2012-11-30 17:35:18,375 DEBUG [agent.transport.Request] (DirectAgent-35:null)
Seq 1-855572481: Processing: { Ans: , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 110, [{"SetupAnswer":{"_reconnect":false,"result":true,"wait":0}}] }
2012-11-30 17:35:18,375 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572481: Received: { Ans: , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 110, { SetupAnswer } }
2012-11-30 17:35:18,376 DEBUG [agent.manager.AgentAttache]
(DirectAgent-35:null) Seq 1-855572481: No more commands found
2012-11-30 17:35:18,443 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener:
VmwareManagerImpl$$EnhancerByCGLIB$$4d87e44b
2012-11-30 17:35:18,443 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener:
ClusteredVirtualMachineManagerImpl$$EnhancerByCGLIB$$18737205
2012-11-30 17:35:18,446 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572482: Sending { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100011,
[{"ClusterSyncCommand":{"_interval":60,"_clusterId":1,"wait":0}}] }
2012-11-30 17:35:18,446 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572482: Executing: { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100011,
[{"ClusterSyncCommand":{"_interval":60,"_clusterId":1,"wait":0}}] }
2012-11-30 17:35:18,446 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(AgentTaskPool-9:null) Cluster VM sync started with jobid 855572482
2012-11-30 17:35:18,446 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: SecurityGroupListener
2012-11-30 17:35:18,446 INFO [network.security.SecurityGroupListener]
(AgentTaskPool-9:null) Received a host startup notification
2012-11-30 17:35:18,449 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572483: Sending { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100011, [{"CleanupNetworkRulesCmd":{"interval":2520,"wait":0}}] }
2012-11-30 17:35:18,449 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572483: Executing: { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100011, [{"CleanupNetworkRulesCmd":{"interval":2520,"wait":0}}] }
2012-11-30 17:35:18,449 INFO [network.security.SecurityGroupListener]
(AgentTaskPool-9:null) Scheduled network rules cleanup, interval=2520
2012-11-30 17:35:18,449 INFO [network.security.SecurityGroupListener]
(AgentTaskPool-9:null) Received a host startup notification
2012-11-30 17:35:18,449 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: StoragePoolMonitor
2012-11-30 17:35:18,452 DEBUG [storage.listener.StoragePoolMonitor]
(AgentTaskPool-9:null) Host 1 connected, sending down storage pool information
...
2012-11-30 17:35:18,452 DEBUG [cloud.storage.StorageManagerImpl]
(AgentTaskPool-9:null) Adding pool Galaxy-PSS to host 1
2012-11-30 17:35:18,457 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572484: Sending { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100011,
[{"ModifyStoragePoolCommand":{"add":true,"pool":{"id":200,"uuid":"198d8c53-024a-3628-8a8d-bc7c9e13e5a4","host":"10.0.0.2","path":"/cloud/primary","port":2049,"type":"NetworkFilesystem"},"localPath":"/mnt//198d8c53-024a-3628-8a8d-bc7c9e13e5a4","wait":0}}]
}
2012-11-30 17:35:18,457 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572484: Executing: { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100011,
[{"ModifyStoragePoolCommand":{"add":true,"pool":{"id":200,"uuid":"198d8c53-024a-3628-8a8d-bc7c9e13e5a4","host":"10.0.0.2","path":"/cloud/primary","port":2049,"type":"NetworkFilesystem"},"localPath":"/mnt//198d8c53-024a-3628-8a8d-bc7c9e13e5a4","wait":0}}]
}
2012-11-30 17:35:18,457 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-445:null) Seq 1-855572484: Executing request
2012-11-30 17:35:18,608 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-445:null) SR retrieved for 200
2012-11-30 17:35:18,621 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-445:null) Checking 198d8c53-024a-3628-8a8d-bc7c9e13e5a4 or SR
78987364-2aed-89bb-d1a7-c34cf909b315 on
XS[7a888894-c79a-412a-b454-333b7c443d83-192.168.22.100]
2012-11-30 17:35:19,039 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-445:null) Seq 1-855572484: Response Received:
2012-11-30 17:35:19,039 DEBUG [agent.transport.Request] (DirectAgent-445:null)
Seq 1-855572484: Processing: { Ans: , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 10,
[{"ModifyStoragePoolAnswer":{"poolInfo":{"host":"10.0.0.2","localPath":"/mnt//198d8c53-024a-3628-8a8d-bc7c9e13e5a4","hostPath":"/cloud/primary","poolType":"NetworkFilesystem","capacityBytes":9996400066560,"availableBytes":9790674436096},"templateInfo":{},"result":true,"wait":0}}]
}
2012-11-30 17:35:19,039 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572484: Received: { Ans: , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 10, { ModifyStoragePoolAnswer } }
2012-11-30 17:35:19,100 INFO [cloud.storage.StorageManagerImpl]
(AgentTaskPool-9:null) Connection established between
Pool[200|NetworkFilesystem] host + 1
2012-11-30 17:35:19,103 DEBUG [cloud.storage.StorageManagerImpl]
(AgentTaskPool-9:null) Successfully set Capacity - 19992800133120 for capacity
type - 3 , DataCenterId - 1, HostOrPoolId - 200, PodId 1
2012-11-30 17:35:19,103 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: SecondaryStorageListener
2012-11-30 17:35:19,103 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener:
NetworkManagerImpl$$EnhancerByCGLIB$$c2335121
2012-11-30 17:35:19,105 DEBUG [cloud.network.NetworkManagerImpl]
(AgentTaskPool-9:null) Host's hypervisorType is: XenServer
2012-11-30 17:35:19,114 DEBUG [cloud.network.NetworkManagerImpl]
(AgentTaskPool-9:null) Sending CheckNetworkCommand to check the Network is
setup correctly on Agent
2012-11-30 17:35:19,117 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572485: Sending { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100111,
[{"CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":1,"privateNetworkName":"mgmt","guestNetworkName":"guest","storageNetworkName":"mgmt"}],"wait":0}}]
}
2012-11-30 17:35:19,117 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572485: Executing: { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100111,
[{"CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":1,"privateNetworkName":"mgmt","guestNetworkName":"guest","storageNetworkName":"mgmt"}],"wait":0}}]
}
2012-11-30 17:35:19,118 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-105:null) Seq 1-855572485: Executing request
2012-11-30 17:35:19,118 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-105:null) Checking if network name setup is done on the resource
2012-11-30 17:35:19,118 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-105:null) Looking for network setup by name guest
2012-11-30 17:35:19,245 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-105:null) Found more than one network with the name guest
2012-11-30 17:35:19,287 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-105:null) Found a network called guest on host=192.168.22.100;
Network=2e8c202b-64ee-75fa-dd49-31818fd960b7;
pif=d98b02ff-f841-6696-6301-377a37f00a46
2012-11-30 17:35:19,287 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-105:null) Looking for network setup by name mgmt
2012-11-30 17:35:19,413 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-105:null) Seq 1-855572485: Response Received:
2012-11-30 17:35:19,413 DEBUG [agent.transport.Request] (DirectAgent-105:null)
Seq 1-855572485: Processing: { Ans: , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 110,
[{"CheckNetworkAnswer":{"_reconnect":false,"result":true,"details":"Network
Setup check by names is done","wait":0}}] }
2012-11-30 17:35:19,413 DEBUG [agent.manager.AgentAttache]
(DirectAgent-105:null) Seq 1-855572485: No more commands found
2012-11-30 17:35:19,413 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572485: Received: { Ans: , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 110, { CheckNetworkAnswer } }
2012-11-30 17:35:19,413 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Details from executing class
com.cloud.agent.api.CheckNetworkCommand: Network Setup check by names is done
2012-11-30 17:35:19,413 DEBUG [cloud.network.NetworkManagerImpl]
(AgentTaskPool-9:null) Network setup is correct on Agent
2012-11-30 17:35:19,413 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener:
AgentMonitor$$EnhancerByCGLIB$$32d3d381
2012-11-30 17:35:19,414 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: DownloadListener
2012-11-30 17:35:19,416 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: UploadListener
2012-11-30 17:35:19,416 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener:
LocalStoragePoolListener$$EnhancerByCGLIB$$c2c1f9b5
2012-11-30 17:35:19,416 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: StorageCapacityListener
2012-11-30 17:35:19,416 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: ComputeCapacityListener
2012-11-30 17:35:19,422 DEBUG [cloud.capacity.CapacityManagerImpl]
(AgentTaskPool-9:null) Found 0 VMs on host 1
2012-11-30 17:35:19,425 DEBUG [cloud.capacity.CapacityManagerImpl]
(AgentTaskPool-9:null) Found 1 VM, not running on host 1
2012-11-30 17:35:19,427 DEBUG [cloud.capacity.CapacityManagerImpl]
(AgentTaskPool-9:null) No need to calibrate cpu capacity, host:1 usedCpu: 0
reservedCpu: 0
2012-11-30 17:35:19,428 DEBUG [cloud.capacity.CapacityManagerImpl]
(AgentTaskPool-9:null) No need to calibrate memory capacity, host:1 usedMem: 0
reservedMem: 0
2012-11-30 17:35:19,428 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: ConsoleProxyListener
2012-11-30 17:35:19,428 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: SshKeysDistriMonitor
2012-11-30 17:35:19,432 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572486: Sending { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100011, [{"ModifySshKeysCommand":{"wait":0}}] }
2012-11-30 17:35:19,432 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572486: Executing: { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100011, [{"ModifySshKeysCommand":{"wait":0}}] }
2012-11-30 17:35:19,433 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener:
VpcVirtualNetworkApplianceManagerImpl$$EnhancerByCGLIB$$c52c78a9
2012-11-30 17:35:19,433 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-444:null) Seq 1-855572486: Executing request
2012-11-30 17:35:19,433 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-444:null) Seq 1-855572486: Response Received:
2012-11-30 17:35:19,433 DEBUG [agent.transport.Request] (DirectAgent-444:null)
Seq 1-855572486: Processing: { Ans: , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 10, [{"Answer":{"result":true,"wait":0}}] }
2012-11-30 17:35:19,435 DEBUG [agent.manager.AgentManagerImpl]
(AgentTaskPool-9:null) Sending Connect to listener: DirectNetworkStatsListener
2012-11-30 17:35:19,438 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572487: Sending { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100111, [{"ReadyCommand":{"dcId":1,"wait":0}}] }
2012-11-30 17:35:19,438 DEBUG [agent.transport.Request] (AgentTaskPool-9:null)
Seq 1-855572487: Executing: { Cmd , MgmtId: 27114220232708, via: 1, Ver: v1,
Flags: 100111, [{"ReadyCommand":{"dcId":1,"wait":0}}] }
2012-11-30 17:35:19,441 DEBUG [cloud.server.StatsCollector]
(StatsCollector-2:null) VmStatsCollector is running...
2012-11-30 17:35:19,463 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-328:null) Seq 1-855572487: Executing request
2012-11-30 17:35:19,498 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-148:null) Seq 5-247660799: Executing request
2012-11-30 17:35:19,838 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-328:null) already have a vif on dom0 for link local network
2012-11-30 17:35:19,937 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.35000000000000003
2012-11-30 17:35:19,937 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.16
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.13
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.8
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.36
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 2.1350000000000002
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 1.76
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.2
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.12
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.26999999999999996
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.38
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.8175
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.74
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.16
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.12
2012-11-30 17:35:19,938 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-148:null) Vm cpu utilization 0.12000000000000001
2012-11-30 17:35:19,938 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-148:null) Seq 5-247660799: Response Received:
2012-11-30 17:35:19,938 DEBUG [agent.transport.Request] (StatsCollector-2:null)
Seq 5-247660799: Received: { Ans: , MgmtId: 27114220232708, via: 5, Ver: v1,
Flags: 10, { GetVmStatsAnswer } }
2012-11-30 17:35:30,361 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2012-11-30 17:35:36,166 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2012-11-30 17:35:37,708 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-12:null) Ping from 3
2012-11-30 17:35:37,825 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-13:null) Ping from 8
2012-11-30 17:35:44,565 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-151:null) Ping from 5
2012-11-30 17:35:46,285 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-182:null) Seq 5-247660546: Executing request
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
