Details
-
Bug
-
Status: Open
-
Major
-
Resolution: Unresolved
-
4.8.0
-
None
-
Security Level: Public (Anyone can view this level - this is the default.)
-
None
-
Ubuntu 14.04
Description
Some time after creating a new VM it prompts me with following message: Unable to start a VM due to insufficient capacity.
I dunno exactly, but it seems like its fails because the start of the virtual router fails.
Would be nice, if anyone could give me a hint on whats going wrong.
agent.log (with DEBUG)
2016-06-22 14:25:21,020 DEBUG [kvm.resource.LibvirtConnection] (Thread-5:null) (logid Looking for libvirtd connection at: qemu:///system
2016-06-22 14:25:21,027 DEBUG [kvm.resource.KVMHAMonitor] (Thread-5:null) (logid Found NFS storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 in libvirt, continuing
2016-06-22 14:25:21,027 DEBUG [kvm.resource.KVMHAMonitor] (Thread-5:null) (logid Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 172.16.3.150 -p /primary -m /mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482 -h 172.16.3.150
2016-06-22 14:25:21,055 DEBUG [kvm.resource.KVMHAMonitor] (Thread-5:null) (logid Execution is successful.
2016-06-22 14:25:22,257 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-3:null) (logid Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms
2016-06-22 14:25:22,393 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-3:null) (logid Execution is successful.
2016-06-22 14:25:22,395 DEBUG [kvm.resource.LibvirtConnection] (UgentTask-3:null) (logid Looking for libvirtd connection at: qemu:///system
2016-06-22 14:25:22,421 DEBUG [cloud.agent.Agent] (UgentTask-3:null) (logid Sending ping: Seq 6-3: { Cmd , MgmtId: -1, via: 6, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"_hostVmStateReport":{"v-30-VM":
,"s-31-VM":{"state":"PowerOn","host":"testserver"}},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":6,"wait":0}}] }
2016-06-22 14:25:22,575 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null) (logid Received response: Seq 6-3: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":
,"result":true,"wait":0}}] }
2016-06-22 14:25:28,872 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:9b9aca0b) Processing command: com.cloud.agent.api.GetHostStatsCommand
2016-06-22 14:25:30,316 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:e3ec4fd2) Processing command: com.cloud.agent.api.GetStorageStatsCommand
2016-06-22 14:25:30,317 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:e3ec4fd2) Trying to fetch storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 from libvirt
2016-06-22 14:25:30,317 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-4:null) (logid:e3ec4fd2) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:25:30,334 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:e3ec4fd2) Asking libvirt to refresh storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482
2016-06-22 14:25:30,361 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:e3ec4fd2) Succesfully refreshed pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 Capacity: 1408689504256 Used: 11399069696 Available: 1397290434560
2016-06-22 14:25:50,989 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:9368758d) Request:Seq 6-2916643708675817487: { Cmd , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"88391c73-bba2-46f9-b4d8-5b24b42cf1ff","origUrl":"http://cloudstack.apt-get.eu/systemvm/4.6/systemvm64template-4.6.0-kvm.qcow2.bz2","uuid":"88391c73-bba2-46f9-b4d8-5b24b42cf1ff","id":3,"format":"QCOW2","accountId":1,"checksum":"c059b0d051e0cd6fbe9d5d4fc40c7e5d","hvm":false,"displayText":"SystemVM Template (KVM)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"bd3eb32c-10b0-33b1-8def-f4fb77a66482","id":1,"poolType":"NetworkFilesystem","host":"172.16.3.150","path":"/primary","port":2049,"url":"NetworkFilesystem://172.16.3.150/primary/?ROLE=Primary&STOREUUID=bd3eb32c-10b0-33b1-8def-f4fb77a66482"}},"name":"routing-3","hypervisorType":"KVM"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"853051c3-998f-466d-8eb2-8c2e1663c427","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"bd3eb32c-10b0-33b1-8def-f4fb77a66482","id":1,"poolType":"NetworkFilesystem","host":"172.16.3.150","path":"/primary","port":2049,"url":"NetworkFilesystem://172.16.3.150/primary/?ROLE=Primary&STOREUUID=bd3eb32c-10b0-33b1-8def-f4fb77a66482"}},"name":"ROOT-35","size":322954240,"volumeId":37,"vmName":"r-35-VM","accountId":1,"format":"QCOW2","provisioningType":"THIN","id":37,"deviceId":0,"hypervisorType":"KVM"}},"executeInSequence":true,"options":{},"options2":{},"wait":0}}] }
2016-06-22 14:25:50,989 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:9368758d) Processing command: org.apache.cloudstack.storage.command.CopyCommand
2016-06-22 14:25:50,992 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:9368758d) Trying to fetch storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 from libvirt
2016-06-22 14:25:50,992 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:25:51,026 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:9368758d) Succesfully refreshed pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 Capacity: 1408689504256 Used: 11399069696 Available: 1397290434560
2016-06-22 14:25:51,027 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:9368758d) Trying to fetch storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 from libvirt
2016-06-22 14:25:51,027 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:25:51,060 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:9368758d) Succesfully refreshed pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 Capacity: 1408689504256 Used: 11399069696 Available: 1397290434560
2016-06-22 14:25:51,080 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:9368758d) Creating volume 853051c3-998f-466d-8eb2-8c2e1663c427 from template 88391c73-bba2-46f9-b4d8-5b24b42cf1ff in pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 (NetworkFilesystem) with size 322954240
2016-06-22 14:25:51,081 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:9368758d) Attempting to create volume 853051c3-998f-466d-8eb2-8c2e1663c427 (NetworkFilesystem) in pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 with size 3145728000
2016-06-22 14:25:51,087 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) (logid:9368758d) Executing: qemu-img create -o preallocation=off -f qcow2 /mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482/853051c3-998f-466d-8eb2-8c2e1663c427 3145728000
2016-06-22 14:25:51,118 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) (logid:9368758d) Execution is successful.
2016-06-22 14:25:51,119 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) (logid:9368758d) Formatting '/mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482/853051c3-998f-466d-8eb2-8c2e1663c427', fmt=qcow2 size=3145728000 encryption=off cluster_size=65536 preallocation='off' lazy_refcounts=off
2016-06-22 14:25:51,120 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) (logid:9368758d) Executing: qemu-img info /mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482/853051c3-998f-466d-8eb2-8c2e1663c427
2016-06-22 14:25:51,144 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) (logid:9368758d) Execution is successful.
2016-06-22 14:25:51,148 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) (logid:9368758d) Executing: qemu-img create -o preallocation=off -f qcow2 -b /mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482/88391c73-bba2-46f9-b4d8-5b24b42cf1ff /mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482/853051c3-998f-466d-8eb2-8c2e1663c427 3145728000
2016-06-22 14:25:51,181 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) (logid:9368758d) Execution is successful.
2016-06-22 14:25:51,181 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) (logid:9368758d) Formatting '/mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482/853051c3-998f-466d-8eb2-8c2e1663c427', fmt=qcow2 size=3145728000 backing_file='/mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482/88391c73-bba2-46f9-b4d8-5b24b42cf1ff' encryption=off cluster_size=65536 preallocation='off' lazy_refcounts=off
2016-06-22 14:25:51,190 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:9368758d) Seq 6-2916643708675817487: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"size":322954240,"path":"853051c3-998f-466d-8eb2-8c2e1663c427","accountId":0,"format":"QCOW2","id":0}},"result":true,"wait":0}}] }
2016-06-22 14:25:51,942 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:9368758d) Request:Seq 6-2916643708675817488: { Cmd , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StartCommand":{"vm":{"id":35,"name":"r-35-VM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (64-bit)","platformEmulator":"Debian GNU/Linux 5","bootArgs":" template=domP name=r-35-VM eth0ip=172.16.3.175 eth0mask=255.255.255.0 gateway=172.16.3.1 domain=cs1cloud.internal cidrsize=24 dhcprange=172.16.3.1 eth1ip=169.254.2.27 eth1mask=255.255.0.0 type=dhcpsrvr disable_rp_filter=true dns1=8.8.8.8 dns2=8.8.4.4 baremetalnotificationsecuritykey=WckREvZhMQakhKLDgEXB3D1oZvEJc4Z6-zKkLfIxTrLizKya34nNSr5SSwxKqvfyKK59F4IkC6kDwtJnqUPGkA baremetalnotificationapikey=SP2qdUPUdLs8VUw8i-vcXug0AzkGbVX6du8s7hKUXtk7herzRoBvecZc0snm32UTfmwq9E4SqKjUJnGjUzyKTA host=172.16.3.150 port=8080","enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"iazFdyr0ZvQ5y5TFHYzkNg","params":{},"uuid":"6e7a79d6-b3f4-4fdd-ae1a-e98a1f16f4dc","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"853051c3-998f-466d-8eb2-8c2e1663c427","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"bd3eb32c-10b0-33b1-8def-f4fb77a66482","id":1,"poolType":"NetworkFilesystem","host":"172.16.3.150","path":"/primary","port":2049,"url":"NetworkFilesystem://172.16.3.150/primary/?ROLE=Primary&STOREUUID=bd3eb32c-10b0-33b1-8def-f4fb77a66482"}},"name":"ROOT-35","size":322954240,"path":"853051c3-998f-466d-8eb2-8c2e1663c427","volumeId":37,"vmName":"r-35-VM","accountId":1,"format":"QCOW2","provisioningType":"THIN","id":37,"deviceId":0,"hypervisorType":"KVM"}},"diskSeq":0,"path":"853051c3-998f-466d-8eb2-8c2e1663c427","type":"ROOT","_details":{"managed":"false","storagePort":"2049","storageHost":"172.16.3.150","volumeSize":"322954240"}}],"nics":[
,
{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"31cc00eb-3c7d-47f8-ab17-d322a3da2ff7","uuid":"b3def8e0-b87b-49b5-82d0-bb33f82f1b25","ip":"169.254.2.27","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:02:1b","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"hostIp":"172.16.3.150","executeInSequence":false,"wait":0}},{"com.cloud.agent.api.check.CheckSshCommand":{"ip":"169.254.2.27","port":3922,"interval":6,"retries":100,"name":"r-35-VM","wait":0}},{"com.cloud.agent.api.GetDomRVersionCmd":{"accessDetails":
{"router.ip":"169.254.2.27","router.name":"r-35-VM"},"wait":0}},{},{"com.cloud.agent.api.routing.AggregationControlCommand":{"action":"Start","accessDetails":
{"router.guest.ip":"172.16.3.175","router.ip":"169.254.2.27","router.name":"r-35-VM"},"wait":0}},{"com.cloud.agent.api.routing.SetMonitorServiceCommand":{"services":[
{"id":0,"service":"dhcp","processname":"dnsmasq","serviceName":"dnsmasq","servicePath":"/var/run/dnsmasq/dnsmasq.pid","pidFile":"/var/run/dnsmasq/dnsmasq.pid","isDefault":false},
{"id":0,"service":"ssh","processname":"sshd","serviceName":"ssh","servicePath":"/var/run/sshd.pid","pidFile":"/var/run/sshd.pid","isDefault":true},
{"id":0,"service":"webserver","processname":"apache2","serviceName":"apache2","servicePath":"/var/run/apache2.pid","pidFile":"/var/run/apache2.pid","isDefault":true}],"accessDetails":
{"router.guest.ip":"172.16.3.175","router.ip":"169.254.2.27","router.name":"r-35-VM"},"wait":0}},{"com.cloud.agent.api.routing.AggregationControlCommand":{"action":"Finish","accessDetails":
{"router.guest.ip":"172.16.3.175","router.ip":"169.254.2.27","router.name":"r-35-VM"},"wait":0}}] }
2016-06-22 14:25:51,943 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:9368758d) Processing command: com.cloud.agent.api.StartCommand
2016-06-22 14:25:51,969 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:25:51,972 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:9368758d) Trying to fetch storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 from libvirt
2016-06-22 14:25:51,972 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:25:51,995 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:9368758d) Succesfully refreshed pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 Capacity: 1408689504256 Used: 11399069696 Available: 1397290434560
2016-06-22 14:25:52,012 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:9368758d) Could not find volume 853051c3-998f-466d-8eb2-8c2e1663c427: Storage volume not found: no storage vol with matching name '853051c3-998f-466d-8eb2-8c2e1663c427'
2016-06-22 14:25:52,012 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:9368758d) Refreshing storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482
2016-06-22 14:25:52,026 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:9368758d) Found volume 853051c3-998f-466d-8eb2-8c2e1663c427 in storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 after refreshing the pool
2016-06-22 14:25:52,048 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:9368758d) Trying to fetch storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 from libvirt
2016-06-22 14:25:52,048 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:25:52,070 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:9368758d) Succesfully refreshed pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 Capacity: 1408689504256 Used: 11399069696 Available: 1397290434560
2016-06-22 14:25:52,071 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-1:null) (logid:9368758d) nic=[Nic:Guest-172.16.3.175-vlan://untagged]
2016-06-22 14:25:52,077 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-1:null) (logid:9368758d) nic=[Nic:Control-169.254.2.27-null]
2016-06-22 14:25:52,077 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:9368758d) Executing: /bin/bash -c ip route | grep 169.254.0.0/16
2016-06-22 14:25:52,087 DEBUG [utils.script.Script] (agentRequest-Handler-1:null) (logid:9368758d) Execution is successful.
2016-06-22 14:25:52,090 DEBUG [resource.wrapper.LibvirtStartCommandWrapper] (agentRequest-Handler-1:null) (logid:9368758d) starting r-35-VM: <domain type='kvm'>
<name>r-35-VM</name>
<uuid>6e7a79d6-b3f4-4fdd-ae1a-e98a1f16f4dc</uuid>
<description>Debian GNU/Linux 5.0 (64-bit)</description>
<clock offset='utc'>
<timer name='kvmclock' >
</timer>
</clock>
<features>
<pae/>
<apic/>
<acpi/>
</features>
<devices>
<emulator>/usr/bin/kvm-spice</emulator>
<interface type='bridge'>
<source bridge='cloudbr0'/>
<mac address='06:43:4c:00:00:19'/>
<model type='virtio'/>
<bandwidth>
<inbound average='25600' peak='25600'/>
<outbound average='25600' peak='25600'/>
</bandwidth>
<rom bar='off' file=''/></interface>
<interface type='bridge'>
<source bridge='cloud0'/>
<mac address='0e:00:a9:fe:02:1b'/>
<model type='virtio'/>
<rom bar='off' file=''/></interface>
<serial type='pty'>
<target port='0'/>
</serial>
<graphics type='vnc' autoport='yes' listen='172.16.3.150' passwd='iazFdyr0ZvQ5y5TFHYzkNg'/>
<disk device='disk' type='file'>
<driver name='qemu' type='qcow2' cache='none' />
<source file='/mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482/853051c3-998f-466d-8eb2-8c2e1663c427'/>
<target dev='vda' bus='virtio'/>
<serial>853051c3998f466d8eb2</serial></disk>
<disk device='cdrom' type='file'>
<driver name='qemu' type='raw' cache='none' />
<source file='/usr/share/cloudstack-common/vms/systemvm.iso'/>
<target dev='hdc' bus='ide'/>
</disk>
<console type='pty'>
<target port='0'/>
</console>
<input type='tablet' bus='usb'/>
<channel type='unix'>
<source mode='bind' path='/var/lib/libvirt/qemu/r-35-VM.agent'/>
<target type='virtio' name='r-35-VM.vport'/>
<address type='virtio-serial'/>
</channel>
</devices>
<memory>262144</memory>
<devices>
<memballoon model='none'/>
</devices>
<vcpu>1</vcpu>
<sysinfo type='smbios'>
<system>
<entry name='manufacturer'>Apache Software Foundation</entry>
<entry name='product'>CloudStack KVM Hypervisor</entry>
<entry name='uuid'>6e7a79d6-b3f4-4fdd-ae1a-e98a1f16f4dc</entry>
</system>
</sysinfo>
<os>
<type arch='x86_64' machine='pc'>hvm</type>
<boot dev='cdrom'/>
<boot dev='hd'/>
<smbios mode='sysinfo'/>
</os>
<cputune>
<shares>500</shares>
</cputune>
<cpu></cpu><on_reboot>restart</on_reboot>
<on_poweroff>destroy</on_poweroff>
<on_crash>destroy</on_crash>
</domain>
2016-06-22 14:25:52,853 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py default_network_rules_systemvm --vmname r-35-VM --localbrname cloud0
2016-06-22 14:25:53,008 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Execution is successful.
2016-06-22 14:25:53,010 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/patchviasocket.pl -n r-35-VM -p %template=domP%name=r-35-VM%eth0ip=172.16.3.175%eth0mask=255.255.255.0%gateway=172.16.3.1%domain=cs1cloud.internal%cidrsize=24%dhcprange=172.16.3.1%eth1ip=169.254.2.27%eth1mask=255.255.0.0%type=dhcpsrvr%disable_rp_filter=true%dns1=8.8.8.8%dns2=8.8.4.4%baremetalnotificationsecuritykey=WckREvZhMQakhKLDgEXB3D1oZvEJc4Z6-zKkLfIxTrLizKya34nNSr5SSwxKqvfyKK59F4IkC6kDwtJnqUPGkA%baremetalnotificationapikey=SP2qdUPUdLs8VUw8i-vcXug0AzkGbVX6du8s7hKUXtk7herzRoBvecZc0snm32UTfmwq9E4SqKjUJnGjUzyKTA%host=172.16.3.150%port=8080
2016-06-22 14:25:53,045 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Execution is successful.
2016-06-22 14:25:53,046 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) (logid:9368758d) Trying to connect to 169.254.2.27
2016-06-22 14:25:56,047 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) (logid:9368758d) Could not connect to 169.254.2.27
2016-06-22 14:26:01,049 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) (logid:9368758d) Trying to connect to 169.254.2.27
2016-06-22 14:26:03,051 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) (logid:9368758d) Could not connect to 169.254.2.27
2016-06-22 14:26:08,052 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) (logid:9368758d) Unable to logon to 169.254.2.27
2016-06-22 14:26:08,054 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/patchviasocket.pl -n r-35-VM -p %template=domP%name=r-35-VM%eth0ip=172.16.3.175%eth0mask=255.255.255.0%gateway=172.16.3.1%domain=cs1cloud.internal%cidrsize=24%dhcprange=172.16.3.1%eth1ip=169.254.2.27%eth1mask=255.255.0.0%type=dhcpsrvr%disable_rp_filter=true%dns1=8.8.8.8%dns2=8.8.4.4%baremetalnotificationsecuritykey=WckREvZhMQakhKLDgEXB3D1oZvEJc4Z6-zKkLfIxTrLizKya34nNSr5SSwxKqvfyKK59F4IkC6kDwtJnqUPGkA%baremetalnotificationapikey=SP2qdUPUdLs8VUw8i-vcXug0AzkGbVX6du8s7hKUXtk7herzRoBvecZc0snm32UTfmwq9E4SqKjUJnGjUzyKTA%host=172.16.3.150%port=8080
2016-06-22 14:26:08,093 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:08,095 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) (logid:9368758d) Trying to connect to 169.254.2.27
2016-06-22 14:26:21,058 DEBUG [kvm.resource.LibvirtConnection] (Thread-6:null) (logid Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:21,072 DEBUG [kvm.resource.KVMHAMonitor] (Thread-6:null) (logid Found NFS storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 in libvirt, continuing
2016-06-22 14:26:21,072 DEBUG [kvm.resource.KVMHAMonitor] (Thread-6:null) (logid Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 172.16.3.150 -p /primary -m /mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482 -h 172.16.3.150
2016-06-22 14:26:21,099 DEBUG [kvm.resource.KVMHAMonitor] (Thread-6:null) (logid Execution is successful.
2016-06-22 14:26:22,257 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-4:null) (logid Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms
2016-06-22 14:26:22,402 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-4:null) (logid Execution is successful.
2016-06-22 14:26:22,403 DEBUG [kvm.resource.LibvirtConnection] (UgentTask-4:null) (logid Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:22,429 DEBUG [cloud.agent.Agent] (UgentTask-4:null) (logid Sending ping: Seq 6-4: { Cmd , MgmtId: -1, via: 6, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"_hostVmStateReport":{"r-35-VM":
,"v-30-VM":
{"state":"PowerOn","host":"testserver"},"s-31-VM":{"state":"PowerOn","host":"testserver"}},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":6,"wait":0}}] }
2016-06-22 14:26:22,607 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null) (logid Received response: Seq 6-4: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":
,"result":true,"wait":0}}] }
2016-06-22 14:26:23,119 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) (logid:9368758d) Could not connect to 169.254.2.27
2016-06-22 14:26:28,120 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) (logid:9368758d) Trying to connect to 169.254.2.27
2016-06-22 14:26:28,123 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:9368758d) Processing command: com.cloud.agent.api.check.CheckSshCommand
2016-06-22 14:26:28,123 DEBUG [resource.wrapper.LibvirtOvsVpcRoutingPolicyConfigCommandWrapper] (agentRequest-Handler-1:null) (logid:9368758d) Ping command port, 169.254.2.27:3922
2016-06-22 14:26:28,124 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-1:null) (logid:9368758d) Trying to connect to 169.254.2.27
2016-06-22 14:26:28,125 DEBUG [resource.wrapper.LibvirtOvsVpcRoutingPolicyConfigCommandWrapper] (agentRequest-Handler-1:null) (logid:9368758d) Ping command port succeeded for vm r-35-VM
2016-06-22 14:26:28,125 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:9368758d) Processing command: com.cloud.agent.api.GetDomRVersionCmd
2016-06-22 14:26:28,136 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh get_template_version.sh 169.254.2.27
2016-06-22 14:26:28,266 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Exit value is 255
2016-06-22 14:26:28,268 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d)
2016-06-22 14:26:28,301 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:9368758d) Seq 6-2916643708675817488: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":35,"name":"r-35-VM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (64-bit)","platformEmulator":"Debian GNU/Linux 5","bootArgs":" template=domP name=r-35-VM eth0ip=172.16.3.175 eth0mask=255.255.255.0 gateway=172.16.3.1 domain=cs1cloud.internal cidrsize=24 dhcprange=172.16.3.1 eth1ip=169.254.2.27 eth1mask=255.255.0.0 type=dhcpsrvr disable_rp_filter=true dns1=8.8.8.8 dns2=8.8.4.4 baremetalnotificationsecuritykey=WckREvZhMQakhKLDgEXB3D1oZvEJc4Z6-zKkLfIxTrLizKya34nNSr5SSwxKqvfyKK59F4IkC6kDwtJnqUPGkA baremetalnotificationapikey=SP2qdUPUdLs8VUw8i-vcXug0AzkGbVX6du8s7hKUXtk7herzRoBvecZc0snm32UTfmwq9E4SqKjUJnGjUzyKTA host=172.16.3.150 port=8080","enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"iazFdyr0ZvQ5y5TFHYzkNg","vncAddr":"172.16.3.150","params":{},"uuid":"6e7a79d6-b3f4-4fdd-ae1a-e98a1f16f4dc","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"853051c3-998f-466d-8eb2-8c2e1663c427","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"bd3eb32c-10b0-33b1-8def-f4fb77a66482","id":1,"poolType":"NetworkFilesystem","host":"172.16.3.150","path":"/primary","port":2049,"url":"NetworkFilesystem://172.16.3.150/primary/?ROLE=Primary&STOREUUID=bd3eb32c-10b0-33b1-8def-f4fb77a66482"}},"name":"ROOT-35","size":322954240,"path":"853051c3-998f-466d-8eb2-8c2e1663c427","volumeId":37,"vmName":"r-35-VM","accountId":1,"format":"QCOW2","provisioningType":"THIN","id":37,"deviceId":0,"hypervisorType":"KVM"}},"diskSeq":0,"path":"853051c3-998f-466d-8eb2-8c2e1663c427","type":"ROOT","_details":{"managed":"false","storagePort":"2049","storageHost":"172.16.3.150","volumeSize":"322954240"}}],"nics":[
,
{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"31cc00eb-3c7d-47f8-ab17-d322a3da2ff7","uuid":"b3def8e0-b87b-49b5-82d0-bb33f82f1b25","ip":"169.254.2.27","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:02:1b","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"result":true,"wait":0}},{"com.cloud.agent.api.check.CheckSshAnswer":{"result":true,"wait":0}},{"com.cloud.agent.api.GetDomRVersionAnswer":{"result":false,"details":"GetDomRVersionCmd failed","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped by previous failure","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped by previous failure","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped by previous failure","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped by previous failure","wait":0}}] }
2016-06-22 14:26:28,442 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:9368758d) Request:Seq 6-2916643708675817489: { Cmd , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"r-35-VM","wait":0}}] }
2016-06-22 14:26:28,443 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:9368758d) Processing command: com.cloud.agent.api.StopCommand
2016-06-22 14:26:28,443 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:28,525 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname r-35-VM --vif vnet6
2016-06-22 14:26:28,761 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:28,762 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) Try to stop the vm at first
2016-06-22 14:26:28,917 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:51241c42) Processing command: com.cloud.agent.api.GetHostStatsCommand
2016-06-22 14:26:30,490 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:605ee4cb) Processing command: com.cloud.agent.api.GetStorageStatsCommand
2016-06-22 14:26:30,491 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:605ee4cb) Trying to fetch storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 from libvirt
2016-06-22 14:26:30,492 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-4:null) (logid:605ee4cb) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:30,504 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:605ee4cb) Asking libvirt to refresh storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482
2016-06-22 14:26:30,532 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:605ee4cb) Succesfully refreshed pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 Capacity: 1408689504256 Used: 11412701184 Available: 1397276803072
2016-06-22 14:26:34,785 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) successfully shut down vm r-35-VM
2016-06-22 14:26:34,786 DEBUG [utils.script.Script] (agentRequest-Handler-2:null) (logid:9368758d) Executing: /bin/bash -c ls /sys/class/net/cloudbr0
2016-06-22 14:26:34,796 DEBUG [utils.script.Script] (agentRequest-Handler-2:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:34,798 DEBUG [utils.script.Script] (agentRequest-Handler-2:null) (logid:9368758d) Executing: /bin/bash -c ls /sys/class/net/cloudbr0/brif | tr '
' ' '
2016-06-22 14:26:34,808 DEBUG [utils.script.Script] (agentRequest-Handler-2:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:34,810 DEBUG [utils.script.Script] (agentRequest-Handler-2:null) (logid:9368758d) Executing: /bin/bash -c ls /sys/class/net/cloud0
2016-06-22 14:26:34,819 DEBUG [utils.script.Script] (agentRequest-Handler-2:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:34,821 DEBUG [utils.script.Script] (agentRequest-Handler-2:null) (logid:9368758d) Executing: /bin/bash -c ls /sys/class/net/cloud0/brif | tr '
' ' '
2016-06-22 14:26:34,833 DEBUG [utils.script.Script] (agentRequest-Handler-2:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:34,838 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:9368758d) Seq 6-2916643708675817489: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2016-06-22 14:26:34,917 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:9368758d) Request:Seq 6-2916643708675817492: { Cmd , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"r-35-VM","wait":0}}] }
2016-06-22 14:26:34,918 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:9368758d) Processing command: com.cloud.agent.api.StopCommand
2016-06-22 14:26:34,918 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:34,924 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Can not find KVM connection for Instance: r-35-VM, continuing.
2016-06-22 14:26:34,925 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Looking for libvirtd connection at: lxc:///
2016-06-22 14:26:34,925 INFO [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) No existing libvirtd connection found. Opening a new one
2016-06-22 14:26:34,932 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Successfully connected to libvirt at: lxc:///
2016-06-22 14:26:34,936 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Can not find LXC connection for Instance: r-35-VM, continuing.
2016-06-22 14:26:34,937 WARN [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Can not find a connection for Instance r-35-VM. Assuming the default connection.
2016-06-22 14:26:34,937 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:34,943 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'r-35-VM'
2016-06-22 14:26:34,945 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'r-35-VM'
2016-06-22 14:26:34,949 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'r-35-VM'
2016-06-22 14:26:34,950 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname r-35-VM
2016-06-22 14:26:35,178 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:35,181 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Try to stop the vm at first
2016-06-22 14:26:35,185 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) VM r-35-VM doesn't exist, no need to stop it
2016-06-22 14:26:35,187 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:9368758d) Seq 6-2916643708675817492: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2016-06-22 14:26:35,730 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:9368758d) Request:Seq 6-2916643708675817493: { Cmd , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-34-VM","wait":0}}] }
2016-06-22 14:26:35,731 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:9368758d) Processing command: com.cloud.agent.api.StopCommand
2016-06-22 14:26:35,731 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:35,736 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:9368758d) Can not find KVM connection for Instance: i-2-34-VM, continuing.
2016-06-22 14:26:35,736 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:9368758d) Looking for libvirtd connection at: lxc:///
2016-06-22 14:26:35,741 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:9368758d) Can not find LXC connection for Instance: i-2-34-VM, continuing.
2016-06-22 14:26:35,741 WARN [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:9368758d) Can not find a connection for Instance i-2-34-VM. Assuming the default connection.
2016-06-22 14:26:35,741 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-1:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:35,746 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'i-2-34-VM'
2016-06-22 14:26:35,750 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'i-2-34-VM'
2016-06-22 14:26:35,752 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'i-2-34-VM'
2016-06-22 14:26:35,753 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname i-2-34-VM
2016-06-22 14:26:36,005 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:36,007 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) Try to stop the vm at first
2016-06-22 14:26:36,014 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) (logid:9368758d) VM i-2-34-VM doesn't exist, no need to stop it
2016-06-22 14:26:36,015 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) (logid:9368758d) Seq 6-2916643708675817493: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2016-06-22 14:26:38,462 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:9368758d) Request:Seq 6-2916643708675817494: { Cmd , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StartCommand":{"vm":{"id":35,"name":"r-35-VM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (64-bit)","platformEmulator":"Debian GNU/Linux 5","bootArgs":" template=domP name=r-35-VM eth0ip=172.16.3.175 eth0mask=255.255.255.0 gateway=172.16.3.1 domain=cs1cloud.internal cidrsize=24 dhcprange=172.16.3.1 eth1ip=169.254.0.205 eth1mask=255.255.0.0 type=dhcpsrvr disable_rp_filter=true dns1=8.8.8.8 dns2=8.8.4.4 baremetalnotificationsecuritykey=WckREvZhMQakhKLDgEXB3D1oZvEJc4Z6-zKkLfIxTrLizKya34nNSr5SSwxKqvfyKK59F4IkC6kDwtJnqUPGkA baremetalnotificationapikey=SP2qdUPUdLs8VUw8i-vcXug0AzkGbVX6du8s7hKUXtk7herzRoBvecZc0snm32UTfmwq9E4SqKjUJnGjUzyKTA host=172.16.3.150 port=8080","enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"iazFdyr0ZvQ5y5TFHYzkNg","params":{},"uuid":"6e7a79d6-b3f4-4fdd-ae1a-e98a1f16f4dc","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"853051c3-998f-466d-8eb2-8c2e1663c427","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"bd3eb32c-10b0-33b1-8def-f4fb77a66482","id":1,"poolType":"NetworkFilesystem","host":"172.16.3.150","path":"/primary","port":2049,"url":"NetworkFilesystem://172.16.3.150/primary/?ROLE=Primary&STOREUUID=bd3eb32c-10b0-33b1-8def-f4fb77a66482"}},"name":"ROOT-35","size":322954240,"path":"853051c3-998f-466d-8eb2-8c2e1663c427","volumeId":37,"vmName":"r-35-VM","accountId":1,"format":"QCOW2","provisioningType":"THIN","id":37,"deviceId":0,"hypervisorType":"KVM"}},"diskSeq":0,"path":"853051c3-998f-466d-8eb2-8c2e1663c427","type":"ROOT","_details":{"managed":"false","storagePort":"2049","storageHost":"172.16.3.150","volumeSize":"322954240"}}],"nics":[
,
{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"31cc00eb-3c7d-47f8-ab17-d322a3da2ff7","uuid":"b3def8e0-b87b-49b5-82d0-bb33f82f1b25","ip":"169.254.0.205","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:cd","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"hostIp":"172.16.3.150","executeInSequence":false,"wait":0}},{"com.cloud.agent.api.check.CheckSshCommand":{"ip":"169.254.0.205","port":3922,"interval":6,"retries":100,"name":"r-35-VM","wait":0}},{"com.cloud.agent.api.GetDomRVersionCmd":{"accessDetails":
{"router.ip":"169.254.0.205","router.name":"r-35-VM"},"wait":0}},{},{"com.cloud.agent.api.routing.AggregationControlCommand":{"action":"Start","accessDetails":
{"router.guest.ip":"172.16.3.175","router.ip":"169.254.0.205","router.name":"r-35-VM"},"wait":0}},{"com.cloud.agent.api.routing.SetMonitorServiceCommand":{"services":[
{"id":0,"service":"dhcp","processname":"dnsmasq","serviceName":"dnsmasq","servicePath":"/var/run/dnsmasq/dnsmasq.pid","pidFile":"/var/run/dnsmasq/dnsmasq.pid","isDefault":false},
{"id":0,"service":"ssh","processname":"sshd","serviceName":"ssh","servicePath":"/var/run/sshd.pid","pidFile":"/var/run/sshd.pid","isDefault":true},
{"id":0,"service":"webserver","processname":"apache2","serviceName":"apache2","servicePath":"/var/run/apache2.pid","pidFile":"/var/run/apache2.pid","isDefault":true}],"accessDetails":
{"router.guest.ip":"172.16.3.175","router.ip":"169.254.0.205","router.name":"r-35-VM"},"wait":0}},{"com.cloud.agent.api.routing.AggregationControlCommand":{"action":"Finish","accessDetails":
{"router.guest.ip":"172.16.3.175","router.ip":"169.254.0.205","router.name":"r-35-VM"},"wait":0}}] }
2016-06-22 14:26:38,463 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:9368758d) Processing command: com.cloud.agent.api.StartCommand
2016-06-22 14:26:38,463 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:38,465 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:9368758d) Trying to fetch storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 from libvirt
2016-06-22 14:26:38,465 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:38,494 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:9368758d) Succesfully refreshed pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 Capacity: 1408689504256 Used: 11412701184 Available: 1397276803072
2016-06-22 14:26:38,515 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:9368758d) Trying to fetch storage pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 from libvirt
2016-06-22 14:26:38,515 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-3:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:38,538 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:9368758d) Succesfully refreshed pool bd3eb32c-10b0-33b1-8def-f4fb77a66482 Capacity: 1408689504256 Used: 11412701184 Available: 1397276803072
2016-06-22 14:26:38,538 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-3:null) (logid:9368758d) nic=[Nic:Guest-172.16.3.175-vlan://untagged]
2016-06-22 14:26:38,538 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-3:null) (logid:9368758d) nic=[Nic:Control-169.254.0.205-null]
2016-06-22 14:26:38,538 DEBUG [utils.script.Script] (agentRequest-Handler-3:null) (logid:9368758d) Executing: /bin/bash -c ip route | grep 169.254.0.0/16
2016-06-22 14:26:38,546 DEBUG [utils.script.Script] (agentRequest-Handler-3:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:38,548 DEBUG [resource.wrapper.LibvirtStartCommandWrapper] (agentRequest-Handler-3:null) (logid:9368758d) starting r-35-VM: <domain type='kvm'>
<name>r-35-VM</name>
<uuid>6e7a79d6-b3f4-4fdd-ae1a-e98a1f16f4dc</uuid>
<description>Debian GNU/Linux 5.0 (64-bit)</description>
<clock offset='utc'>
<timer name='kvmclock' >
</timer>
</clock>
<features>
<pae/>
<apic/>
<acpi/>
</features>
<devices>
<emulator>/usr/bin/kvm-spice</emulator>
<interface type='bridge'>
<source bridge='cloudbr0'/>
<mac address='06:43:4c:00:00:19'/>
<model type='virtio'/>
<bandwidth>
<inbound average='25600' peak='25600'/>
<outbound average='25600' peak='25600'/>
</bandwidth>
<rom bar='off' file=''/></interface>
<interface type='bridge'>
<source bridge='cloud0'/>
<mac address='0e:00:a9:fe:00:cd'/>
<model type='virtio'/>
<rom bar='off' file=''/></interface>
<serial type='pty'>
<target port='0'/>
</serial>
<graphics type='vnc' autoport='yes' listen='172.16.3.150' passwd='iazFdyr0ZvQ5y5TFHYzkNg'/>
<disk device='disk' type='file'>
<driver name='qemu' type='qcow2' cache='none' />
<source file='/mnt/bd3eb32c-10b0-33b1-8def-f4fb77a66482/853051c3-998f-466d-8eb2-8c2e1663c427'/>
<target dev='vda' bus='virtio'/>
<serial>853051c3998f466d8eb2</serial></disk>
<disk device='cdrom' type='file'>
<driver name='qemu' type='raw' cache='none' />
<source file='/usr/share/cloudstack-common/vms/systemvm.iso'/>
<target dev='hdc' bus='ide'/>
</disk>
<console type='pty'>
<target port='0'/>
</console>
<input type='tablet' bus='usb'/>
<channel type='unix'>
<source mode='bind' path='/var/lib/libvirt/qemu/r-35-VM.agent'/>
<target type='virtio' name='r-35-VM.vport'/>
<address type='virtio-serial'/>
</channel>
</devices>
<memory>262144</memory>
<devices>
<memballoon model='none'/>
</devices>
<vcpu>1</vcpu>
<sysinfo type='smbios'>
<system>
<entry name='manufacturer'>Apache Software Foundation</entry>
<entry name='product'>CloudStack KVM Hypervisor</entry>
<entry name='uuid'>6e7a79d6-b3f4-4fdd-ae1a-e98a1f16f4dc</entry>
</system>
</sysinfo>
<os>
<type arch='x86_64' machine='pc'>hvm</type>
<boot dev='cdrom'/>
<boot dev='hd'/>
<smbios mode='sysinfo'/>
</os>
<cputune>
<shares>500</shares>
</cputune>
<cpu></cpu><on_reboot>restart</on_reboot>
<on_poweroff>destroy</on_poweroff>
<on_crash>destroy</on_crash>
</domain>
2016-06-22 14:26:39,243 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py default_network_rules_systemvm --vmname r-35-VM --localbrname cloud0
2016-06-22 14:26:39,415 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:39,416 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/patchviasocket.pl -n r-35-VM -p %template=domP%name=r-35-VM%eth0ip=172.16.3.175%eth0mask=255.255.255.0%gateway=172.16.3.1%domain=cs1cloud.internal%cidrsize=24%dhcprange=172.16.3.1%eth1ip=169.254.0.205%eth1mask=255.255.0.0%type=dhcpsrvr%disable_rp_filter=true%dns1=8.8.8.8%dns2=8.8.4.4%baremetalnotificationsecuritykey=WckREvZhMQakhKLDgEXB3D1oZvEJc4Z6-zKkLfIxTrLizKya34nNSr5SSwxKqvfyKK59F4IkC6kDwtJnqUPGkA%baremetalnotificationapikey=SP2qdUPUdLs8VUw8i-vcXug0AzkGbVX6du8s7hKUXtk7herzRoBvecZc0snm32UTfmwq9E4SqKjUJnGjUzyKTA%host=172.16.3.150%port=8080
2016-06-22 14:26:39,451 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:39,452 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) (logid:9368758d) Trying to connect to 169.254.0.205
2016-06-22 14:26:42,451 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) (logid:9368758d) Could not connect to 169.254.0.205
2016-06-22 14:26:47,452 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) (logid:9368758d) Trying to connect to 169.254.0.205
2016-06-22 14:26:48,451 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) (logid:9368758d) Could not connect to 169.254.0.205
2016-06-22 14:26:53,452 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) (logid:9368758d) Unable to logon to 169.254.0.205
2016-06-22 14:26:53,454 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/patchviasocket.pl -n r-35-VM -p %template=domP%name=r-35-VM%eth0ip=172.16.3.175%eth0mask=255.255.255.0%gateway=172.16.3.1%domain=cs1cloud.internal%cidrsize=24%dhcprange=172.16.3.1%eth1ip=169.254.0.205%eth1mask=255.255.0.0%type=dhcpsrvr%disable_rp_filter=true%dns1=8.8.8.8%dns2=8.8.4.4%baremetalnotificationsecuritykey=WckREvZhMQakhKLDgEXB3D1oZvEJc4Z6-zKkLfIxTrLizKya34nNSr5SSwxKqvfyKK59F4IkC6kDwtJnqUPGkA%baremetalnotificationapikey=SP2qdUPUdLs8VUw8i-vcXug0AzkGbVX6du8s7hKUXtk7herzRoBvecZc0snm32UTfmwq9E4SqKjUJnGjUzyKTA%host=172.16.3.150%port=8080
2016-06-22 14:26:53,498 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:53,500 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) (logid:9368758d) Trying to connect to 169.254.0.205
2016-06-22 14:26:53,501 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) (logid:9368758d) Could not connect to 169.254.0.205
2016-06-22 14:26:58,502 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) (logid:9368758d) Trying to connect to 169.254.0.205
2016-06-22 14:26:58,504 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:9368758d) Processing command: com.cloud.agent.api.check.CheckSshCommand
2016-06-22 14:26:58,504 DEBUG [resource.wrapper.LibvirtOvsVpcRoutingPolicyConfigCommandWrapper] (agentRequest-Handler-3:null) (logid:9368758d) Ping command port, 169.254.0.205:3922
2016-06-22 14:26:58,504 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-3:null) (logid:9368758d) Trying to connect to 169.254.0.205
2016-06-22 14:26:58,505 DEBUG [resource.wrapper.LibvirtOvsVpcRoutingPolicyConfigCommandWrapper] (agentRequest-Handler-3:null) (logid:9368758d) Ping command port succeeded for vm r-35-VM
2016-06-22 14:26:58,505 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:9368758d) Processing command: com.cloud.agent.api.GetDomRVersionCmd
2016-06-22 14:26:58,506 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh get_template_version.sh 169.254.0.205
2016-06-22 14:26:58,639 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:9368758d) Exit value is 255
2016-06-22 14:26:58,640 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) (logid:9368758d)
2016-06-22 14:26:58,668 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) (logid:9368758d) Seq 6-2916643708675817494: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":35,"name":"r-35-VM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (64-bit)","platformEmulator":"Debian GNU/Linux 5","bootArgs":" template=domP name=r-35-VM eth0ip=172.16.3.175 eth0mask=255.255.255.0 gateway=172.16.3.1 domain=cs1cloud.internal cidrsize=24 dhcprange=172.16.3.1 eth1ip=169.254.0.205 eth1mask=255.255.0.0 type=dhcpsrvr disable_rp_filter=true dns1=8.8.8.8 dns2=8.8.4.4 baremetalnotificationsecuritykey=WckREvZhMQakhKLDgEXB3D1oZvEJc4Z6-zKkLfIxTrLizKya34nNSr5SSwxKqvfyKK59F4IkC6kDwtJnqUPGkA baremetalnotificationapikey=SP2qdUPUdLs8VUw8i-vcXug0AzkGbVX6du8s7hKUXtk7herzRoBvecZc0snm32UTfmwq9E4SqKjUJnGjUzyKTA host=172.16.3.150 port=8080","enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"iazFdyr0ZvQ5y5TFHYzkNg","vncAddr":"172.16.3.150","params":{},"uuid":"6e7a79d6-b3f4-4fdd-ae1a-e98a1f16f4dc","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"853051c3-998f-466d-8eb2-8c2e1663c427","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"bd3eb32c-10b0-33b1-8def-f4fb77a66482","id":1,"poolType":"NetworkFilesystem","host":"172.16.3.150","path":"/primary","port":2049,"url":"NetworkFilesystem://172.16.3.150/primary/?ROLE=Primary&STOREUUID=bd3eb32c-10b0-33b1-8def-f4fb77a66482"}},"name":"ROOT-35","size":322954240,"path":"853051c3-998f-466d-8eb2-8c2e1663c427","volumeId":37,"vmName":"r-35-VM","accountId":1,"format":"QCOW2","provisioningType":"THIN","id":37,"deviceId":0,"hypervisorType":"KVM"}},"diskSeq":0,"path":"853051c3-998f-466d-8eb2-8c2e1663c427","type":"ROOT","_details":{"managed":"false","storagePort":"2049","storageHost":"172.16.3.150","volumeSize":"322954240"}}],"nics":[
,
{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"31cc00eb-3c7d-47f8-ab17-d322a3da2ff7","uuid":"b3def8e0-b87b-49b5-82d0-bb33f82f1b25","ip":"169.254.0.205","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:cd","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}]},"result":true,"wait":0}},{"com.cloud.agent.api.check.CheckSshAnswer":{"result":true,"wait":0}},{"com.cloud.agent.api.GetDomRVersionAnswer":{"result":false,"details":"GetDomRVersionCmd failed","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped by previous failure","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped by previous failure","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped by previous failure","wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"Stopped by previous failure","wait":0}}] }
2016-06-22 14:26:58,852 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:9368758d) Request:Seq 6-2916643708675817495: { Cmd , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"r-35-VM","wait":0}}] }
2016-06-22 14:26:58,853 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:9368758d) Processing command: com.cloud.agent.api.StopCommand
2016-06-22 14:26:58,853 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-4:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:26:58,915 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname r-35-VM --vif vnet6
2016-06-22 14:26:59,170 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) (logid:9368758d) Execution is successful.
2016-06-22 14:26:59,172 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) (logid:9368758d) Try to stop the vm at first
2016-06-22 14:27:05,195 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) (logid:9368758d) successfully shut down vm r-35-VM
2016-06-22 14:27:05,196 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:9368758d) Executing: /bin/bash -c ls /sys/class/net/cloudbr0
2016-06-22 14:27:05,205 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:9368758d) Execution is successful.
2016-06-22 14:27:05,207 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:9368758d) Executing: /bin/bash -c ls /sys/class/net/cloudbr0/brif | tr '
' ' '
2016-06-22 14:27:05,218 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:9368758d) Execution is successful.
2016-06-22 14:27:05,219 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:9368758d) Executing: /bin/bash -c ls /sys/class/net/cloud0
2016-06-22 14:27:05,225 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:9368758d) Execution is successful.
2016-06-22 14:27:05,226 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:9368758d) Executing: /bin/bash -c ls /sys/class/net/cloud0/brif | tr '
' ' '
2016-06-22 14:27:05,236 DEBUG [utils.script.Script] (agentRequest-Handler-4:null) (logid:9368758d) Execution is successful.
2016-06-22 14:27:05,238 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) (logid:9368758d) Seq 6-2916643708675817495: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2016-06-22 14:27:05,329 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:9368758d) Request:Seq 6-2916643708675817496: { Cmd , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"r-35-VM","wait":0}}] }
2016-06-22 14:27:05,329 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:9368758d) Processing command: com.cloud.agent.api.StopCommand
2016-06-22 14:27:05,330 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:27:05,335 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:9368758d) Can not find KVM connection for Instance: r-35-VM, continuing.
2016-06-22 14:27:05,336 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:9368758d) Looking for libvirtd connection at: lxc:///
2016-06-22 14:27:05,341 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:9368758d) Can not find LXC connection for Instance: r-35-VM, continuing.
2016-06-22 14:27:05,342 WARN [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:9368758d) Can not find a connection for Instance r-35-VM. Assuming the default connection.
2016-06-22 14:27:05,342 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:27:05,348 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'r-35-VM'
2016-06-22 14:27:05,352 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'r-35-VM'
2016-06-22 14:27:05,355 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'r-35-VM'
2016-06-22 14:27:05,355 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname r-35-VM
2016-06-22 14:27:05,581 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) Execution is successful.
2016-06-22 14:27:05,582 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) Try to stop the vm at first
2016-06-22 14:27:05,586 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) (logid:9368758d) VM r-35-VM doesn't exist, no need to stop it
2016-06-22 14:27:05,589 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) (logid:9368758d) Seq 6-2916643708675817496: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2016-06-22 14:27:06,084 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:9368758d) Request:Seq 6-2916643708675817497: { Cmd , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-34-VM","wait":0}}] }
2016-06-22 14:27:06,085 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:9368758d) Processing command: com.cloud.agent.api.StopCommand
2016-06-22 14:27:06,085 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:27:06,089 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Can not find KVM connection for Instance: i-2-34-VM, continuing.
2016-06-22 14:27:06,090 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Looking for libvirtd connection at: lxc:///
2016-06-22 14:27:06,094 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Can not find LXC connection for Instance: i-2-34-VM, continuing.
2016-06-22 14:27:06,094 WARN [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Can not find a connection for Instance i-2-34-VM. Assuming the default connection.
2016-06-22 14:27:06,094 DEBUG [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:9368758d) Looking for libvirtd connection at: qemu:///system
2016-06-22 14:27:06,098 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'i-2-34-VM'
2016-06-22 14:27:06,101 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'i-2-34-VM'
2016-06-22 14:27:06,105 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Failed to get dom xml: org.libvirt.LibvirtException: Domain not found: no domain with matching name 'i-2-34-VM'
2016-06-22 14:27:06,105 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py destroy_network_rules_for_vm --vmname i-2-34-VM
2016-06-22 14:27:06,355 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Execution is successful.
2016-06-22 14:27:06,357 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) Try to stop the vm at first
2016-06-22 14:27:06,361 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) (logid:9368758d) VM i-2-34-VM doesn't exist, no need to stop it
2016-06-22 14:27:06,363 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) (logid:9368758d) Seq 6-2916643708675817497: { Ans: , MgmtId: 161332502846, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }