You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users-cn@cloudstack.apache.org by 崔佳 <cu...@gmail.com> on 2015/04/15 10:30:52 UTC
关于虚拟路由器的问题
我的虚拟路由器重启过一次,并更改了下系统方案,我自定义的
现在的问题是自从重启后,我无法新添加实例了~~添加就报如下错误
---------------------------------------------------------------------------------------------------------
2015-04-15 15:12:53,502 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-4:null) SeqA 2-4128765: Processing Seq 2-4128765: {
Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-04-15 15:12:53,506 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-4:null) SeqA 2-4128765: Sending Seq 2-4128765: {
Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-04-15 15:12:56,430 DEBUG [cloud.api.ApiServlet]
(catalina-exec-17:null) ===START=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081975080
2015-04-15 15:12:56,454 DEBUG [cloud.api.ApiServlet]
(catalina-exec-17:null) ===END=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081975080
2015-04-15 15:12:59,432 DEBUG [cloud.api.ApiServlet]
(catalina-exec-16:null) ===START=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081978082
2015-04-15 15:12:59,456 DEBUG [cloud.api.ApiServlet]
(catalina-exec-16:null) ===END=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081978082
2015-04-15 15:13:02,433 DEBUG [cloud.api.ApiServlet]
(catalina-exec-18:null) ===START=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081981083
2015-04-15 15:13:02,458 DEBUG [cloud.api.ApiServlet]
(catalina-exec-18:null) ===END=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081981083
2015-04-15 15:13:02,632 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-440:null) Seq 1-1234763896: Response Received:
2015-04-15 15:13:02,632 DEBUG [agent.transport.Request]
(DirectAgent-440:null) Seq 1-1234763896: Processing: { Ans: , MgmtId:
264018885718825, via: 1, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.Answer":{"result":false,"details":"DhcpEntry
failed","wait":0}}] }
2015-04-15 15:13:02,633 DEBUG [agent.manager.AgentAttache]
(DirectAgent-440:null) Seq 1-1234763896: No more commands found
2015-04-15 15:13:02,633 DEBUG [agent.transport.Request]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
1-1234763896: Received: { Ans: , MgmtId: 264018885718825, via: 1, Ver: v1,
Flags: 110, { Answer } }
2015-04-15 15:13:02,633 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Unable
to contact resource.
com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:1]
is unreachable: Unable to apply dhcp entry on router
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3808)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyDhcpEntry(VirtualNetworkApplianceManagerImpl.java:2919)
at
com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:898)
at
com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2070)
at
com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2191)
at
com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2127)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:887)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2015-04-15 15:13:02,636 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
Cleaning up resources for the vm VM[User|pipGame001] in Starting state
2015-04-15 15:13:02,639 DEBUG [agent.transport.Request]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
4-554565737: Sending { Cmd , MgmtId: 264018885718825, via: 4, Ver: v1,
Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-162-VM","wait":0}}]
}
2015-04-15 15:13:02,639 DEBUG [agent.transport.Request]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
4-554565737: Executing: { Cmd , MgmtId: 264018885718825, via: 4, Ver: v1,
Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-162-VM","wait":0}}]
}
2015-04-15 15:13:02,640 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-441:null) Seq 4-554565737: Executing request
2015-04-15 15:13:02,715 INFO [xen.resource.CitrixResourceBase]
(DirectAgent-441:null) VM does not exist on
XenServere0e8ebf2-a5b4-4176-8ff5-2e29d9f289aa
2015-04-15 15:13:02,715 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-441:null) Seq 4-554565737: Response Received:
2015-04-15 15:13:02,715 DEBUG [agent.transport.Request]
(DirectAgent-441:null) Seq 4-554565737: Processing: { Ans: , MgmtId:
264018885718825, via: 4, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM
does not exist","wait":0}}] }
2015-04-15 15:13:02,716 DEBUG [agent.manager.AgentAttache]
(DirectAgent-441:null) Seq 4-554565737: No more commands found
2015-04-15 15:13:02,716 DEBUG [agent.transport.Request]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
4-554565737: Received: { Ans: , MgmtId: 264018885718825, via: 4, Ver: v1,
Flags: 110, { StopAnswer } }
2015-04-15 15:13:02,729 DEBUG [cloud.network.NetworkModelImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Service
SecurityGroup is not supported in the network id=204
2015-04-15 15:13:02,735 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
Changing active number of nics for network id=204 on -1
2015-04-15 15:13:02,743 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Asking
VirtualRouter to release
Nic[178-162-59f93f8f-d782-438d-ae31-683c3887e5b8-10.10.30.29]
2015-04-15 15:13:02,743 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
Successfully released network resources for the vm VM[User|pipGame001]
2015-04-15 15:13:02,743 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
Successfully cleanued up resources for the vm VM[User|pipGame001] in
Starting state
2015-04-15 15:13:02,758 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Deploy
avoids pods: [], clusters: [], hosts: [4]
2015-04-15 15:13:02,758 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot
allocate the VM, returning.
2015-04-15 15:13:02,766 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
state transitted from :Starting to Stopped with event: OperationFailedvm's
original host id: null new host id: null host id before state transition: 4
2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Hosts's
actual total CPU: 52800 and CPU after applying overprovisioning: 52800
2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Hosts's
actual total RAM: 198546824448 and RAM after applying overprovisioning:
198546817024
2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) release
cpu from host: 4, old used: 50500,reserved: 0, actual total: 52800, total
with overprovisioning: 52800; new used: 46500,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) release
mem from host: 4, old used: 152974655488,reserved: 0, total: 198546817024;
new used: 144586047488,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2015-04-15 15:13:02,795 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
state transitted from :Stopped to Starting with event: StartRequestedvm's
original host id: null new host id: null host id before state transition:
null
2015-04-15 15:13:02,795 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
Successfully transitioned to start state for VM[User|pipGame001]
reservation id = 3d92c258-9747-46ae-98b3-d14f8c52b24b
2015-04-15 15:13:02,798 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Trying
to deploy VM, vm has dcId: 1 and podId: 1
2015-04-15 15:13:02,798 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Deploy
avoids pods: [], clusters: [], hosts: [4]
2015-04-15 15:13:02,813 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Deploy
avoids pods: [], clusters: [], hosts: [4]
2015-04-15 15:13:02,813 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot
allocate the VM, returning.
2015-04-15 15:13:02,821 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
state transitted from :Starting to Stopped with event: OperationFailedvm's
original host id: null new host id: null host id before state transition:
null
2015-04-15 15:13:02,836 DEBUG [cloud.vm.UserVmManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
Destroying vm VM[User|pipGame001] as it failed to create on Host with
Id:null
2015-04-15 15:13:02,845 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
state transitted from :Stopped to Error with event:
OperationFailedToErrorvm's original host id: null new host id: null host id
before state transition: null
2015-04-15 15:13:02,854 WARN [apache.cloudstack.alerts]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null //
message:: Failed to deploy Vm with Id: 162, on Host with Id: null
2015-04-15 15:13:03,503 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-5:null) SeqA 2-4128766: Processing Seq 2-4128766: {
Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-04-15 15:13:03,506 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-5:null) SeqA 2-4128766: Sending Seq 2-4128766: {
Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-04-15 15:13:04,586 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) HostStatsCollector is running...
2015-04-15 15:13:04,601 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-234:null) Seq 1-1234763897: Executing request
2015-04-15 15:13:04,843 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-234:null) Seq 1-1234763897: Response Received:
2015-04-15 15:13:04,844 DEBUG [agent.transport.Request]
(StatsCollector-1:null) Seq 1-1234763897: Received: { Ans: , MgmtId:
264018885718825, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2015-04-15 15:13:04,854 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-443:null) Seq 4-554565738: Executing request
2015-04-15 15:13:05,089 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-443:null) Seq 4-554565738: Response Received:
2015-04-15 15:13:05,089 DEBUG [agent.transport.Request]
(StatsCollector-1:null) Seq 4-554565738: Received: { Ans: , MgmtId:
264018885718825, via: 4, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2015-04-15 15:13:05,099 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-444:null) Seq 10-1866137706: Executing request
2015-04-15 15:13:05,332 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-444:null) Seq 10-1866137706: Response Received:
2015-04-15 15:13:05,332 DEBUG [agent.transport.Request]
(StatsCollector-1:null) Seq 10-1866137706: Received: { Ans: , MgmtId:
264018885718825, via: 10, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2015-04-15 15:13:05,342 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-445:null) Seq 11-1040711788: Executing request
2015-04-15 15:13:05,434 DEBUG [cloud.api.ApiServlet]
(catalina-exec-21:null) ===START=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081984085
2015-04-15 15:13:05,460 DEBUG [cloud.api.ApiServlet]
(catalina-exec-21:null) ===END=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081984085
2015-04-15 15:13:05,502 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-445:null) Seq 11-1040711788: Response Received:
2015-04-15 15:13:05,503 DEBUG [agent.transport.Request]
(StatsCollector-1:null) Seq 11-1040711788: Received: { Ans: , MgmtId:
264018885718825, via: 11, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
^C2015-04-15 15:13:07,855 DEBUG [cloud.api.ApiServlet]
(catalina-exec-15:null) ===START=== 114.251.179.130 -- GET
command=listServiceOfferings&response=json&sessionkey=n%2FBH%2BAXCkHPZx8RI5Eo%2BVxyikIE%3D&issystem=false&id=134ee9f2-e9e0-4676-9ecd-b51d65b60766&_=1429081997475
2015-04-15 15:13:07,875 DEBUG [cloud.api.ApiServlet]
(catalina-exec-15:null) ===END=== 114.251.179.130 -- GET
command=listServiceOfferings&response=json&sessionkey=n%2FBH%2BAXCkHPZx8RI5Eo%2BVxyikIE%3D&issystem=false&id=134ee9f2-e9e0-4676-9ecd-b51d65b60766&_=1429081997475
2015-04-15 15:13:07,982 ERROR [cloud.alert.AlertManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Problem
sending email alert
javax.mail.MessagingException: Exception reading response
(javax.net.ssl.SSLException: Unrecognized SSL message, plaintext
connection?)
at
com.sun.mail.smtp.SMTPTransport.readServerResponse(SMTPTransport.java:1462)
at com.sun.mail.smtp.SMTPTransport.openServer(SMTPTransport.java:1260)
at com.sun.mail.smtp.SMTPTransport.protocolConnect(SMTPTransport.java:370)
at javax.mail.Service.connect(Service.java:251)
at javax.mail.Service.connect(Service.java:91)
at javax.mail.Service.connect(Service.java:76)
at
com.cloud.alert.AlertManagerImpl$EmailAlert.sendAlert(AlertManagerImpl.java:872)
at com.cloud.alert.AlertManagerImpl.sendAlert(AlertManagerImpl.java:261)
at
com.cloud.vm.UserVmManagerImpl.updateVmStateForFailedVmCreation(UserVmManagerImpl.java:1732)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2969)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: javax.net.ssl.SSLException: Unrecognized SSL message, plaintext
connection?
at
com.sun.net.ssl.internal.ssl.InputRecord.handleUnknownRecord(InputRecord.java:523)
at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:355)
at
com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:798)
at
com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1138)
at
com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:753)
at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
at com.sun.mail.util.TraceInputStream.read(TraceInputStream.java:97)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
at com.sun.mail.util.LineInputStream.readLine(LineInputStream.java:75)
at
com.sun.mail.smtp.SMTPTransport.readServerResponse(SMTPTransport.java:1440)
... 24 more
2015-04-15 15:13:08,009 INFO [user.vm.DeployVMCmd] (Job-Executor-5:job-862
= [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|pipGame001]Scope=interface com.cloud.dc.DataCenter;
id=1
2015-04-15 15:13:08,009 INFO [user.vm.DeployVMCmd] (Job-Executor-5:job-862
= [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Unable to create a deployment
for VM[User|pipGame001]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|pipGame001]Scope=interface com.cloud.dc.DataCenter;
id=1
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2015-04-15 15:13:08,011 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
Complete async job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ],
jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable
to create a deployment for VM[User|pipGame001]
2015-04-15 15:13:08,435 DEBUG [cloud.api.ApiServlet]
(catalina-exec-24:null) ===START=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987085
2015-04-15 15:13:08,452 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-24:null) Async job-862 = [
83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ] completed
2015-04-15 15:13:08,458 DEBUG [cloud.api.ApiServlet]
(catalina-exec-24:null) ===END=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987085
2015-04-15 15:13:08,514 DEBUG [cloud.api.ApiServlet]
(catalina-exec-19:null) ===START=== 114.251.179.130 -- GET
command=listVirtualMachines&id=62b63a2d-70d3-4b83-a83f-9682e565f8d2&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987162
2015-04-15 15:13:08,542 DEBUG [cloud.api.ApiServlet]
(catalina-exec-19:null) ===END=== 114.251.179.130 -- GET
command=listVirtualMachines&id=62b63a2d-70d3-4b83-a83f-9682e565f8d2&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987162
2015-04-15 15:13:13,504 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-6:null) SeqA 2-4128767: Processing Seq 2-4128767: {
Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-04-15 15:13:13,508 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-6:null) SeqA 2-4128767: Sending Seq 2-4128767: {
Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-04-15 15:13:15,389 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is ready to launch secondary storage VM
2015-04-15 15:13:15,587 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is ready to launch console proxy
^C
[root@pip_manager ~]# tail -f
/var/log/cloudstack/management/management-server.log
2015-04-15 15:15:13,904 DEBUG [agent.transport.Request]
(Job-Executor-7:job-864 = [ 72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66 ]) Seq
1-1234763906: Executing: { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1,
Flags: 100111,
[{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:00:06:47:00:9c","vmIpAddress":"10.10.30.246","vmName":"over1","defaultRouter":"10.10.30.1","defaultDns":"10.10.30.1","duid":"00:03:00:01:02:00:06:47:00:9c","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","
router.name":"r-109-VM","router.ip":"169.254.2.10"},"wait":0}}] }
2015-04-15 15:15:13,905 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-346:null) Seq 1-1234763906: Executing request
2015-04-15 15:15:15,392 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is ready to launch secondary storage VM
2015-04-15 15:15:15,587 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is ready to launch console proxy
2015-04-15 15:15:16,288 DEBUG [cloud.api.ApiServlet]
(catalina-exec-18:null) ===START=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429082114936
2015-04-15 15:15:16,312 DEBUG [cloud.api.ApiServlet]
(catalina-exec-18:null) ===END=== 114.251.179.130 -- GET
command=queryAsyncJobResult&jobId=72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429082114936
2015-04-15 15:15:17,494 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 1 routers to update status.
2015-04-15 15:15:17,496 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2015-04-15 15:15:17,528 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 1 routers to update status.
2015-04-15 15:15:17,530 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
----------------------------------------------------------------------------------------------------------
Re: 关于虚拟路由器的问题
Posted by 崔佳 <cu...@gmail.com>.
多谢Darren Tang 问题已解决
是路由器下的dhcp服务没启动
登进去启动就好了
2015-04-15 16:42 GMT+08:00 崔佳 <cu...@gmail.com>:
> 日志我转存到其他磁盘上了~ 但我迁移了之后,日志都不输出了 从df 命令上来看的话 磁盘空间还有
> 日志一直不输出了...............
>
> 2015-04-15 16:38 GMT+08:00 Darren Tang <da...@gmail.com>:
>
>> 应该是虚拟路由器空间满了。
>> 通过console登录到虚拟路由器看看/var下面的空间是否满了，清理下就行了。
>>
>>
>> 2015-04-15 16:30 GMT+08:00 崔佳 <cu...@gmail.com>:
>>
>> > 我的虚拟路由器重启过一次,并更改了下系统方案,我自定义的
>> >
>> > 现在的问题是自从重启后,我无法新添加实例了~~添加就报如下错误
>> >
>> >
>> >
>> ---------------------------------------------------------------------------------------------------------
>> > 2015-04-15 15:12:53,502 DEBUG [agent.manager.AgentManagerImpl]
>> > (AgentManager-Handler-4:null) SeqA 2-4128765: Processing Seq
>> 2-4128765: {
>> > Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
>> >
>> >
>> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
>> > \"connections\": []\n}","wait":0}}] }
>> > 2015-04-15 15:12:53,506 DEBUG [agent.manager.AgentManagerImpl]
>> > (AgentManager-Handler-4:null) SeqA 2-4128765: Sending Seq 2-4128765: {
>> > Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
>> > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>> > 2015-04-15 15:12:56,430 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-17:null) ===START=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081975080
>> > 2015-04-15 15:12:56,454 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-17:null) ===END=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081975080
>> > 2015-04-15 15:12:59,432 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-16:null) ===START=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081978082
>> > 2015-04-15 15:12:59,456 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-16:null) ===END=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081978082
>> > 2015-04-15 15:13:02,433 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-18:null) ===START=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081981083
>> > 2015-04-15 15:13:02,458 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-18:null) ===END=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081981083
>> > 2015-04-15 15:13:02,632 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-440:null) Seq 1-1234763896: Response Received:
>> > 2015-04-15 15:13:02,632 DEBUG [agent.transport.Request]
>> > (DirectAgent-440:null) Seq 1-1234763896: Processing: { Ans: , MgmtId:
>> > 264018885718825, via: 1, Ver: v1, Flags: 110,
>> > [{"com.cloud.agent.api.Answer":{"result":false,"details":"DhcpEntry
>> > failed","wait":0}}] }
>> > 2015-04-15 15:13:02,633 DEBUG [agent.manager.AgentAttache]
>> > (DirectAgent-440:null) Seq 1-1234763896: No more commands found
>> > 2015-04-15 15:13:02,633 DEBUG [agent.transport.Request]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
>> > 1-1234763896: Received: { Ans: , MgmtId: 264018885718825, via: 1, Ver:
>> v1,
>> > Flags: 110, { Answer } }
>> > 2015-04-15 15:13:02,633 INFO [cloud.vm.VirtualMachineManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Unable
>> > to contact resource.
>> > com.cloud.exception.ResourceUnavailableException: Resource
>> [DataCenter:1]
>> > is unreachable: Unable to apply dhcp entry on router
>> > at
>> >
>> >
>> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3808)
>> > at
>> >
>> >
>> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyDhcpEntry(VirtualNetworkApplianceManagerImpl.java:2919)
>> > at
>> >
>> >
>> com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:898)
>> > at
>> >
>> >
>> com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2070)
>> > at
>> >
>> >
>> com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2191)
>> > at
>> >
>> com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2127)
>> > at
>> >
>> >
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:887)
>> > at
>> >
>> >
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
>> > at
>> >
>> >
>> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
>> > at
>> >
>> >
>> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
>> > at
>> >
>> >
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
>> > at
>> >
>> >
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
>> > at
>> >
>> >
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
>> > at
>> >
>> >
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>> > at
>> >
>> >
>> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
>> > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>> > at
>> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>> > at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>> > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>> > at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>> > at
>> >
>> >
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>> > at
>> >
>> >
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>> > at java.lang.Thread.run(Thread.java:662)
>> > 2015-04-15 15:13:02,636 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > Cleaning up resources for the vm VM[User|pipGame001] in Starting state
>> > 2015-04-15 15:13:02,639 DEBUG [agent.transport.Request]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
>> > 4-554565737: Sending { Cmd , MgmtId: 264018885718825, via: 4, Ver: v1,
>> > Flags: 100111,
>> >
>> >
>> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-162-VM","wait":0}}]
>> > }
>> > 2015-04-15 15:13:02,639 DEBUG [agent.transport.Request]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
>> > 4-554565737: Executing: { Cmd , MgmtId: 264018885718825, via: 4, Ver:
>> v1,
>> > Flags: 100111,
>> >
>> >
>> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-162-VM","wait":0}}]
>> > }
>> > 2015-04-15 15:13:02,640 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-441:null) Seq 4-554565737: Executing request
>> > 2015-04-15 15:13:02,715 INFO [xen.resource.CitrixResourceBase]
>> > (DirectAgent-441:null) VM does not exist on
>> > XenServere0e8ebf2-a5b4-4176-8ff5-2e29d9f289aa
>> > 2015-04-15 15:13:02,715 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-441:null) Seq 4-554565737: Response Received:
>> > 2015-04-15 15:13:02,715 DEBUG [agent.transport.Request]
>> > (DirectAgent-441:null) Seq 4-554565737: Processing: { Ans: , MgmtId:
>> > 264018885718825, via: 4, Ver: v1, Flags: 110,
>> >
>> [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM
>> > does not exist","wait":0}}] }
>> > 2015-04-15 15:13:02,716 DEBUG [agent.manager.AgentAttache]
>> > (DirectAgent-441:null) Seq 4-554565737: No more commands found
>> > 2015-04-15 15:13:02,716 DEBUG [agent.transport.Request]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
>> > 4-554565737: Received: { Ans: , MgmtId: 264018885718825, via: 4, Ver:
>> v1,
>> > Flags: 110, { StopAnswer } }
>> > 2015-04-15 15:13:02,729 DEBUG [cloud.network.NetworkModelImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Service
>> > SecurityGroup is not supported in the network id=204
>> > 2015-04-15 15:13:02,735 DEBUG [cloud.network.NetworkManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > Changing active number of nics for network id=204 on -1
>> > 2015-04-15 15:13:02,743 DEBUG [cloud.network.NetworkManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Asking
>> > VirtualRouter to release
>> > Nic[178-162-59f93f8f-d782-438d-ae31-683c3887e5b8-10.10.30.29]
>> > 2015-04-15 15:13:02,743 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > Successfully released network resources for the vm VM[User|pipGame001]
>> > 2015-04-15 15:13:02,743 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > Successfully cleanued up resources for the vm VM[User|pipGame001] in
>> > Starting state
>> > 2015-04-15 15:13:02,758 DEBUG
>> [cloud.deploy.DeploymentPlanningManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Deploy
>> > avoids pods: [], clusters: [], hosts: [4]
>> > 2015-04-15 15:13:02,758 DEBUG
>> [cloud.deploy.DeploymentPlanningManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot
>> > allocate the VM, returning.
>> > 2015-04-15 15:13:02,766 DEBUG [cloud.capacity.CapacityManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
>> > state transitted from :Starting to Stopped with event:
>> OperationFailedvm's
>> > original host id: null new host id: null host id before state
>> transition: 4
>> > 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Hosts's
>> > actual total CPU: 52800 and CPU after applying overprovisioning: 52800
>> > 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Hosts's
>> > actual total RAM: 198546824448 and RAM after applying overprovisioning:
>> > 198546817024
>> > 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> release
>> > cpu from host: 4, old used: 50500,reserved: 0, actual total: 52800,
>> total
>> > with overprovisioning: 52800; new used: 46500,reserved:0;
>> > movedfromreserved: false,moveToReserveredfalse
>> > 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> release
>> > mem from host: 4, old used: 152974655488,reserved: 0, total:
>> 198546817024;
>> > new used: 144586047488,reserved:0; movedfromreserved:
>> > false,moveToReserveredfalse
>> > 2015-04-15 15:13:02,795 DEBUG [cloud.capacity.CapacityManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
>> > state transitted from :Stopped to Starting with event:
>> StartRequestedvm's
>> > original host id: null new host id: null host id before state
>> transition:
>> > null
>> > 2015-04-15 15:13:02,795 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > Successfully transitioned to start state for VM[User|pipGame001]
>> > reservation id = 3d92c258-9747-46ae-98b3-d14f8c52b24b
>> > 2015-04-15 15:13:02,798 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Trying
>> > to deploy VM, vm has dcId: 1 and podId: 1
>> > 2015-04-15 15:13:02,798 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Deploy
>> > avoids pods: [], clusters: [], hosts: [4]
>> > 2015-04-15 15:13:02,813 DEBUG
>> [cloud.deploy.DeploymentPlanningManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Deploy
>> > avoids pods: [], clusters: [], hosts: [4]
>> > 2015-04-15 15:13:02,813 DEBUG
>> [cloud.deploy.DeploymentPlanningManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot
>> > allocate the VM, returning.
>> > 2015-04-15 15:13:02,821 DEBUG [cloud.capacity.CapacityManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
>> > state transitted from :Starting to Stopped with event:
>> OperationFailedvm's
>> > original host id: null new host id: null host id before state
>> transition:
>> > null
>> > 2015-04-15 15:13:02,836 DEBUG [cloud.vm.UserVmManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > Destroying vm VM[User|pipGame001] as it failed to create on Host with
>> > Id:null
>> > 2015-04-15 15:13:02,845 DEBUG [cloud.capacity.CapacityManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
>> > state transitted from :Stopped to Error with event:
>> > OperationFailedToErrorvm's original host id: null new host id: null
>> host id
>> > before state transition: null
>> > 2015-04-15 15:13:02,854 WARN [apache.cloudstack.alerts]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null //
>> > message:: Failed to deploy Vm with Id: 162, on Host with Id: null
>> > 2015-04-15 15:13:03,503 DEBUG [agent.manager.AgentManagerImpl]
>> > (AgentManager-Handler-5:null) SeqA 2-4128766: Processing Seq
>> 2-4128766: {
>> > Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
>> >
>> >
>> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
>> > \"connections\": []\n}","wait":0}}] }
>> > 2015-04-15 15:13:03,506 DEBUG [agent.manager.AgentManagerImpl]
>> > (AgentManager-Handler-5:null) SeqA 2-4128766: Sending Seq 2-4128766: {
>> > Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
>> > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>> > 2015-04-15 15:13:04,586 DEBUG [cloud.server.StatsCollector]
>> > (StatsCollector-1:null) HostStatsCollector is running...
>> > 2015-04-15 15:13:04,601 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-234:null) Seq 1-1234763897: Executing request
>> > 2015-04-15 15:13:04,843 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-234:null) Seq 1-1234763897: Response Received:
>> > 2015-04-15 15:13:04,844 DEBUG [agent.transport.Request]
>> > (StatsCollector-1:null) Seq 1-1234763897: Received: { Ans: , MgmtId:
>> > 264018885718825, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
>> > 2015-04-15 15:13:04,854 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-443:null) Seq 4-554565738: Executing request
>> > 2015-04-15 15:13:05,089 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-443:null) Seq 4-554565738: Response Received:
>> > 2015-04-15 15:13:05,089 DEBUG [agent.transport.Request]
>> > (StatsCollector-1:null) Seq 4-554565738: Received: { Ans: , MgmtId:
>> > 264018885718825, via: 4, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
>> > 2015-04-15 15:13:05,099 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-444:null) Seq 10-1866137706: Executing request
>> > 2015-04-15 15:13:05,332 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-444:null) Seq 10-1866137706: Response Received:
>> > 2015-04-15 15:13:05,332 DEBUG [agent.transport.Request]
>> > (StatsCollector-1:null) Seq 10-1866137706: Received: { Ans: , MgmtId:
>> > 264018885718825, via: 10, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
>> > 2015-04-15 15:13:05,342 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-445:null) Seq 11-1040711788: Executing request
>> > 2015-04-15 15:13:05,434 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-21:null) ===START=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081984085
>> > 2015-04-15 15:13:05,460 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-21:null) ===END=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081984085
>> > 2015-04-15 15:13:05,502 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-445:null) Seq 11-1040711788: Response Received:
>> > 2015-04-15 15:13:05,503 DEBUG [agent.transport.Request]
>> > (StatsCollector-1:null) Seq 11-1040711788: Received: { Ans: , MgmtId:
>> > 264018885718825, via: 11, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
>> > ^C2015-04-15 15:13:07,855 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-15:null) ===START=== 114.251.179.130 -- GET
>> >
>> >
>> command=listServiceOfferings&response=json&sessionkey=n%2FBH%2BAXCkHPZx8RI5Eo%2BVxyikIE%3D&issystem=false&id=134ee9f2-e9e0-4676-9ecd-b51d65b60766&_=1429081997475
>> > 2015-04-15 15:13:07,875 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-15:null) ===END=== 114.251.179.130 -- GET
>> >
>> >
>> command=listServiceOfferings&response=json&sessionkey=n%2FBH%2BAXCkHPZx8RI5Eo%2BVxyikIE%3D&issystem=false&id=134ee9f2-e9e0-4676-9ecd-b51d65b60766&_=1429081997475
>> > 2015-04-15 15:13:07,982 ERROR [cloud.alert.AlertManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> Problem
>> > sending email alert
>> > javax.mail.MessagingException: Exception reading response
>> > (javax.net.ssl.SSLException: Unrecognized SSL message, plaintext
>> > connection?)
>> > at
>> >
>> com.sun.mail.smtp.SMTPTransport.readServerResponse(SMTPTransport.java:1462)
>> > at com.sun.mail.smtp.SMTPTransport.openServer(SMTPTransport.java:1260)
>> > at
>> com.sun.mail.smtp.SMTPTransport.protocolConnect(SMTPTransport.java:370)
>> > at javax.mail.Service.connect(Service.java:251)
>> > at javax.mail.Service.connect(Service.java:91)
>> > at javax.mail.Service.connect(Service.java:76)
>> > at
>> >
>> >
>> com.cloud.alert.AlertManagerImpl$EmailAlert.sendAlert(AlertManagerImpl.java:872)
>> > at com.cloud.alert.AlertManagerImpl.sendAlert(AlertManagerImpl.java:261)
>> > at
>> >
>> >
>> com.cloud.vm.UserVmManagerImpl.updateVmStateForFailedVmCreation(UserVmManagerImpl.java:1732)
>> > at
>> >
>> >
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2969)
>> > at
>> >
>> >
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
>> > at
>> >
>> >
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>> > at
>> >
>> >
>> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
>> > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>> > at
>> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>> > at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>> > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>> > at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>> > at
>> >
>> >
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>> > at
>> >
>> >
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>> > at java.lang.Thread.run(Thread.java:662)
>> > Caused by: javax.net.ssl.SSLException: Unrecognized SSL message,
>> plaintext
>> > connection?
>> > at
>> >
>> >
>> com.sun.net.ssl.internal.ssl.InputRecord.handleUnknownRecord(InputRecord.java:523)
>> > at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:355)
>> > at
>> >
>> >
>> com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:798)
>> > at
>> >
>> >
>> com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1138)
>> > at
>> >
>> >
>> com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:753)
>> > at
>> com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
>> > at com.sun.mail.util.TraceInputStream.read(TraceInputStream.java:97)
>> > at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
>> > at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
>> > at com.sun.mail.util.LineInputStream.readLine(LineInputStream.java:75)
>> > at
>> >
>> com.sun.mail.smtp.SMTPTransport.readServerResponse(SMTPTransport.java:1440)
>> > ... 24 more
>> > 2015-04-15 15:13:08,009 INFO [user.vm.DeployVMCmd]
>> (Job-Executor-5:job-862
>> > = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > com.cloud.exception.InsufficientServerCapacityException: Unable to
>> create a
>> > deployment for VM[User|pipGame001]Scope=interface
>> com.cloud.dc.DataCenter;
>> > id=1
>> > 2015-04-15 15:13:08,009 INFO [user.vm.DeployVMCmd]
>> (Job-Executor-5:job-862
>> > = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Unable to create a
>> deployment
>> > for VM[User|pipGame001]
>> > com.cloud.exception.InsufficientServerCapacityException: Unable to
>> create a
>> > deployment for VM[User|pipGame001]Scope=interface
>> com.cloud.dc.DataCenter;
>> > id=1
>> > at
>> >
>> >
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
>> > at
>> >
>> >
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
>> > at
>> >
>> >
>> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
>> > at
>> >
>> >
>> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
>> > at
>> >
>> >
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
>> > at
>> >
>> >
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
>> > at
>> >
>> >
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
>> > at
>> >
>> >
>> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>> > at
>> >
>> >
>> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
>> > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
>> > at
>> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
>> > at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>> > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>> > at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>> > at
>> >
>> >
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>> > at
>> >
>> >
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>> > at java.lang.Thread.run(Thread.java:662)
>> > 2015-04-15 15:13:08,011 DEBUG [cloud.async.AsyncJobManagerImpl]
>> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
>> > Complete async job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ],
>> > jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text:
>> Unable
>> > to create a deployment for VM[User|pipGame001]
>> > 2015-04-15 15:13:08,435 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-24:null) ===START=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987085
>> > 2015-04-15 15:13:08,452 DEBUG [cloud.async.AsyncJobManagerImpl]
>> > (catalina-exec-24:null) Async job-862 = [
>> > 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ] completed
>> > 2015-04-15 15:13:08,458 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-24:null) ===END=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987085
>> > 2015-04-15 15:13:08,514 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-19:null) ===START=== 114.251.179.130 -- GET
>> >
>> >
>> command=listVirtualMachines&id=62b63a2d-70d3-4b83-a83f-9682e565f8d2&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987162
>> > 2015-04-15 15:13:08,542 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-19:null) ===END=== 114.251.179.130 -- GET
>> >
>> >
>> command=listVirtualMachines&id=62b63a2d-70d3-4b83-a83f-9682e565f8d2&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987162
>> > 2015-04-15 15:13:13,504 DEBUG [agent.manager.AgentManagerImpl]
>> > (AgentManager-Handler-6:null) SeqA 2-4128767: Processing Seq
>> 2-4128767: {
>> > Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
>> >
>> >
>> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
>> > \"connections\": []\n}","wait":0}}] }
>> > 2015-04-15 15:13:13,508 DEBUG [agent.manager.AgentManagerImpl]
>> > (AgentManager-Handler-6:null) SeqA 2-4128767: Sending Seq 2-4128767: {
>> > Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
>> > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>> > 2015-04-15 15:13:15,389 DEBUG
>> > [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
>> Zone 1
>> > is ready to launch secondary storage VM
>> > 2015-04-15 15:13:15,587 DEBUG
>> [cloud.consoleproxy.ConsoleProxyManagerImpl]
>> > (consoleproxy-1:null) Zone 1 is ready to launch console proxy
>> > ^C
>> > [root@pip_manager ~]# tail -f
>> > /var/log/cloudstack/management/management-server.log
>> > 2015-04-15 15:15:13,904 DEBUG [agent.transport.Request]
>> > (Job-Executor-7:job-864 = [ 72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66 ]) Seq
>> > 1-1234763906: Executing: { Cmd , MgmtId: 264018885718825, via: 1, Ver:
>> v1,
>> > Flags: 100111,
>> >
>> >
>> [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:00:06:47:00:9c","vmIpAddress":"10.10.30.246","vmName":"over1","defaultRouter":"10.10.30.1","defaultDns":"10.10.30.1","duid":"00:03:00:01:02:00:06:47:00:9c","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","
>> > router.name":"r-109-VM","router.ip":"169.254.2.10"},"wait":0}}] }
>> > 2015-04-15 15:15:13,905 DEBUG [agent.manager.DirectAgentAttache]
>> > (DirectAgent-346:null) Seq 1-1234763906: Executing request
>> > 2015-04-15 15:15:15,392 DEBUG
>> > [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
>> Zone 1
>> > is ready to launch secondary storage VM
>> > 2015-04-15 15:15:15,587 DEBUG
>> [cloud.consoleproxy.ConsoleProxyManagerImpl]
>> > (consoleproxy-1:null) Zone 1 is ready to launch console proxy
>> > 2015-04-15 15:15:16,288 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-18:null) ===START=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429082114936
>> > 2015-04-15 15:15:16,312 DEBUG [cloud.api.ApiServlet]
>> > (catalina-exec-18:null) ===END=== 114.251.179.130 -- GET
>> >
>> >
>> command=queryAsyncJobResult&jobId=72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429082114936
>> > 2015-04-15 15:15:17,494 DEBUG
>> > [network.router.VirtualNetworkApplianceManagerImpl]
>> > (RouterStatusMonitor-1:null) Found 1 routers to update status.
>> > 2015-04-15 15:15:17,496 DEBUG
>> > [network.router.VirtualNetworkApplianceManagerImpl]
>> > (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
>> > 2015-04-15 15:15:17,528 DEBUG
>> > [network.router.VirtualNetworkApplianceManagerImpl]
>> > (RouterStatusMonitor-1:null) Found 1 routers to update status.
>> > 2015-04-15 15:15:17,530 DEBUG
>> > [network.router.VirtualNetworkApplianceManagerImpl]
>> > (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
>> >
>> >
>> ----------------------------------------------------------------------------------------------------------
>> >
>>
>
>
Re: 关于虚拟路由器的问题
Posted by 崔佳 <cu...@gmail.com>.
日志我转存到其他磁盘上了~ 但我迁移了之后,日志都不输出了 从df 命令上来看的话 磁盘空间还有
日志一直不输出了...............
2015-04-15 16:38 GMT+08:00 Darren Tang <da...@gmail.com>:
> 应该是虚拟路由器空间满了。
> 通过console登录到虚拟路由器看看/var下面的空间是否满了，清理下就行了。
>
>
> 2015-04-15 16:30 GMT+08:00 崔佳 <cu...@gmail.com>:
>
> > 我的虚拟路由器重启过一次,并更改了下系统方案,我自定义的
> >
> > 现在的问题是自从重启后,我无法新添加实例了~~添加就报如下错误
> >
> >
> >
> ---------------------------------------------------------------------------------------------------------
> > 2015-04-15 15:12:53,502 DEBUG [agent.manager.AgentManagerImpl]
> > (AgentManager-Handler-4:null) SeqA 2-4128765: Processing Seq 2-4128765:
> {
> > Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> >
> >
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> > \"connections\": []\n}","wait":0}}] }
> > 2015-04-15 15:12:53,506 DEBUG [agent.manager.AgentManagerImpl]
> > (AgentManager-Handler-4:null) SeqA 2-4128765: Sending Seq 2-4128765: {
> > Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
> > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> > 2015-04-15 15:12:56,430 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-17:null) ===START=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081975080
> > 2015-04-15 15:12:56,454 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-17:null) ===END=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081975080
> > 2015-04-15 15:12:59,432 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-16:null) ===START=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081978082
> > 2015-04-15 15:12:59,456 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-16:null) ===END=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081978082
> > 2015-04-15 15:13:02,433 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-18:null) ===START=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081981083
> > 2015-04-15 15:13:02,458 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-18:null) ===END=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081981083
> > 2015-04-15 15:13:02,632 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-440:null) Seq 1-1234763896: Response Received:
> > 2015-04-15 15:13:02,632 DEBUG [agent.transport.Request]
> > (DirectAgent-440:null) Seq 1-1234763896: Processing: { Ans: , MgmtId:
> > 264018885718825, via: 1, Ver: v1, Flags: 110,
> > [{"com.cloud.agent.api.Answer":{"result":false,"details":"DhcpEntry
> > failed","wait":0}}] }
> > 2015-04-15 15:13:02,633 DEBUG [agent.manager.AgentAttache]
> > (DirectAgent-440:null) Seq 1-1234763896: No more commands found
> > 2015-04-15 15:13:02,633 DEBUG [agent.transport.Request]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
> > 1-1234763896: Received: { Ans: , MgmtId: 264018885718825, via: 1, Ver:
> v1,
> > Flags: 110, { Answer } }
> > 2015-04-15 15:13:02,633 INFO [cloud.vm.VirtualMachineManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Unable
> > to contact resource.
> > com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:1]
> > is unreachable: Unable to apply dhcp entry on router
> > at
> >
> >
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3808)
> > at
> >
> >
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyDhcpEntry(VirtualNetworkApplianceManagerImpl.java:2919)
> > at
> >
> >
> com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:898)
> > at
> >
> >
> com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2070)
> > at
> >
> >
> com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2191)
> > at
> >
> com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2127)
> > at
> >
> >
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:887)
> > at
> >
> >
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
> > at
> >
> >
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
> > at
> >
> >
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> > at
> >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
> > at
> >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
> > at
> >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> > at
> >
> >
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> > at
> >
> >
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> > at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> > at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
> > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> > at java.util.concurrent.FutureTask.run(FutureTask.java:138)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> > at java.lang.Thread.run(Thread.java:662)
> > 2015-04-15 15:13:02,636 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > Cleaning up resources for the vm VM[User|pipGame001] in Starting state
> > 2015-04-15 15:13:02,639 DEBUG [agent.transport.Request]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
> > 4-554565737: Sending { Cmd , MgmtId: 264018885718825, via: 4, Ver: v1,
> > Flags: 100111,
> >
> >
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-162-VM","wait":0}}]
> > }
> > 2015-04-15 15:13:02,639 DEBUG [agent.transport.Request]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
> > 4-554565737: Executing: { Cmd , MgmtId: 264018885718825, via: 4, Ver:
> v1,
> > Flags: 100111,
> >
> >
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-162-VM","wait":0}}]
> > }
> > 2015-04-15 15:13:02,640 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-441:null) Seq 4-554565737: Executing request
> > 2015-04-15 15:13:02,715 INFO [xen.resource.CitrixResourceBase]
> > (DirectAgent-441:null) VM does not exist on
> > XenServere0e8ebf2-a5b4-4176-8ff5-2e29d9f289aa
> > 2015-04-15 15:13:02,715 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-441:null) Seq 4-554565737: Response Received:
> > 2015-04-15 15:13:02,715 DEBUG [agent.transport.Request]
> > (DirectAgent-441:null) Seq 4-554565737: Processing: { Ans: , MgmtId:
> > 264018885718825, via: 4, Ver: v1, Flags: 110,
> >
> [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM
> > does not exist","wait":0}}] }
> > 2015-04-15 15:13:02,716 DEBUG [agent.manager.AgentAttache]
> > (DirectAgent-441:null) Seq 4-554565737: No more commands found
> > 2015-04-15 15:13:02,716 DEBUG [agent.transport.Request]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
> > 4-554565737: Received: { Ans: , MgmtId: 264018885718825, via: 4, Ver:
> v1,
> > Flags: 110, { StopAnswer } }
> > 2015-04-15 15:13:02,729 DEBUG [cloud.network.NetworkModelImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Service
> > SecurityGroup is not supported in the network id=204
> > 2015-04-15 15:13:02,735 DEBUG [cloud.network.NetworkManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > Changing active number of nics for network id=204 on -1
> > 2015-04-15 15:13:02,743 DEBUG [cloud.network.NetworkManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Asking
> > VirtualRouter to release
> > Nic[178-162-59f93f8f-d782-438d-ae31-683c3887e5b8-10.10.30.29]
> > 2015-04-15 15:13:02,743 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > Successfully released network resources for the vm VM[User|pipGame001]
> > 2015-04-15 15:13:02,743 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > Successfully cleanued up resources for the vm VM[User|pipGame001] in
> > Starting state
> > 2015-04-15 15:13:02,758 DEBUG
> [cloud.deploy.DeploymentPlanningManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Deploy
> > avoids pods: [], clusters: [], hosts: [4]
> > 2015-04-15 15:13:02,758 DEBUG
> [cloud.deploy.DeploymentPlanningManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot
> > allocate the VM, returning.
> > 2015-04-15 15:13:02,766 DEBUG [cloud.capacity.CapacityManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
> > state transitted from :Starting to Stopped with event:
> OperationFailedvm's
> > original host id: null new host id: null host id before state
> transition: 4
> > 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Hosts's
> > actual total CPU: 52800 and CPU after applying overprovisioning: 52800
> > 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Hosts's
> > actual total RAM: 198546824448 and RAM after applying overprovisioning:
> > 198546817024
> > 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> release
> > cpu from host: 4, old used: 50500,reserved: 0, actual total: 52800, total
> > with overprovisioning: 52800; new used: 46500,reserved:0;
> > movedfromreserved: false,moveToReserveredfalse
> > 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> release
> > mem from host: 4, old used: 152974655488,reserved: 0, total:
> 198546817024;
> > new used: 144586047488,reserved:0; movedfromreserved:
> > false,moveToReserveredfalse
> > 2015-04-15 15:13:02,795 DEBUG [cloud.capacity.CapacityManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
> > state transitted from :Stopped to Starting with event: StartRequestedvm's
> > original host id: null new host id: null host id before state transition:
> > null
> > 2015-04-15 15:13:02,795 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > Successfully transitioned to start state for VM[User|pipGame001]
> > reservation id = 3d92c258-9747-46ae-98b3-d14f8c52b24b
> > 2015-04-15 15:13:02,798 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Trying
> > to deploy VM, vm has dcId: 1 and podId: 1
> > 2015-04-15 15:13:02,798 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Deploy
> > avoids pods: [], clusters: [], hosts: [4]
> > 2015-04-15 15:13:02,813 DEBUG
> [cloud.deploy.DeploymentPlanningManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Deploy
> > avoids pods: [], clusters: [], hosts: [4]
> > 2015-04-15 15:13:02,813 DEBUG
> [cloud.deploy.DeploymentPlanningManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot
> > allocate the VM, returning.
> > 2015-04-15 15:13:02,821 DEBUG [cloud.capacity.CapacityManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
> > state transitted from :Starting to Stopped with event:
> OperationFailedvm's
> > original host id: null new host id: null host id before state transition:
> > null
> > 2015-04-15 15:13:02,836 DEBUG [cloud.vm.UserVmManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > Destroying vm VM[User|pipGame001] as it failed to create on Host with
> > Id:null
> > 2015-04-15 15:13:02,845 DEBUG [cloud.capacity.CapacityManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
> > state transitted from :Stopped to Error with event:
> > OperationFailedToErrorvm's original host id: null new host id: null host
> id
> > before state transition: null
> > 2015-04-15 15:13:02,854 WARN [apache.cloudstack.alerts]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null //
> > message:: Failed to deploy Vm with Id: 162, on Host with Id: null
> > 2015-04-15 15:13:03,503 DEBUG [agent.manager.AgentManagerImpl]
> > (AgentManager-Handler-5:null) SeqA 2-4128766: Processing Seq 2-4128766:
> {
> > Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> >
> >
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> > \"connections\": []\n}","wait":0}}] }
> > 2015-04-15 15:13:03,506 DEBUG [agent.manager.AgentManagerImpl]
> > (AgentManager-Handler-5:null) SeqA 2-4128766: Sending Seq 2-4128766: {
> > Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
> > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> > 2015-04-15 15:13:04,586 DEBUG [cloud.server.StatsCollector]
> > (StatsCollector-1:null) HostStatsCollector is running...
> > 2015-04-15 15:13:04,601 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-234:null) Seq 1-1234763897: Executing request
> > 2015-04-15 15:13:04,843 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-234:null) Seq 1-1234763897: Response Received:
> > 2015-04-15 15:13:04,844 DEBUG [agent.transport.Request]
> > (StatsCollector-1:null) Seq 1-1234763897: Received: { Ans: , MgmtId:
> > 264018885718825, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> > 2015-04-15 15:13:04,854 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-443:null) Seq 4-554565738: Executing request
> > 2015-04-15 15:13:05,089 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-443:null) Seq 4-554565738: Response Received:
> > 2015-04-15 15:13:05,089 DEBUG [agent.transport.Request]
> > (StatsCollector-1:null) Seq 4-554565738: Received: { Ans: , MgmtId:
> > 264018885718825, via: 4, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> > 2015-04-15 15:13:05,099 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-444:null) Seq 10-1866137706: Executing request
> > 2015-04-15 15:13:05,332 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-444:null) Seq 10-1866137706: Response Received:
> > 2015-04-15 15:13:05,332 DEBUG [agent.transport.Request]
> > (StatsCollector-1:null) Seq 10-1866137706: Received: { Ans: , MgmtId:
> > 264018885718825, via: 10, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> > 2015-04-15 15:13:05,342 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-445:null) Seq 11-1040711788: Executing request
> > 2015-04-15 15:13:05,434 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-21:null) ===START=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081984085
> > 2015-04-15 15:13:05,460 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-21:null) ===END=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081984085
> > 2015-04-15 15:13:05,502 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-445:null) Seq 11-1040711788: Response Received:
> > 2015-04-15 15:13:05,503 DEBUG [agent.transport.Request]
> > (StatsCollector-1:null) Seq 11-1040711788: Received: { Ans: , MgmtId:
> > 264018885718825, via: 11, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> > ^C2015-04-15 15:13:07,855 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-15:null) ===START=== 114.251.179.130 -- GET
> >
> >
> command=listServiceOfferings&response=json&sessionkey=n%2FBH%2BAXCkHPZx8RI5Eo%2BVxyikIE%3D&issystem=false&id=134ee9f2-e9e0-4676-9ecd-b51d65b60766&_=1429081997475
> > 2015-04-15 15:13:07,875 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-15:null) ===END=== 114.251.179.130 -- GET
> >
> >
> command=listServiceOfferings&response=json&sessionkey=n%2FBH%2BAXCkHPZx8RI5Eo%2BVxyikIE%3D&issystem=false&id=134ee9f2-e9e0-4676-9ecd-b51d65b60766&_=1429081997475
> > 2015-04-15 15:13:07,982 ERROR [cloud.alert.AlertManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Problem
> > sending email alert
> > javax.mail.MessagingException: Exception reading response
> > (javax.net.ssl.SSLException: Unrecognized SSL message, plaintext
> > connection?)
> > at
> >
> com.sun.mail.smtp.SMTPTransport.readServerResponse(SMTPTransport.java:1462)
> > at com.sun.mail.smtp.SMTPTransport.openServer(SMTPTransport.java:1260)
> > at
> com.sun.mail.smtp.SMTPTransport.protocolConnect(SMTPTransport.java:370)
> > at javax.mail.Service.connect(Service.java:251)
> > at javax.mail.Service.connect(Service.java:91)
> > at javax.mail.Service.connect(Service.java:76)
> > at
> >
> >
> com.cloud.alert.AlertManagerImpl$EmailAlert.sendAlert(AlertManagerImpl.java:872)
> > at com.cloud.alert.AlertManagerImpl.sendAlert(AlertManagerImpl.java:261)
> > at
> >
> >
> com.cloud.vm.UserVmManagerImpl.updateVmStateForFailedVmCreation(UserVmManagerImpl.java:1732)
> > at
> >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2969)
> > at
> >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> > at
> >
> >
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> > at
> >
> >
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> > at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> > at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
> > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> > at java.util.concurrent.FutureTask.run(FutureTask.java:138)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> > at java.lang.Thread.run(Thread.java:662)
> > Caused by: javax.net.ssl.SSLException: Unrecognized SSL message,
> plaintext
> > connection?
> > at
> >
> >
> com.sun.net.ssl.internal.ssl.InputRecord.handleUnknownRecord(InputRecord.java:523)
> > at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:355)
> > at
> >
> >
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:798)
> > at
> >
> >
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1138)
> > at
> >
> >
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:753)
> > at
> com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
> > at com.sun.mail.util.TraceInputStream.read(TraceInputStream.java:97)
> > at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> > at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
> > at com.sun.mail.util.LineInputStream.readLine(LineInputStream.java:75)
> > at
> >
> com.sun.mail.smtp.SMTPTransport.readServerResponse(SMTPTransport.java:1440)
> > ... 24 more
> > 2015-04-15 15:13:08,009 INFO [user.vm.DeployVMCmd]
> (Job-Executor-5:job-862
> > = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > com.cloud.exception.InsufficientServerCapacityException: Unable to
> create a
> > deployment for VM[User|pipGame001]Scope=interface
> com.cloud.dc.DataCenter;
> > id=1
> > 2015-04-15 15:13:08,009 INFO [user.vm.DeployVMCmd]
> (Job-Executor-5:job-862
> > = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Unable to create a deployment
> > for VM[User|pipGame001]
> > com.cloud.exception.InsufficientServerCapacityException: Unable to
> create a
> > deployment for VM[User|pipGame001]Scope=interface
> com.cloud.dc.DataCenter;
> > id=1
> > at
> >
> >
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
> > at
> >
> >
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
> > at
> >
> >
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
> > at
> >
> >
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> > at
> >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
> > at
> >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
> > at
> >
> >
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> > at
> >
> >
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> > at
> >
> >
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> > at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> > at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
> > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> > at java.util.concurrent.FutureTask.run(FutureTask.java:138)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> > at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> > at java.lang.Thread.run(Thread.java:662)
> > 2015-04-15 15:13:08,011 DEBUG [cloud.async.AsyncJobManagerImpl]
> > (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> > Complete async job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ],
> > jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable
> > to create a deployment for VM[User|pipGame001]
> > 2015-04-15 15:13:08,435 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-24:null) ===START=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987085
> > 2015-04-15 15:13:08,452 DEBUG [cloud.async.AsyncJobManagerImpl]
> > (catalina-exec-24:null) Async job-862 = [
> > 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ] completed
> > 2015-04-15 15:13:08,458 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-24:null) ===END=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987085
> > 2015-04-15 15:13:08,514 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-19:null) ===START=== 114.251.179.130 -- GET
> >
> >
> command=listVirtualMachines&id=62b63a2d-70d3-4b83-a83f-9682e565f8d2&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987162
> > 2015-04-15 15:13:08,542 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-19:null) ===END=== 114.251.179.130 -- GET
> >
> >
> command=listVirtualMachines&id=62b63a2d-70d3-4b83-a83f-9682e565f8d2&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987162
> > 2015-04-15 15:13:13,504 DEBUG [agent.manager.AgentManagerImpl]
> > (AgentManager-Handler-6:null) SeqA 2-4128767: Processing Seq 2-4128767:
> {
> > Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> >
> >
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> > \"connections\": []\n}","wait":0}}] }
> > 2015-04-15 15:13:13,508 DEBUG [agent.manager.AgentManagerImpl]
> > (AgentManager-Handler-6:null) SeqA 2-4128767: Sending Seq 2-4128767: {
> > Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
> > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> > 2015-04-15 15:13:15,389 DEBUG
> > [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone
> 1
> > is ready to launch secondary storage VM
> > 2015-04-15 15:13:15,587 DEBUG
> [cloud.consoleproxy.ConsoleProxyManagerImpl]
> > (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> > ^C
> > [root@pip_manager ~]# tail -f
> > /var/log/cloudstack/management/management-server.log
> > 2015-04-15 15:15:13,904 DEBUG [agent.transport.Request]
> > (Job-Executor-7:job-864 = [ 72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66 ]) Seq
> > 1-1234763906: Executing: { Cmd , MgmtId: 264018885718825, via: 1, Ver:
> v1,
> > Flags: 100111,
> >
> >
> [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:00:06:47:00:9c","vmIpAddress":"10.10.30.246","vmName":"over1","defaultRouter":"10.10.30.1","defaultDns":"10.10.30.1","duid":"00:03:00:01:02:00:06:47:00:9c","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","
> > router.name":"r-109-VM","router.ip":"169.254.2.10"},"wait":0}}] }
> > 2015-04-15 15:15:13,905 DEBUG [agent.manager.DirectAgentAttache]
> > (DirectAgent-346:null) Seq 1-1234763906: Executing request
> > 2015-04-15 15:15:15,392 DEBUG
> > [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone
> 1
> > is ready to launch secondary storage VM
> > 2015-04-15 15:15:15,587 DEBUG
> [cloud.consoleproxy.ConsoleProxyManagerImpl]
> > (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> > 2015-04-15 15:15:16,288 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-18:null) ===START=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429082114936
> > 2015-04-15 15:15:16,312 DEBUG [cloud.api.ApiServlet]
> > (catalina-exec-18:null) ===END=== 114.251.179.130 -- GET
> >
> >
> command=queryAsyncJobResult&jobId=72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429082114936
> > 2015-04-15 15:15:17,494 DEBUG
> > [network.router.VirtualNetworkApplianceManagerImpl]
> > (RouterStatusMonitor-1:null) Found 1 routers to update status.
> > 2015-04-15 15:15:17,496 DEBUG
> > [network.router.VirtualNetworkApplianceManagerImpl]
> > (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> > 2015-04-15 15:15:17,528 DEBUG
> > [network.router.VirtualNetworkApplianceManagerImpl]
> > (RouterStatusMonitor-1:null) Found 1 routers to update status.
> > 2015-04-15 15:15:17,530 DEBUG
> > [network.router.VirtualNetworkApplianceManagerImpl]
> > (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> >
> >
> ----------------------------------------------------------------------------------------------------------
> >
>
Re: 关于虚拟路由器的问题
Posted by Darren Tang <da...@gmail.com>.
应该是虚拟路由器空间满了。
通过console登录到虚拟路由器看看/var下面的空间是否满了，清理下就行了。
2015-04-15 16:30 GMT+08:00 崔佳 <cu...@gmail.com>:
> 我的虚拟路由器重启过一次,并更改了下系统方案,我自定义的
>
> 现在的问题是自从重启后,我无法新添加实例了~~添加就报如下错误
>
>
> ---------------------------------------------------------------------------------------------------------
> 2015-04-15 15:12:53,502 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-4:null) SeqA 2-4128765: Processing Seq 2-4128765: {
> Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
>
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2015-04-15 15:12:53,506 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-4:null) SeqA 2-4128765: Sending Seq 2-4128765: {
> Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-04-15 15:12:56,430 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-17:null) ===START=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081975080
> 2015-04-15 15:12:56,454 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-17:null) ===END=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081975080
> 2015-04-15 15:12:59,432 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-16:null) ===START=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081978082
> 2015-04-15 15:12:59,456 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-16:null) ===END=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081978082
> 2015-04-15 15:13:02,433 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-18:null) ===START=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081981083
> 2015-04-15 15:13:02,458 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-18:null) ===END=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081981083
> 2015-04-15 15:13:02,632 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-440:null) Seq 1-1234763896: Response Received:
> 2015-04-15 15:13:02,632 DEBUG [agent.transport.Request]
> (DirectAgent-440:null) Seq 1-1234763896: Processing: { Ans: , MgmtId:
> 264018885718825, via: 1, Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.Answer":{"result":false,"details":"DhcpEntry
> failed","wait":0}}] }
> 2015-04-15 15:13:02,633 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-440:null) Seq 1-1234763896: No more commands found
> 2015-04-15 15:13:02,633 DEBUG [agent.transport.Request]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
> 1-1234763896: Received: { Ans: , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 110, { Answer } }
> 2015-04-15 15:13:02,633 INFO [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Unable
> to contact resource.
> com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:1]
> is unreachable: Unable to apply dhcp entry on router
> at
>
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3808)
> at
>
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyDhcpEntry(VirtualNetworkApplianceManagerImpl.java:2919)
> at
>
> com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:898)
> at
>
> com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2070)
> at
>
> com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2191)
> at
> com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2127)
> at
>
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:887)
> at
>
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
> at
>
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
> at
>
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at
>
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
> at
>
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
> at
>
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> at
>
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
>
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> at java.util.concurrent.FutureTask.run(FutureTask.java:138)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:662)
> 2015-04-15 15:13:02,636 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Cleaning up resources for the vm VM[User|pipGame001] in Starting state
> 2015-04-15 15:13:02,639 DEBUG [agent.transport.Request]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
> 4-554565737: Sending { Cmd , MgmtId: 264018885718825, via: 4, Ver: v1,
> Flags: 100111,
>
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-162-VM","wait":0}}]
> }
> 2015-04-15 15:13:02,639 DEBUG [agent.transport.Request]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
> 4-554565737: Executing: { Cmd , MgmtId: 264018885718825, via: 4, Ver: v1,
> Flags: 100111,
>
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-162-VM","wait":0}}]
> }
> 2015-04-15 15:13:02,640 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-441:null) Seq 4-554565737: Executing request
> 2015-04-15 15:13:02,715 INFO [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) VM does not exist on
> XenServere0e8ebf2-a5b4-4176-8ff5-2e29d9f289aa
> 2015-04-15 15:13:02,715 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-441:null) Seq 4-554565737: Response Received:
> 2015-04-15 15:13:02,715 DEBUG [agent.transport.Request]
> (DirectAgent-441:null) Seq 4-554565737: Processing: { Ans: , MgmtId:
> 264018885718825, via: 4, Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM
> does not exist","wait":0}}] }
> 2015-04-15 15:13:02,716 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-441:null) Seq 4-554565737: No more commands found
> 2015-04-15 15:13:02,716 DEBUG [agent.transport.Request]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Seq
> 4-554565737: Received: { Ans: , MgmtId: 264018885718825, via: 4, Ver: v1,
> Flags: 110, { StopAnswer } }
> 2015-04-15 15:13:02,729 DEBUG [cloud.network.NetworkModelImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Service
> SecurityGroup is not supported in the network id=204
> 2015-04-15 15:13:02,735 DEBUG [cloud.network.NetworkManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Changing active number of nics for network id=204 on -1
> 2015-04-15 15:13:02,743 DEBUG [cloud.network.NetworkManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Asking
> VirtualRouter to release
> Nic[178-162-59f93f8f-d782-438d-ae31-683c3887e5b8-10.10.30.29]
> 2015-04-15 15:13:02,743 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Successfully released network resources for the vm VM[User|pipGame001]
> 2015-04-15 15:13:02,743 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Successfully cleanued up resources for the vm VM[User|pipGame001] in
> Starting state
> 2015-04-15 15:13:02,758 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Deploy
> avoids pods: [], clusters: [], hosts: [4]
> 2015-04-15 15:13:02,758 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot
> allocate the VM, returning.
> 2015-04-15 15:13:02,766 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
> state transitted from :Starting to Stopped with event: OperationFailedvm's
> original host id: null new host id: null host id before state transition: 4
> 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Hosts's
> actual total CPU: 52800 and CPU after applying overprovisioning: 52800
> 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Hosts's
> actual total RAM: 198546824448 and RAM after applying overprovisioning:
> 198546817024
> 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) release
> cpu from host: 4, old used: 50500,reserved: 0, actual total: 52800, total
> with overprovisioning: 52800; new used: 46500,reserved:0;
> movedfromreserved: false,moveToReserveredfalse
> 2015-04-15 15:13:02,776 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) release
> mem from host: 4, old used: 152974655488,reserved: 0, total: 198546817024;
> new used: 144586047488,reserved:0; movedfromreserved:
> false,moveToReserveredfalse
> 2015-04-15 15:13:02,795 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
> state transitted from :Stopped to Starting with event: StartRequestedvm's
> original host id: null new host id: null host id before state transition:
> null
> 2015-04-15 15:13:02,795 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Successfully transitioned to start state for VM[User|pipGame001]
> reservation id = 3d92c258-9747-46ae-98b3-d14f8c52b24b
> 2015-04-15 15:13:02,798 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Trying
> to deploy VM, vm has dcId: 1 and podId: 1
> 2015-04-15 15:13:02,798 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Deploy
> avoids pods: [], clusters: [], hosts: [4]
> 2015-04-15 15:13:02,813 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Deploy
> avoids pods: [], clusters: [], hosts: [4]
> 2015-04-15 15:13:02,813 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot
> allocate the VM, returning.
> 2015-04-15 15:13:02,821 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
> state transitted from :Starting to Stopped with event: OperationFailedvm's
> original host id: null new host id: null host id before state transition:
> null
> 2015-04-15 15:13:02,836 DEBUG [cloud.vm.UserVmManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Destroying vm VM[User|pipGame001] as it failed to create on Host with
> Id:null
> 2015-04-15 15:13:02,845 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) VM
> state transitted from :Stopped to Error with event:
> OperationFailedToErrorvm's original host id: null new host id: null host id
> before state transition: null
> 2015-04-15 15:13:02,854 WARN [apache.cloudstack.alerts]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null //
> message:: Failed to deploy Vm with Id: 162, on Host with Id: null
> 2015-04-15 15:13:03,503 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-5:null) SeqA 2-4128766: Processing Seq 2-4128766: {
> Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
>
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2015-04-15 15:13:03,506 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-5:null) SeqA 2-4128766: Sending Seq 2-4128766: {
> Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-04-15 15:13:04,586 DEBUG [cloud.server.StatsCollector]
> (StatsCollector-1:null) HostStatsCollector is running...
> 2015-04-15 15:13:04,601 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-234:null) Seq 1-1234763897: Executing request
> 2015-04-15 15:13:04,843 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-234:null) Seq 1-1234763897: Response Received:
> 2015-04-15 15:13:04,844 DEBUG [agent.transport.Request]
> (StatsCollector-1:null) Seq 1-1234763897: Received: { Ans: , MgmtId:
> 264018885718825, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2015-04-15 15:13:04,854 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-443:null) Seq 4-554565738: Executing request
> 2015-04-15 15:13:05,089 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-443:null) Seq 4-554565738: Response Received:
> 2015-04-15 15:13:05,089 DEBUG [agent.transport.Request]
> (StatsCollector-1:null) Seq 4-554565738: Received: { Ans: , MgmtId:
> 264018885718825, via: 4, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2015-04-15 15:13:05,099 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-444:null) Seq 10-1866137706: Executing request
> 2015-04-15 15:13:05,332 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-444:null) Seq 10-1866137706: Response Received:
> 2015-04-15 15:13:05,332 DEBUG [agent.transport.Request]
> (StatsCollector-1:null) Seq 10-1866137706: Received: { Ans: , MgmtId:
> 264018885718825, via: 10, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2015-04-15 15:13:05,342 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-445:null) Seq 11-1040711788: Executing request
> 2015-04-15 15:13:05,434 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-21:null) ===START=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081984085
> 2015-04-15 15:13:05,460 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-21:null) ===END=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081984085
> 2015-04-15 15:13:05,502 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-445:null) Seq 11-1040711788: Response Received:
> 2015-04-15 15:13:05,503 DEBUG [agent.transport.Request]
> (StatsCollector-1:null) Seq 11-1040711788: Received: { Ans: , MgmtId:
> 264018885718825, via: 11, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> ^C2015-04-15 15:13:07,855 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-15:null) ===START=== 114.251.179.130 -- GET
>
> command=listServiceOfferings&response=json&sessionkey=n%2FBH%2BAXCkHPZx8RI5Eo%2BVxyikIE%3D&issystem=false&id=134ee9f2-e9e0-4676-9ecd-b51d65b60766&_=1429081997475
> 2015-04-15 15:13:07,875 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-15:null) ===END=== 114.251.179.130 -- GET
>
> command=listServiceOfferings&response=json&sessionkey=n%2FBH%2BAXCkHPZx8RI5Eo%2BVxyikIE%3D&issystem=false&id=134ee9f2-e9e0-4676-9ecd-b51d65b60766&_=1429081997475
> 2015-04-15 15:13:07,982 ERROR [cloud.alert.AlertManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Problem
> sending email alert
> javax.mail.MessagingException: Exception reading response
> (javax.net.ssl.SSLException: Unrecognized SSL message, plaintext
> connection?)
> at
> com.sun.mail.smtp.SMTPTransport.readServerResponse(SMTPTransport.java:1462)
> at com.sun.mail.smtp.SMTPTransport.openServer(SMTPTransport.java:1260)
> at com.sun.mail.smtp.SMTPTransport.protocolConnect(SMTPTransport.java:370)
> at javax.mail.Service.connect(Service.java:251)
> at javax.mail.Service.connect(Service.java:91)
> at javax.mail.Service.connect(Service.java:76)
> at
>
> com.cloud.alert.AlertManagerImpl$EmailAlert.sendAlert(AlertManagerImpl.java:872)
> at com.cloud.alert.AlertManagerImpl.sendAlert(AlertManagerImpl.java:261)
> at
>
> com.cloud.vm.UserVmManagerImpl.updateVmStateForFailedVmCreation(UserVmManagerImpl.java:1732)
> at
>
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2969)
> at
>
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> at
>
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
>
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> at java.util.concurrent.FutureTask.run(FutureTask.java:138)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:662)
> Caused by: javax.net.ssl.SSLException: Unrecognized SSL message, plaintext
> connection?
> at
>
> com.sun.net.ssl.internal.ssl.InputRecord.handleUnknownRecord(InputRecord.java:523)
> at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:355)
> at
>
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:798)
> at
>
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1138)
> at
>
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:753)
> at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
> at com.sun.mail.util.TraceInputStream.read(TraceInputStream.java:97)
> at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
> at com.sun.mail.util.LineInputStream.readLine(LineInputStream.java:75)
> at
> com.sun.mail.smtp.SMTPTransport.readServerResponse(SMTPTransport.java:1440)
> ... 24 more
> 2015-04-15 15:13:08,009 INFO [user.vm.DeployVMCmd] (Job-Executor-5:job-862
> = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|pipGame001]Scope=interface com.cloud.dc.DataCenter;
> id=1
> 2015-04-15 15:13:08,009 INFO [user.vm.DeployVMCmd] (Job-Executor-5:job-862
> = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ]) Unable to create a deployment
> for VM[User|pipGame001]
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|pipGame001]Scope=interface com.cloud.dc.DataCenter;
> id=1
> at
>
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
> at
>
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
> at
>
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
> at
>
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at
>
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
> at
>
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
> at
>
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> at
>
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
>
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
> at java.util.concurrent.FutureTask.run(FutureTask.java:138)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:662)
> 2015-04-15 15:13:08,011 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-5:job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ])
> Complete async job-862 = [ 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ],
> jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable
> to create a deployment for VM[User|pipGame001]
> 2015-04-15 15:13:08,435 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-24:null) ===START=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987085
> 2015-04-15 15:13:08,452 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-24:null) Async job-862 = [
> 83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66 ] completed
> 2015-04-15 15:13:08,458 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-24:null) ===END=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=83e26ebb-8b29-40cb-8e2e-6a9b10cbfa66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987085
> 2015-04-15 15:13:08,514 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-19:null) ===START=== 114.251.179.130 -- GET
>
> command=listVirtualMachines&id=62b63a2d-70d3-4b83-a83f-9682e565f8d2&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987162
> 2015-04-15 15:13:08,542 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-19:null) ===END=== 114.251.179.130 -- GET
>
> command=listVirtualMachines&id=62b63a2d-70d3-4b83-a83f-9682e565f8d2&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429081987162
> 2015-04-15 15:13:13,504 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-6:null) SeqA 2-4128767: Processing Seq 2-4128767: {
> Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
>
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2015-04-15 15:13:13,508 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-6:null) SeqA 2-4128767: Sending Seq 2-4128767: {
> Ans: , MgmtId: 264018885718825, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-04-15 15:13:15,389 DEBUG
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
> is ready to launch secondary storage VM
> 2015-04-15 15:13:15,587 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> ^C
> [root@pip_manager ~]# tail -f
> /var/log/cloudstack/management/management-server.log
> 2015-04-15 15:15:13,904 DEBUG [agent.transport.Request]
> (Job-Executor-7:job-864 = [ 72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66 ]) Seq
> 1-1234763906: Executing: { Cmd , MgmtId: 264018885718825, via: 1, Ver: v1,
> Flags: 100111,
>
> [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:00:06:47:00:9c","vmIpAddress":"10.10.30.246","vmName":"over1","defaultRouter":"10.10.30.1","defaultDns":"10.10.30.1","duid":"00:03:00:01:02:00:06:47:00:9c","isDefault":true,"executeInSequence":true,"accessDetails":{"router.guest.ip":"10.10.30.1","zone.network.type":"Advanced","
> router.name":"r-109-VM","router.ip":"169.254.2.10"},"wait":0}}] }
> 2015-04-15 15:15:13,905 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-346:null) Seq 1-1234763906: Executing request
> 2015-04-15 15:15:15,392 DEBUG
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
> is ready to launch secondary storage VM
> 2015-04-15 15:15:15,587 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> 2015-04-15 15:15:16,288 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-18:null) ===START=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429082114936
> 2015-04-15 15:15:16,312 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-18:null) ===END=== 114.251.179.130 -- GET
>
> command=queryAsyncJobResult&jobId=72e3f2ce-ceaa-4df7-8c43-5cd925d9fc66&response=json&sessionkey=svFUwxEo%2BngKJh0xvUJxNAeqp10%3D&_=1429082114936
> 2015-04-15 15:15:17,494 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 1 routers to update status.
> 2015-04-15 15:15:17,496 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2015-04-15 15:15:17,528 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 1 routers to update status.
> 2015-04-15 15:15:17,530 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
>
> ----------------------------------------------------------------------------------------------------------
>