cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "ASF subversion and git services (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-7761) [Automation] Rebooting System VMs - VMs are getting stopped and started instead of reboot
Date Wed, 22 Oct 2014 00:26:34 GMT

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-7761?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14179395#comment-14179395
] 

ASF subversion and git services commented on CLOUDSTACK-7761:
-------------------------------------------------------------

Commit 0141b37784805b1a55bc450affa282897889e9b9 in cloudstack's branch refs/heads/4.5 from
[~anthonyxu]
[ https://git-wip-us.apache.org/repos/asf?p=cloudstack.git;h=0141b37 ]

CLOUDSTACK-7761:

Revert "when system VM ping times out, stop system VM"

This reverts commit ee23be1942001ab732cfb3ad50fa24163cb88a48.


> [Automation] Rebooting System VMs - VMs are getting stopped and started instead of reboot
> -----------------------------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-7761
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7761
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: Automation
>    Affects Versions: 4.5.0
>            Reporter: Chandan Purushothama
>            Assignee: Anthony Xu
>            Priority: Critical
>             Fix For: 4.5.0
>
>         Attachments: management-server.zip
>
>
> Rebooting System VM using cases are failing on the automation as shown below:
> *Error Message*
> Check Private IP after reboot with that of before reboot  
> *Stacktrace*
>   File "/usr/lib/python2.7/unittest/case.py", line 332, in run
>     testMethod()
>   File "/root/cloudstack/test/integration/smoke/test_ssvm.py", line 725, in test_07_reboot_ssvm
>     "Check Private IP after reboot with that of before reboot"
>   File "/usr/lib/python2.7/unittest/case.py", line 516, in assertEqual
>     assertion_func(first, second, msg=msg)
>   File "/usr/lib/python2.7/unittest/case.py", line 927, in assertMultiLineEqual
>     self.fail(self._formatMessage(msg, standardMsg))
>   File "/usr/lib/python2.7/unittest/case.py", line 413, in fail
>     raise self.failureException(msg)
> 'Check Private IP after reboot with that of before reboot\n
> On further analysis, we found that the reboot command is actually calling Stopcommand
in the later part of the job. This results in the change in private ip address.
> {noformat}
> 2014-10-21 17:06:35,451 DEBUG [c.c.a.ApiServlet] (catalina-exec-21:ctx-f76226cf) ===START===
 10.220.135.30 -- GET  response=json&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=rebootSystemVm&id=0d3261c0-18af-4f4f-8052-78398ea3d319&signature=TXvdc%2FRdiaOYDVvVKjoo%2FYaoMho%3D
> 2014-10-21 17:06:35,476 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-21:ctx-f76226cf
ctx-64e39462 ctx-47749a02) submit async job-547, details: AsyncJobVO {id:547, userId: 2, accountId:
2, instanceType: SystemVm, instanceId: 2, cmd: org.apache.cloudstack.api.command.admin.systemvm.RebootSystemVmCmd,
cmdInfo: {"response":"json","id":"0d3261c0-18af-4f4f-8052-78398ea3d319","ctxDetails":"{\"com.cloud.vm.VirtualMachine\":\"0d3261c0-18af-4f4f-8052-78398ea3d319\"}","cmdEventType":"PROXY.REBOOT","ctxUserId":"2","httpmethod":"GET","uuid":"0d3261c0-18af-4f4f-8052-78398ea3d319","ctxAccountId":"2","ctxStartEventId":"1702","apiKey":"8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg","signature":"TXvdc/RdiaOYDVvVKjoo/YaoMho\u003d"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
59825535280071, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-10-21 17:06:35,476 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-44:ctx-7d84e64c
job-547) Add job-547 into job monitoring
> 2014-10-21 17:06:35,476 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-44:ctx-7d84e64c
job-547) Executing AsyncJobVO {id:547, userId: 2, accountId: 2, instanceType: SystemVm, instanceId:
2, cmd: org.apache.cloudstack.api.command.admin.systemvm.RebootSystemVmCmd, cmdInfo: {"response":"json","id":"0d3261c0-18af-4f4f-8052-78398ea3d319","ctxDetails":"{\"com.cloud.vm.VirtualMachine\":\"0d3261c0-18af-4f4f-8052-78398ea3d319\"}","cmdEventType":"PROXY.REBOOT","ctxUserId":"2","httpmethod":"GET","uuid":"0d3261c0-18af-4f4f-8052-78398ea3d319","ctxAccountId":"2","ctxStartEventId":"1702","apiKey":"8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg","signature":"TXvdc/RdiaOYDVvVKjoo/YaoMho\u003d"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
59825535280071, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-10-21 17:06:35,477 DEBUG [c.c.a.ApiServlet] (catalina-exec-21:ctx-f76226cf ctx-64e39462
ctx-47749a02) ===END===  10.220.135.30 -- GET  response=json&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=rebootSystemVm&id=0d3261c0-18af-4f4f-8052-78398ea3d319&signature=TXvdc%2FRdiaOYDVvVKjoo%2FYaoMho%3D
> 2014-10-21 17:06:35,483 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-a631c521) ===START===
 10.220.135.30 -- GET  jobid=89c344f2-54de-40b7-b1ea-2a9f5b573a4e&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=queryAsyncJobResult&response=json&signature=9GRPDgWSdAC0UuqA0wooTnJ%2FMZc%3D
> 2014-10-21 17:06:35,504 DEBUG [c.c.a.t.Request] (API-Job-Executor-44:ctx-7d84e64c job-547
ctx-dfce25f5) Seq 2-7242632625741890164: Sending  { Cmd , MgmtId: 59825535280071, via: 2(cl09-A-08),
Ver: v1, Flags: 100111, [{"com.cloud.agent.api.RebootCommand":{"vmName":"v-2-VM","wait":0}}]
}
> 2014-10-21 17:06:35,506 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-a631c521 ctx-75530939
ctx-3d3149fb) ===END===  10.220.135.30 -- GET  jobid=89c344f2-54de-40b7-b1ea-2a9f5b573a4e&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=queryAsyncJobResult&response=json&signature=9GRPDgWSdAC0UuqA0wooTnJ%2FMZc%3D
> 2014-10-21 17:06:36,025 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null)
SeqA 3--1: Processing Seq 3--1:  { Cmd , MgmtId: -1, via: 3, Ver: v1, Flags: 111, [{"com.cloud.agent.api.ShutdownCommand":{"reason":"sig.kill","wait":0}}]
}
> 2014-10-21 17:06:36,025 INFO  [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null)
Host 3 has informed us that it is shutting down with reason sig.kill and detail null
> 2014-10-21 17:06:36,026 INFO  [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Host 3 is disconnecting with event ShutdownRequested
> 2014-10-21 17:06:36,027 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
The next status of agent 3 is Disconnected, current status is Up
> 2014-10-21 17:06:36,027 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Deregistering link for 3 with state Disconnected
> 2014-10-21 17:06:36,027 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Remove Agent : 3
> 2014-10-21 17:06:36,027 DEBUG [c.c.a.m.ConnectedAgentAttache] (AgentTaskPool-4:ctx-430ab573)
Processing Disconnect.
> 2014-10-21 17:06:36,028 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.hypervisor.xenserver.discoverer.XcpServerDiscoverer
> 2014-10-21 17:06:36,028 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.hypervisor.hyperv.discoverer.HypervServerDiscoverer
> 2014-10-21 17:06:36,028 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: org.apache.cloudstack.engine.orchestration.NetworkOrchestrator
> 2014-10-21 17:06:36,028 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.deploy.DeploymentPlanningManagerImpl
> 2014-10-21 17:06:36,028 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.storage.listener.StoragePoolMonitor
> 2014-10-21 17:06:36,028 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.vm.ClusteredVirtualMachineManagerImpl
> 2014-10-21 17:06:36,028 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.hypervisor.vmware.manager.VmwareManagerImpl
> 2014-10-21 17:06:36,028 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.network.security.SecurityGroupListener
> 2014-10-21 17:06:36,028 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.storage.secondary.SecondaryStorageListener
> 2014-10-21 17:06:36,029 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
> 2014-10-21 17:06:36,029 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl
> 2014-10-21 17:06:36,029 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener
> 2014-10-21 17:06:36,029 DEBUG [c.c.n.NetworkUsageManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Disconnected called on 3 with status Disconnected
> 2014-10-21 17:06:36,029 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
> 2014-10-21 17:06:36,029 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.network.router.VirtualNetworkApplianceManagerImpl
> 2014-10-21 17:06:36,029 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$BehindOnPingListener
> 2014-10-21 17:06:36,029 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener
> 2014-10-21 17:06:36,030 INFO  [c.c.c.ConsoleProxyManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Console proxy agent disconnected, proxy: v-2-VM
> 2014-10-21 17:06:36,033 WARN  [o.a.c.f.j.AsyncJobExecutionContext] (AgentTaskPool-4:ctx-430ab573)
Job is executed without a context, setup psudo job for the executing thread
> 2014-10-21 17:06:36,047 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AgentTaskPool-4:ctx-430ab573)
Sync job-549 execution on object VmWorkJobQueue.2
> 2014-10-21 17:06:38,015 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-30e36079)
Execute sync-queue item: SyncQueueItemVO {id:206, queueId: 2, contentType: AsyncJob, contentId:
549, lastProcessMsid: null, lastprocessNumber: null, lastProcessTime: null, created: Tue Oct
21 17:06:36 UTC 2014}
> 2014-10-21 17:06:38,016 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-30e36079)
Schedule queued job-549
> 2014-10-21 17:06:38,019 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-41:ctx-966b6925
job-548/job-549) Add job-549 into job monitoring
> 2014-10-21 17:06:38,019 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-41:ctx-966b6925
job-548/job-549) Executing AsyncJobVO {id:549, userId: 1, accountId: 1, instanceType: null,
instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAAAnQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
59825535280071, completeMsid: null, lastUpdated: null, lastPolled: null, created: Tue Oct
21 17:06:36 UTC 2014}
> 2014-10-21 17:06:38,019 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-41:ctx-966b6925
job-548/job-549) Run VM work job: com.cloud.vm.VmWorkStop for VM 2, job origin: 548
> 2014-10-21 17:06:38,020 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-41:ctx-966b6925
job-548/job-549 ctx-f142c8e2) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":1,"accountId":1,"vmId":2,"handlerName":"VirtualMachineManagerImpl"}
> 2014-10-21 17:06:38,031 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-41:ctx-966b6925
job-548/job-549 ctx-f142c8e2) VM state transitted from :Running to Stopping with event: StopRequestedvm's
original host id: 2 new host id: 2 host id before state transition: 2
> 2014-10-21 17:06:38,035 DEBUG [c.c.a.t.Request] (Work-Job-Executor-41:ctx-966b6925 job-548/job-549
ctx-f142c8e2) Seq 2-7242632625741890165: Sending  { Cmd , MgmtId: 59825535280071, via: 2(cl09-A-08),
Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"v-2-VM","wait":0}}]
}
> 2014-10-21 17:06:38,456 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-308251fd)
Storage pool garbage collector found 0 templates to clean up in storage pool: XenRT-Zone-0-Pod-0-Cluster-0-Primary-Store-0
> 2014-10-21 17:06:38,460 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-308251fd)
Secondary storage garbage collector found 0 templates to cleanup on template_store_ref for
store: nfs://10.220.160.33/vol/export/871375-eLdP6E
> 2014-10-21 17:06:38,462 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-308251fd)
Secondary storage garbage collector found 0 snapshots to cleanup on snapshot_store_ref for
store: nfs://10.220.160.33/vol/export/871375-eLdP6E
> 2014-10-21 17:06:38,463 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-308251fd)
Secondary storage garbage collector found 0 volumes to cleanup on volume_store_ref for store:
nfs://10.220.160.33/vol/export/871375-eLdP6E
> 2014-10-21 17:06:40,016 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-5cc6c3b3)
Begin cleanup expired async-jobs
> 2014-10-21 17:06:40,023 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-5cc6c3b3)
End cleanup expired async-jobs
> 2014-10-21 17:06:40,518 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-e1d836e8) ===START===
 10.220.135.30 -- GET  jobid=89c344f2-54de-40b7-b1ea-2a9f5b573a4e&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=queryAsyncJobResult&response=json&signature=9GRPDgWSdAC0UuqA0wooTnJ%2FMZc%3D
