cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Fabian Dellwing (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CLOUDSTACK-9421) Cannot add Instance
Date Wed, 22 Jun 2016 12:40:57 GMT

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-9421?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Fabian Dellwing updated CLOUDSTACK-9421:
----------------------------------------
    Attachment: cloudstack1

Screenshot

> Cannot add Instance
> -------------------
>
>                 Key: CLOUDSTACK-9421
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-9421
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: ISO, KVM, Virtual Router
>    Affects Versions: 4.8.0
>         Environment: Ubuntu 14.04
>            Reporter: Fabian Dellwing
>         Attachments: agent.log, cloudstack1
>
>
> 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":{"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: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":{"hostType":"Routing","hostId":6,"wait":0},"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":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e17f1d0-26a6-4477-8187-6bd80a314739","uuid":"685d2965-7786-4a10-8803-74a33d4f1843","ip":"172.16.3.175","netmask":"255.255.255.0","gateway":"172.16.3.1","mac":"06:43:4c:00:00:19","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSecurityGroupEnabled":true},{"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":{"state":"PowerOn","host":"testserver"},"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":{"hostType":"Routing","hostId":6,"wait":0},"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":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e17f1d0-26a6-4477-8187-6bd80a314739","uuid":"685d2965-7786-4a10-8803-74a33d4f1843","ip":"172.16.3.175","netmask":"255.255.255.0","gateway":"172.16.3.1","mac":"06:43:4c:00:00:19","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSecurityGroupEnabled":true},{"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":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e17f1d0-26a6-4477-8187-6bd80a314739","uuid":"685d2965-7786-4a10-8803-74a33d4f1843","ip":"172.16.3.175","netmask":"255.255.255.0","gateway":"172.16.3.1","mac":"06:43:4c:00:00:19","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSecurityGroupEnabled":true},{"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":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e17f1d0-26a6-4477-8187-6bd80a314739","uuid":"685d2965-7786-4a10-8803-74a33d4f1843","ip":"172.16.3.175","netmask":"255.255.255.0","gateway":"172.16.3.1","mac":"06:43:4c:00:00:19","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSecurityGroupEnabled":true},{"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}}] }



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

Mime
View raw message