You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Юрий Карпель <yu...@karpel.su> on 2016/01/24 09:20:36 UTC

Problem witch start systemvm

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