> 2014-10-21 17:06:40,543 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-e1d836e8 ctx-0e5aa01c
ctx-7e1a08f9) ===END===  10.220.135.30 -- GET  jobid=89c344f2-54de-40b7-b1ea-2a9f5b573a4e&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=queryAsyncJobResult&response=json&signature=9GRPDgWSdAC0UuqA0wooTnJ%2FMZc%3D
> 2014-10-21 17:06:42,567 DEBUG [c.c.a.t.Request] (AgentManager-Handler-13:null) Seq 2-7242632625741890164:
Processing:  { Ans: , MgmtId: 59825535280071, via: 2, Ver: v1, Flags: 110, [{"com.cloud.agent.api.RebootAnswer":{"vncPort":0,"result":true,"wait":0}}]
}
> 2014-10-21 17:06:42,567 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-13:null) Seq
2-7242632625741890164: No more commands found
> 2014-10-21 17:06:42,567 DEBUG [c.c.a.t.Request] (API-Job-Executor-44:ctx-7d84e64c job-547
ctx-dfce25f5) Seq 2-7242632625741890164: Received:  { Ans: , MgmtId: 59825535280071, via:
2, Ver: v1, Flags: 110, { RebootAnswer } }
> 2014-10-21 17:06:42,567 DEBUG [c.c.c.ConsoleProxyManagerImpl] (API-Job-Executor-44:ctx-7d84e64c
job-547 ctx-dfce25f5) Successfully reboot console proxy v-2-VM
> 2014-10-21 17:06:42,567 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (API-Job-Executor-44:ctx-7d84e64c
job-547 ctx-dfce25f5) received console proxy alert
> 2014-10-21 17:06:42,573 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (API-Job-Executor-44:ctx-7d84e64c
job-547 ctx-dfce25f5) Console proxy is rebooted, zone: XenRT-Zone-0, proxy: v-2-VM, public
IP: 10.220.166.18, private IP: 10.220.165.114
> 2014-10-21 17:06:42,574 WARN  [o.a.c.alerts] (API-Job-Executor-44:ctx-7d84e64c job-547
ctx-dfce25f5)  alertType:: 10 // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message::
Console proxy rebooted in zone: XenRT-Zone-0, proxy: v-2-VM, public IP: 10.220.166.18, private
IP: 10.220.165.114
> 2014-10-21 17:06:42,617 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-44:ctx-7d84e64c
job-547 ctx-dfce25f5) Complete async job-547, jobStatus: SUCCEEDED, resultCode: 0, result:
org.apache.cloudstack.api.response.SystemVmResponse/systemvm/{"id":"0d3261c0-18af-4f4f-8052-78398ea3d319","systemvmtype":"consoleproxy","zoneid":"32923188-631a-4b07-891b-b58cea6ad6ea","zonename":"XenRT-Zone-0","dns1":"10.220.160.11","gateway":"10.220.160.1","name":"v-2-VM","podid":"e96d1dd8-7ad4-45c1-b5be-8272cf0457e6","hostid":"ca2466c0-1866-4d5e-a744-379ab7838659","hostname":"cl09-A-08","hypervisor":"KVM","privateip":"10.220.165.114","privatemacaddress":"06:b8:96:00:00:02","privatenetmask":"255.255.240.0","linklocalip":"169.254.3.162","linklocalmacaddress":"0e:00:a9:fe:03:a2","linklocalnetmask":"255.255.0.0","publicip":"10.220.166.18","publicmacaddress":"06:8c:56:00:00:16","publicnetmask":"255.255.240.0","templateid":"cad1e542-5933-11e4-b66b-366937c763c7","created":"2014-10-21T15:27:32+0000","state":"Stopping","activeviewersessions":0}
> 2014-10-21 17:06:42,619 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-44:ctx-7d84e64c
job-547 ctx-dfce25f5) Publish async job-547 complete on message bus
> 2014-10-21 17:06:42,619 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-44:ctx-7d84e64c
job-547 ctx-dfce25f5) Wake up jobs related to job- 547
> 2014-10-21 17:06:42,619 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-44:ctx-7d84e64c
job-547 ctx-dfce25f5) Update db status for job- 547
> 2014-10-21 17:06:42,620 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-44:ctx-7d84e64c
job-547 ctx-dfce25f5) Wake up jobs joined with job- 547 and disjoin all subjobs created from
job- 547
> 2014-10-21 17:06:42,622 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-44:ctx-7d84e64c
job-547) Done executing org.apache.cloudstack.api.command.admin.systemvm.RebootSystemVmCmd
for job-547
> 2014-10-21 17:06:42,626 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-44:ctx-7d84e64c
job-547) Remove job-547 from job monitoring
> 2014-10-21 17:06:45,555 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-9f3a9300) ===START===
 10.220.135.30 -- GET  jobid=89c344f2-54de-40b7-b1ea-2a9f5b573a4e&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=queryAsyncJobResult&response=json&signature=9GRPDgWSdAC0UuqA0wooTnJ%2FMZc%3D
