cloudstack 4.7, CentOS Linux release 7.2.1511 (managemet server and kvm),
libvirt 1.2.17-13.el7_2.2
vm state: Starting
Management server log:
2016-01-24 11:01:16,201 WARN [o.a.c.f.j.i.AsyncJobMonitor]
(Timer-1:ctx-e0047508) (logid:8efcba58) Task (job-319) has been pending for
329 seconds
KVM hist log:
2016-01-24 10:57:56,735 DEBUG
[resource.virtualnetwork.VirtualRoutingResource]
(agentRequest-Handler-4:null) (logid:5506e1b3) Could not connect to
169.254.2.228
2016-01-24 10:57:57,887 DEBUG
[resource.virtualnetwork.VirtualRoutingResource]
(agentRequest-Handler-2:null) (logid:48c87877) Could not connect to
169.254.3.17
2016-01-24 10:57:58,028 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) (logid:4edfd77c) Processing command:
com.cloud.agent.api.GetHostStatsCommand
2016-01-24 10:58:01,736 DEBUG
[resource.virtualnetwork.VirtualRoutingResource]
(agentRequest-Handler-4:null) (logid:5506e1b3) Trying to connect to
169.254.2.228
2016-01-24 10:58:02,888 DEBUG
[resource.virtualnetwork.VirtualRoutingResource]
(agentRequest-Handler-2:null) (logid:48c87877) Trying to connect to
169.254.3.17
2016-01-24 10:58:35,635 DEBUG [kvm.resource.LibvirtConnection]
(UgentTask-5:null) (logid:) Looking for libvirtd connection at:
qemu:///system
2016-01-24 10:58:35,642 DEBUG [cloud.agent.Agent] (UgentTask-5:null)
(logid:) Sending ping: Seq 4-7: { Cmd , MgmtId: -1, via: 4, Ver: v1,
Flags: 11,
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"_hostVmStateReport":{"v-15-VM":{"state":"PowerOn","host":"
srv-kvm01.cloud.bstelecom.ru"},"s-16-VM":{"state":"PowerOn","host":"
srv-kvm01.cloud.bstelecom.ru"}},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2016-01-24 10:58:35,801 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null)
(logid:) Received response: Seq 4-7: { Ans: , MgmtId: 90212275930085, via:
4, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
[root@srv-kvm01 ~]# iptables -L
Chain INPUT (policy ACCEPT)
target prot opt source destination
ACCEPT tcp -- anywhere anywhere tcp dpt:etp
ACCEPT tcp -- anywhere anywhere tcp
dpts:49152:49216
ACCEPT tcp -- anywhere anywhere tcp
dpts:rfb:synchronet-db
ACCEPT tcp -- anywhere anywhere tcp dpt:16509
ACCEPT tcp -- anywhere anywhere tcp dpt:ssh
Chain FORWARD (policy ACCEPT)
target prot opt source destination
Chain OUTPUT (policy ACCEPT)
target prot opt source destination
[root@srv-kvm01 ~]# virsh list
Id Name State
----------------------------------------------------
2 v-13-VM running
3 s-14-VM running
[root@srv-kvm01 ~]# ovs-vsctl
ovs-vsctl: missing command name (use --help for help)
[root@srv-kvm01 ~]# ovs-vsctl show
78f8df0f-88df-4283-8215-58fcb067c476
Bridge "cloud0"
Port "cloud0"
Interface "cloud0"
type: internal
Port "vnet0"
Interface "vnet0"
Port "vnet3"
Interface "vnet3"
Bridge "cloudbr0"
Port "vnet4"
tag: 1804
Interface "vnet4"
Port "stor0"
tag: 1806
Interface "stor0"
type: internal
Port "bond0"
Interface "enp6s0f0"
Interface "enp6s0f1"
Port "vnet5"
tag: 1500
Interface "vnet5"
Port "vnet2"
tag: 1500
Interface "vnet2"
Port "mgm0"
tag: 1804
Interface "mgm0"
type: internal
Port "vnet1"
tag: 1804
Interface "vnet1"
Port "cloudbr0"
Interface "cloudbr0"
type: internal
Port "vnet6"
tag: 1806
Interface "vnet6"
ovs_version: "2.4.0"
[root@srv-kvm01 ~]# virsh dumpxml v-15-VM
<domain type='kvm' id='5'>
<name>v-15-VM</name>
<uuid>229beb34-e68f-4611-81b3-d4df38d00568</uuid>
<description>Debian GNU/Linux 5.0 (64-bit)</description>
<memory unit='KiB'>1048576</memory>
<currentMemory unit='KiB'>1048576</currentMemory>
<vcpu placement='static'>1</vcpu>
<cputune>
<shares>500</shares>
</cputune>
<resource>
<partition>/machine</partition>
</resource>
<sysinfo type='smbios'>
<system>
<entry name='manufacturer'>Apache Software Foundation</entry>
<entry name='product'>CloudStack KVM Hypervisor</entry>
<entry name='uuid'>229beb34-e68f-4611-81b3-d4df38d00568</entry>
</system>
</sysinfo>
<os>
<type arch='x86_64' machine='pc-i440fx-rhel7.0.0'>hvm</type>
<boot dev='cdrom'/>
<boot dev='hd'/>
<smbios mode='sysinfo'/>
</os>
<features>
<acpi/>
<apic/>
<pae/>
</features>
<cpu mode='host-model'>
<model fallback='allow'/>
</cpu>
<clock offset='utc'>
<timer name='kvmclock'/>
</clock>
<on_poweroff>destroy</on_poweroff>
<on_reboot>restart</on_reboot>
<on_crash>destroy</on_crash>
<devices>
<emulator>/usr/libexec/qemu-kvm</emulator>
<disk type='network' device='disk'>
<driver name='qemu' type='raw' cache='none'/>
<auth username='libvirt'>
<secret type='ceph' uuid='7497e328-12d1-35f2-90af-a0df708e91fa'/>
</auth>
<source protocol='rbd'
name='ssd-cache/1da1e68e-0e90-45d9-8454-f9b3c8644590'>
<host name='ceph-mon.cloud.bstelecom.ru' port='6789'/>
</source>
<backingStore/>
<target dev='vda' bus='virtio'/>
<serial>1da1e68e0e9045d98454</serial>
<alias name='virtio-disk0'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x07'
function='0x0'/>
</disk>
<disk type='file' device='cdrom'>
<driver name='qemu' type='raw' cache='none'/>
<source file='/usr/share/cloudstack-common/vms/systemvm.iso'/>
<backingStore/>
<target dev='hdc' bus='ide'/>
<readonly/>
<alias name='ide0-1-0'/>
<address type='drive' controller='0' bus='1' target='0' unit='0'/>
</disk>
<controller type='usb' index='0'>
<alias name='usb'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x01'
function='0x2'/>
</controller>
<controller type='pci' index='0' model='pci-root'>
<alias name='pci.0'/>
</controller>
<controller type='ide' index='0'>
<alias name='ide'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x01'
function='0x1'/>
</controller>
<controller type='virtio-serial' index='0'>
<alias name='virtio-serial0'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x06'
function='0x0'/>
</controller>
<interface type='bridge'>
<mac address='0e:00:a9:fe:02:e4'/>
<source bridge='cloud0'/>
<virtualport type='openvswitch'>
<parameters interfaceid='5ed5bc27-d542-4857-bb04-25f27062501a'/>
</virtualport>
<target dev='vnet0'/>
<model type='virtio'/>
<alias name='net0'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x03'
function='0x0'/>
</interface>
<interface type='bridge'>
<mac address='06:ba:7a:00:00:15'/>
<source bridge='mgm0'/>
<virtualport type='openvswitch'>
<parameters interfaceid='624fc1de-273a-4c82-ad3c-d12f3cbe2166'/>
</virtualport>
<target dev='vnet1'/>
<model type='virtio'/>
<alias name='net1'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x04'
function='0x0'/>
</interface>
<interface type='bridge'>
<mac address='06:8a:42:00:00:38'/>
<source bridge='cloudbr0'/>
<vlan>
<tag id='1500'/>
</vlan>
<virtualport type='openvswitch'>
<parameters interfaceid='1c70ccc6-5e9c-4b4a-8169-4172bd7183d3'/>
</virtualport>
<target dev='vnet2'/>
<model type='virtio'/>
<alias name='net2'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x05'
function='0x0'/>
</interface>
<serial type='pty'>
<source path='/dev/pts/0'/>
<target port='0'/>
<alias name='serial0'/>
</serial>
<console type='pty' tty='/dev/pts/0'>
<source path='/dev/pts/0'/>
<target type='serial' port='0'/>
<alias name='serial0'/>
</console>
<channel type='unix'>
<source mode='bind' path='/var/lib/libvirt/qemu/v-15-VM.agent'/>
<target type='virtio' name='v-15-VM.vport' state='disconnected'/>
<alias name='channel0'/>
<address type='virtio-serial' controller='0' bus='0' port='1'/>
</channel>
<input type='tablet' bus='usb'>
<alias name='input0'/>
</input>
<input type='mouse' bus='ps2'/>
<input type='keyboard' bus='ps2'/>
<graphics type='vnc' port='5900' autoport='yes' listen='10.30.10.50'>
<listen type='address' address='10.30.10.50'/>
</graphics>
<video>
<model type='cirrus' vram='16384' heads='1'/>
<alias name='video0'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x02'
function='0x0'/>
</video>
<memballoon model='none'>
<alias name='balloon0'/>
</memballoon>
</devices>
</domain>
*systemctl restart libvirtd.service*
2016-01-24 11:06:40,084 WARN [c.c.h.HighAvailabilityManagerImpl]
(HA-Worker-4:ctx-ba5c4a1b work-25) (logid:f34d095b) Encountered unhandled
exception during HA process, reschedule work
com.cloud.utils.exception.CloudRuntimeException: We cannot stop
VM[ConsoleProxy|v-15-VM] when it is in state Starting
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1486)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1427)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:4590)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4734)
at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:502)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2016-01-24 11:06:40,358 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-ab157623) (logid:ec8b490d) Zone 4 is not ready to launch
secondary storage VM yet
2016-01-24 11:06:40,363 INFO [c.c.v.VirtualMachineManagerImpl]
(AgentManager-Handler-11:null) (logid:) VM s-16-VM is sync-ed to at Running
state according to power-on report from hypervisor
2016-01-24 11:06:40,369 WARN [o.a.c.alerts] (AgentManager-Handler-11:null)
(logid:) alertType:: 27 // dataCenterId:: 4 // podId:: 4 // clusterId::
null // message:: VM state sync alert
2016-01-24 11:06:40,400 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-76297900) (logid:73760be1) Zone 4 is not ready to launch
secondary storage VM yet
2016-01-24 11:06:40,404 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-11:null) (logid:) VM state report. host: 4, vm id:
15, power state: PowerOn
2016-01-24 11:06:40,424 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-11:null) (logid:) VM state report is updated. host:
4, vm id: 15, power state: PowerOn
2016-01-24 11:06:40,447 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-dc0b5293) (logid:ae2e8db2) Zone 4 is not ready to launch
secondary storage VM yet
2016-01-24 11:06:40,449 INFO [c.c.v.VirtualMachineManagerImpl]
(AgentManager-Handler-11:null) (logid:) VM v-15-VM is at Starting and we
received a power-on report while there is no pending jobs on it
2016-01-24 11:06:40,461 DEBUG [c.c.a.t.Request]
(AgentManager-Handler-5:null) (logid:) Seq 4-327636872891203585:
Processing: { Ans: , MgmtId: 90212275930085, via: 4, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":true,"details":"","wait":0}}] }
2016-01-24 11:06:40,483 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-eca02336) (logid:381ce40e) Zone 4 is not ready to launch
secondary storage VM yet
2016-01-24 11:06:40,484 DEBUG [c.c.c.CapacityManagerImpl]
(AgentManager-Handler-11:null) (logid:) VM state transitted from :Starting
to Running with event: FollowAgentPowerOnReportvm's original host id: null
new host id: 4 host id before state transition: 4