> 2014-10-21 17:06:45,580 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-9f3a9300 ctx-9ebd0eb1
ctx-129b5c4d) ===END===  10.220.135.30 -- GET  jobid=89c344f2-54de-40b7-b1ea-2a9f5b573a4e&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=queryAsyncJobResult&response=json&signature=9GRPDgWSdAC0UuqA0wooTnJ%2FMZc%3D
> 2014-10-21 17:06:45,586 DEBUG [c.c.a.ApiServlet] (catalina-exec-3:ctx-1dcb8d0a) ===START===
 10.220.135.30 -- GET  response=json&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=listSystemVms&id=0d3261c0-18af-4f4f-8052-78398ea3d319&signature=ggcw%2Fd7ZoFscmonFgxTTWGX5uyc%3D
> 2014-10-21 17:06:45,635 DEBUG [c.c.a.ApiServlet] (catalina-exec-3:ctx-1dcb8d0a ctx-cdaa7314
ctx-015ea415) ===END===  10.220.135.30 -- GET  response=json&apiKey=8zS-PDiww66KLa3apG55n-SpVbHRv7o4m1yTKiJTghk3NmbsfVAcE_Y1ymDuc-7huYpOW1Q221BgVCCQXcy_Zg&command=listSystemVms&id=0d3261c0-18af-4f4f-8052-78398ea3d319&signature=ggcw%2Fd7ZoFscmonFgxTTWGX5uyc%3D
> 2014-10-21 17:06:47,887 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null)
Ping from 2
> 2014-10-21 17:06:47,887 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null)
Process host VM state report from ping process. host: 2
> 2014-10-21 17:06:47,891 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null)
Process VM state report. host: 2, number of records in report: 2
> 2014-10-21 17:06:47,891 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null)
VM state report. host: 2, vm id: 1, power state: PowerOn
> 2014-10-21 17:06:47,895 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null)
VM state report is updated. host: 2, vm id: 1, power state: PowerOn
> 2014-10-21 17:06:47,900 DEBUG [c.c.c.CapacityManagerImpl] (AgentManager-Handler-14:null)
VM state transitted from :Running to Running with event: FollowAgentPowerOnReportvm's original
host id: 2 new host id: 2 host id before state transition: 2
> 2014-10-21 17:06:47,901 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null)
VM state report. host: 2, vm id: 2, power state: PowerOn
> 2014-10-21 17:06:47,903 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null)
VM power state does not change, skip DB writing. vm id: 2
> 2014-10-21 17:06:47,906 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null)
Done with process of VM state report. host: 2
> 2014-10-21 17:06:49,862 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:ctx-f9b42727)
Found 0 running routers. 
> 2014-10-21 17:06:49,868 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-4e93a5dc)
Found 0 routers to update status. 
> 2014-10-21 17:06:49,869 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-4e93a5dc)
Found 0 networks to update RvR status. 
> 2014-10-21 17:06:49,959 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-72bd0997)
External devices stats collector is running...
> 2014-10-21 17:06:49,963 INFO  [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-8823a15d)
Found 0 removed accounts to cleanup
> 2014-10-21 17:06:49,964 INFO  [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-8823a15d)
Found 0 disabled accounts to cleanup
> 2014-10-21 17:06:49,965 INFO  [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-8823a15d)
Found 0 inactive domains to cleanup
> 2014-10-21 17:06:49,966 INFO  [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-8823a15d)
Found 0 disabled projects to cleanup
> 2014-10-21 17:06:49,974 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-5b81523d)
Snapshot scheduler.poll is being called at 2014-10-21 17:06:49 GMT
> 2014-10-21 17:06:49,975 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-5b81523d)
Got 0 snapshots to be executed at 2014-10-21 17:06:49 GMT
> 2014-10-21 17:06:50,015 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-147bce4d)
Begin cleanup expired async-jobs
> 2014-10-21 17:06:50,020 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-147bce4d)
End cleanup expired async-jobs
> 2014-10-21 17:06:50,032 INFO  [c.c.h.HighAvailabilityManagerImpl] (HA-4:ctx-ac7c6374)
checking health of usage server
> 2014-10-21 17:06:50,033 DEBUG [c.c.h.HighAvailabilityManagerImpl] (HA-4:ctx-ac7c6374)
usage server running? false, heartbeat: null
> 2014-10-21 17:06:50,035 WARN  [o.a.c.alerts] (HA-4:ctx-ac7c6374)  alertType:: 13 // dataCenterId::
0 // podId:: 0 // clusterId:: null // message:: No usage server process running
> 2014-10-21 17:06:50,037 DEBUG [c.c.a.AlertManagerImpl] (HA-4:ctx-ac7c6374) Have already
sent: 1 emails for alert type '13' -- skipping send email
> 2014-10-21 17:06:51,042 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null)
Ping from 1
> 2014-10-21 17:06:51,043 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null)
Process host VM state report from ping process. host: 1
> 2014-10-21 17:06:51,045 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null)
Process VM state report. host: 1, number of records in report: 1
> 2014-10-21 17:06:51,045 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null)
VM state report. host: 1, vm id: 56, power state: PowerOn
> 2014-10-21 17:06:51,048 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null)
VM power state does not change, skip DB writing. vm id: 56
> 2014-10-21 17:06:51,050 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null)
Done with process of VM state report. host: 1
> 2014-10-21 17:06:54,987 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl] (Vm-Operations-Cleanup-1:ctx-1c80f4d4)
Expunge completed work job-431
> 2014-10-21 17:06:54,991 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl] (Vm-Operations-Cleanup-1:ctx-1c80f4d4)
Expunge completed work job-433
> 2014-10-21 17:06:54,996 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl] (Vm-Operations-Cleanup-1:ctx-1c80f4d4)
Expunge completed work job-434
> 2014-10-21 17:06:59,245 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-aee314ec)
HostStatsCollector is running...
> 2014-10-21 17:06:59,833 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-aee314ec) Seq 1-5688046329368937055:
Received:  { Ans: , MgmtId: 59825535280071, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer
} }
> 2014-10-21 17:06:59,982 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-d87cef3b)
LB HealthCheck Manager is running and getting the updates from LB providers and updating service
status
> 2014-10-21 17:06:59,995 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-d87cef3b)
LB HealthCheck Manager is running and getting the updates from LB providers and updating service
status
> 2014-10-21 17:07:00,015 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-09122581)
Begin cleanup expired async-jobs
> 2014-10-21 17:07:00,020 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-09122581)
End cleanup expired async-jobs
> 2014-10-21 17:07:00,433 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-aee314ec) Seq 2-7242632625741890166:
Received:  { Ans: , MgmtId: 59825535280071, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer
} }
> 2014-10-21 17:07:01,877 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-c9e7c76e)
Zone 1 is ready to launch secondary storage VM
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message