[
https://issues.apache.org/jira/browse/CLOUDSTACK-9475?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
John Burwell updated CLOUDSTACK-9475:
-------------------------------------
Description:
When restarting a VR using a PVLAN on a VMware dvSwitch, the VR fails to
attach. An inspection of logs reveals that the cause is the following
ClassCastException:
{code}
java.lang.ClassCastException:
com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be cast to
com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
2016-08-24 08:53:01,259 DEBUG [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Prepare volume at new device
{"capacityInKB":0,"key":-2,"backing":{"diskMode":"persistent","fileName":"[90b2ea22317f3a16b696cf32ae35387f]
r-18-VM/ROOT-18.vmdk","datastore":{"value":"datastore-11324","type":"Datastore"}},"connectable":{"startConnected":true,"allowGuestControl":false,"connected":true},"controllerKey":1000,"unitNumber":0}
2016-08-24 08:53:01,259 DEBUG [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) VM r-18-VM will be started with NIC device
type: E1000
2016-08-24 08:53:01,259 INFO [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Prepare NIC device based on NicTO:
{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e5c5fb9-e9be-4f7b-bb6e-43a94fcdda11","uuid":"eef6de62-85ff-47f4-b916-0a237cfa51d9","ip":"192.168.20.10","netmask":"255.255.255.0","gateway":"192.168.20.1","mac":"06:8c:66:00:01:35","dns1":"10.220.90.107","dns2":"10.220.98.107","broadcastType":"Pvlan","type":"Guest","broadcastUri":"pvlan://1900-i1901","isolationUri":"vlan://1900","isSecurityGroupEnabled":false,"name":"extdvs,,vmwaredvs"}
2016-08-24 08:53:01,267 INFO [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Prepare network on vmwaredvs extdvs with
name prefix: cloud.guest
2016-08-24 08:53:01,310 INFO [c.c.h.v.m.HypervisorHostHelper]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Found Distributed Virtual Port group
cloud.guest.1900.s1900.200.1-extdvs
2016-08-24 08:53:01,341 DEBUG [c.c.h.v.m.HypervisorHostHelper]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Checking if configuration of dvPortGroup
[cloud.guest.1900.s1900.200.1-extdvs] has changed.
2016-08-24 08:53:01,341 INFO [c.c.h.v.u.VmwareHelper]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) [ignored]failed toi get message for
exception: com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be
cast to com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
2016-08-24 08:53:01,376 WARN [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) StartCommand failed due to Exception:
java.lang.ClassCastException
Message: com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be
cast to com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
java.lang.ClassCastException:
com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be cast to
com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
at
com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.isSpecMatch(HypervisorHostHelper.java:836)
at
com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.createPortGroup(HypervisorHostHelper.java:729)
at
com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.prepareNetwork(HypervisorHostHelper.java:547)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.prepareNetworkFromNicInfo(VmwareResource.java:2667)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1813)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:450)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:302)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2016-08-24 08:53:01,378 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-171:ctx-4979098f) Seq 1-8381198906536498178: Cancelling because
one of the answers is false and it is stop on error.
2016-08-24 08:53:01,378 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-171:ctx-4979098f) Seq 1-8381198906536498178: Response Received:
2016-08-24 08:53:01,379 DEBUG [c.c.a.t.Request] (DirectAgent-171:ctx-4979098f)
Seq 1-8381198906536498178: Processing: { Ans: , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":18,"name":"r-18-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"hostName":"r-18-VM","arch":"x86_64","os":"Debian
GNU/Linux 5.0 (64-bit)","platformEmulator":"debian5Guest","bootArgs":"
template=domP name=r-18-VM eth0ip=192.168.20.10 eth0mask=255.255.255.0
gateway=192.168.20.1 domain=guest.vdc cidrsize=24 dhcprange=192.168.20.1
eth1ip=10.220.88.156 eth1mask=255.255.255.0 mgmtcidr=10.220.0.0/16
localgw=10.220.88.254 type=dhcpsrvr disable_rp_filter=true extra_pubnics=2
dns1=10.220.90.107 dns2=10.220.98.107
baremetalnotificationsecuritykey=6U0RW2iZI8feq96HIXwqfSrNCEQQKydW9DI3KPAaqRK7WKtlzOkeYx4gEPrutQAdEqjYI8mcnuSfEoRgoXm12Q
baremetalnotificationapikey=cOJIV9t57rHsswQBdmjdhZVcoKpCxBfLUXEAx96kwlDjDcRqwM_fs8TJqHkkyWKLxprTvCWmG2hImftYNancdg
host=vdc-lablon12-cpman1.lablon12.cp.vdc port=8080
nic_macs=06:8c:66:00:01:35|02:00:61:81:00:07","enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"v71e3kK7x0vmPBc6cOs9pw","params":{"vmware.reserve.cpu":"false","nicAdapter":"E1000","vmware.reserve.mem":"false"},"uuid":"61793ca9-2a53-4438-8721-e36f9053447f","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"6453a5fa-831c-4532-99c7-0659e37ff026","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"90b2ea22-317f-3a16-b696-cf32ae35387f","id":1,"poolType":"NetworkFilesystem","host":"vdc-lablon12-sa01.nfs.lablon12.cp.vdc","path":"/vol/LABLON12_VMS40_HDD1","port":2049,"url":"NetworkFilesystem://vdc-lablon12-sa01.nfs.lablon12.cp.vdc/vol/LABLON12_VMS40_HDD1/?ROLE=Primary&STOREUUID=90b2ea22-317f-3a16-b696-cf32ae35387f"}},"name":"ROOT-18","size":3145728000,"path":"ROOT-18","volumeId":22,"vmName":"r-18-VM","accountId":1,"format":"OVA","provisioningType":"THIN","id":22,"deviceId":0,"hypervisorType":"VMware"}},"diskSeq":0,"path":"ROOT-18","type":"ROOT","_details":{"storageHost":"vdc-lablon12-sa01.nfs.lablon12.cp.vdc","managed":"false","storagePort":"2049","volumeSize":"3145728000"}}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e5c5fb9-e9be-4f7b-bb6e-43a94fcdda11","uuid":"eef6de62-85ff-47f4-b916-0a237cfa51d9","ip":"192.168.20.10","netmask":"255.255.255.0","gateway":"192.168.20.1","mac":"06:8c:66:00:01:35","dns1":"10.220.90.107","dns2":"10.220.98.107","broadcastType":"Pvlan","type":"Guest","broadcastUri":"pvlan://1900-i1901","isolationUri":"vlan://1900","isSecurityGroupEnabled":false,"name":"extdvs,,vmwaredvs"},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"ecc7cea9-bee5-4aa0-a9c5-91ad3de01358","uuid":"0b709cbb-59aa-4c4e-b351-69cc817122c8","ip":"10.220.88.156","netmask":"255.255.255.0","gateway":"10.220.88.254","mac":"02:00:61:81:00:07","broadcastType":"Native","type":"Control","isSecurityGroupEnabled":false,"name":"extdvs,1211,vmwaredvs"}]},"result":false,"details":"StartCommand
failed due to Exception: java.lang.ClassCastException\nMessage:
com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be cast to
com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec\n","wait":0}}] }
2016-08-24 08:53:01,379 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
1-8381198906536498178: Received: { Ans: , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10, { StartAnswer } }
2016-08-24 08:53:01,394 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Unable to
start VM on Host[-1-Routing] due to StartCommand failed due to Exception:
java.lang.ClassCastException
Message: com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be
cast to com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
2016-08-24 08:53:01,402 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Cleaning up
resources for the vm VM[DomainRouter|r-18-VM] in Starting state
2016-08-24 08:53:01,411 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
1-8381198906536498179: Sending { Cmd , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName":"r-18-VM","wait":0}}]
}
2016-08-24 08:53:01,411 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
1-8381198906536498179: Executing: { Cmd , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName":"r-18-VM","wait":0}}]
}
2016-08-24 08:53:01,411 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-341:ctx-c0b6184d) Seq 1-8381198906536498179: Executing request
2016-08-24 08:53:01,411 INFO [c.c.h.v.r.VmwareResource]
(DirectAgent-341:ctx-c0b6184d vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StopCommand) Executing resource StopCommand:
{"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName":"r-18-VM","wait":0}
2016-08-24 08:53:01,444 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-341:ctx-c0b6184d
vdc-lablon12-vh06.lablon12.cp.vdc, job-141/job-144, cmd: StopCommand) find VM
r-18-VM on host
2016-08-24 08:53:01,444 INFO [c.c.h.v.m.HostMO] (DirectAgent-341:ctx-c0b6184d
vdc-lablon12-vh06.lablon12.cp.vdc, job-141/job-144, cmd: StopCommand) VM
r-18-VM not found in host cache
2016-08-24 08:53:01,444 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-341:ctx-c0b6184d
vdc-lablon12-vh06.lablon12.cp.vdc, job-141/job-144, cmd: StopCommand) load VM
cache on host
2016-08-24 08:53:01,471 INFO [c.c.h.v.r.VmwareResource]
(DirectAgentCronJob-320:ctx-4af48a10) Scan hung worker VM to recycle
2016-08-24 08:53:01,543 INFO [c.c.h.v.r.VmwareResource]
(DirectAgent-341:ctx-c0b6184d vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StopCommand) VM r-18-VM is already in stopped state
2016-08-24 08:53:01,543 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-341:ctx-c0b6184d) Seq 1-8381198906536498179: Response Received:
2016-08-24 08:53:01,543 DEBUG [c.c.a.t.Request] (DirectAgent-341:ctx-c0b6184d)
Seq 1-8381198906536498179: Processing: { Ans: , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM r-18-VM is
already in stopped state","wait":0}}] }
2016-08-24 08:53:01,544 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
1-8381198906536498179: Received: { Ans: , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10, { StopAnswer } }
2016-08-24 08:53:01,555 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Successfully
updated user statistics as a part of domR VM[DomainRouter|r-18-VM] reboot/stop
2016-08-24 08:53:01,563 DEBUG [o.a.c.n.t.AdvancedNetworkTopology]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) SETUP DHCP
PVLAN RULES
2016-08-24 08:53:01,576 DEBUG [c.c.n.r.NetworkHelperImpl]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Router
requires upgrade. Unable to send command to router:18, router template version
: null, minimal required version : 4.6.0
{code}
was:
When restarting a VR using a PVLAN on a VMware dvSwitch, the VR fails to
attach. An inspection of logs reveals that the cause is the following
ClassCastException:
{unformatted}
java.lang.ClassCastException:
com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be cast to
com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
2016-08-24 08:53:01,259 DEBUG [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Prepare volume at new device
{"capacityInKB":0,"key":-2,"backing":{"diskMode":"persistent","fileName":"[90b2ea22317f3a16b696cf32ae35387f]
r-18-VM/ROOT-18.vmdk","datastore":{"value":"datastore-11324","type":"Datastore"}},"connectable":{"startConnected":true,"allowGuestControl":false,"connected":true},"controllerKey":1000,"unitNumber":0}
2016-08-24 08:53:01,259 DEBUG [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) VM r-18-VM will be started with NIC device
type: E1000
2016-08-24 08:53:01,259 INFO [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Prepare NIC device based on NicTO:
{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e5c5fb9-e9be-4f7b-bb6e-43a94fcdda11","uuid":"eef6de62-85ff-47f4-b916-0a237cfa51d9","ip":"192.168.20.10","netmask":"255.255.255.0","gateway":"192.168.20.1","mac":"06:8c:66:00:01:35","dns1":"10.220.90.107","dns2":"10.220.98.107","broadcastType":"Pvlan","type":"Guest","broadcastUri":"pvlan://1900-i1901","isolationUri":"vlan://1900","isSecurityGroupEnabled":false,"name":"extdvs,,vmwaredvs"}
2016-08-24 08:53:01,267 INFO [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Prepare network on vmwaredvs extdvs with
name prefix: cloud.guest
2016-08-24 08:53:01,310 INFO [c.c.h.v.m.HypervisorHostHelper]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Found Distributed Virtual Port group
cloud.guest.1900.s1900.200.1-extdvs
2016-08-24 08:53:01,341 DEBUG [c.c.h.v.m.HypervisorHostHelper]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) Checking if configuration of dvPortGroup
[cloud.guest.1900.s1900.200.1-extdvs] has changed.
2016-08-24 08:53:01,341 INFO [c.c.h.v.u.VmwareHelper]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) [ignored]failed toi get message for
exception: com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be
cast to com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
2016-08-24 08:53:01,376 WARN [c.c.h.v.r.VmwareResource]
(DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StartCommand) StartCommand failed due to Exception:
java.lang.ClassCastException
Message: com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be
cast to com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
java.lang.ClassCastException:
com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be cast to
com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
at
com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.isSpecMatch(HypervisorHostHelper.java:836)
at
com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.createPortGroup(HypervisorHostHelper.java:729)
at
com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.prepareNetwork(HypervisorHostHelper.java:547)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.prepareNetworkFromNicInfo(VmwareResource.java:2667)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1813)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:450)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:302)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2016-08-24 08:53:01,378 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-171:ctx-4979098f) Seq 1-8381198906536498178: Cancelling because
one of the answers is false and it is stop on error.
2016-08-24 08:53:01,378 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-171:ctx-4979098f) Seq 1-8381198906536498178: Response Received:
2016-08-24 08:53:01,379 DEBUG [c.c.a.t.Request] (DirectAgent-171:ctx-4979098f)
Seq 1-8381198906536498178: Processing: { Ans: , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":18,"name":"r-18-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"hostName":"r-18-VM","arch":"x86_64","os":"Debian
GNU/Linux 5.0 (64-bit)","platformEmulator":"debian5Guest","bootArgs":"
template=domP name=r-18-VM eth0ip=192.168.20.10 eth0mask=255.255.255.0
gateway=192.168.20.1 domain=guest.vdc cidrsize=24 dhcprange=192.168.20.1
eth1ip=10.220.88.156 eth1mask=255.255.255.0 mgmtcidr=10.220.0.0/16
localgw=10.220.88.254 type=dhcpsrvr disable_rp_filter=true extra_pubnics=2
dns1=10.220.90.107 dns2=10.220.98.107
baremetalnotificationsecuritykey=6U0RW2iZI8feq96HIXwqfSrNCEQQKydW9DI3KPAaqRK7WKtlzOkeYx4gEPrutQAdEqjYI8mcnuSfEoRgoXm12Q
baremetalnotificationapikey=cOJIV9t57rHsswQBdmjdhZVcoKpCxBfLUXEAx96kwlDjDcRqwM_fs8TJqHkkyWKLxprTvCWmG2hImftYNancdg
host=vdc-lablon12-cpman1.lablon12.cp.vdc port=8080
nic_macs=06:8c:66:00:01:35|02:00:61:81:00:07","enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"v71e3kK7x0vmPBc6cOs9pw","params":{"vmware.reserve.cpu":"false","nicAdapter":"E1000","vmware.reserve.mem":"false"},"uuid":"61793ca9-2a53-4438-8721-e36f9053447f","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"6453a5fa-831c-4532-99c7-0659e37ff026","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"90b2ea22-317f-3a16-b696-cf32ae35387f","id":1,"poolType":"NetworkFilesystem","host":"vdc-lablon12-sa01.nfs.lablon12.cp.vdc","path":"/vol/LABLON12_VMS40_HDD1","port":2049,"url":"NetworkFilesystem://vdc-lablon12-sa01.nfs.lablon12.cp.vdc/vol/LABLON12_VMS40_HDD1/?ROLE=Primary&STOREUUID=90b2ea22-317f-3a16-b696-cf32ae35387f"}},"name":"ROOT-18","size":3145728000,"path":"ROOT-18","volumeId":22,"vmName":"r-18-VM","accountId":1,"format":"OVA","provisioningType":"THIN","id":22,"deviceId":0,"hypervisorType":"VMware"}},"diskSeq":0,"path":"ROOT-18","type":"ROOT","_details":{"storageHost":"vdc-lablon12-sa01.nfs.lablon12.cp.vdc","managed":"false","storagePort":"2049","volumeSize":"3145728000"}}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e5c5fb9-e9be-4f7b-bb6e-43a94fcdda11","uuid":"eef6de62-85ff-47f4-b916-0a237cfa51d9","ip":"192.168.20.10","netmask":"255.255.255.0","gateway":"192.168.20.1","mac":"06:8c:66:00:01:35","dns1":"10.220.90.107","dns2":"10.220.98.107","broadcastType":"Pvlan","type":"Guest","broadcastUri":"pvlan://1900-i1901","isolationUri":"vlan://1900","isSecurityGroupEnabled":false,"name":"extdvs,,vmwaredvs"},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"ecc7cea9-bee5-4aa0-a9c5-91ad3de01358","uuid":"0b709cbb-59aa-4c4e-b351-69cc817122c8","ip":"10.220.88.156","netmask":"255.255.255.0","gateway":"10.220.88.254","mac":"02:00:61:81:00:07","broadcastType":"Native","type":"Control","isSecurityGroupEnabled":false,"name":"extdvs,1211,vmwaredvs"}]},"result":false,"details":"StartCommand
failed due to Exception: java.lang.ClassCastException\nMessage:
com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be cast to
com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec\n","wait":0}}] }
2016-08-24 08:53:01,379 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
1-8381198906536498178: Received: { Ans: , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10, { StartAnswer } }
2016-08-24 08:53:01,394 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Unable to
start VM on Host[-1-Routing] due to StartCommand failed due to Exception:
java.lang.ClassCastException
Message: com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be
cast to com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
2016-08-24 08:53:01,402 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Cleaning up
resources for the vm VM[DomainRouter|r-18-VM] in Starting state
2016-08-24 08:53:01,411 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
1-8381198906536498179: Sending { Cmd , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName":"r-18-VM","wait":0}}]
}
2016-08-24 08:53:01,411 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
1-8381198906536498179: Executing: { Cmd , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName":"r-18-VM","wait":0}}]
}
2016-08-24 08:53:01,411 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-341:ctx-c0b6184d) Seq 1-8381198906536498179: Executing request
2016-08-24 08:53:01,411 INFO [c.c.h.v.r.VmwareResource]
(DirectAgent-341:ctx-c0b6184d vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StopCommand) Executing resource StopCommand:
{"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName":"r-18-VM","wait":0}
2016-08-24 08:53:01,444 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-341:ctx-c0b6184d
vdc-lablon12-vh06.lablon12.cp.vdc, job-141/job-144, cmd: StopCommand) find VM
r-18-VM on host
2016-08-24 08:53:01,444 INFO [c.c.h.v.m.HostMO] (DirectAgent-341:ctx-c0b6184d
vdc-lablon12-vh06.lablon12.cp.vdc, job-141/job-144, cmd: StopCommand) VM
r-18-VM not found in host cache
2016-08-24 08:53:01,444 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-341:ctx-c0b6184d
vdc-lablon12-vh06.lablon12.cp.vdc, job-141/job-144, cmd: StopCommand) load VM
cache on host
2016-08-24 08:53:01,471 INFO [c.c.h.v.r.VmwareResource]
(DirectAgentCronJob-320:ctx-4af48a10) Scan hung worker VM to recycle
2016-08-24 08:53:01,543 INFO [c.c.h.v.r.VmwareResource]
(DirectAgent-341:ctx-c0b6184d vdc-lablon12-vh06.lablon12.cp.vdc,
job-141/job-144, cmd: StopCommand) VM r-18-VM is already in stopped state
2016-08-24 08:53:01,543 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-341:ctx-c0b6184d) Seq 1-8381198906536498179: Response Received:
2016-08-24 08:53:01,543 DEBUG [c.c.a.t.Request] (DirectAgent-341:ctx-c0b6184d)
Seq 1-8381198906536498179: Processing: { Ans: , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM r-18-VM is
already in stopped state","wait":0}}] }
2016-08-24 08:53:01,544 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
1-8381198906536498179: Received: { Ans: , MgmtId: 182213231, via:
1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10, { StopAnswer } }
2016-08-24 08:53:01,555 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Successfully
updated user statistics as a part of domR VM[DomainRouter|r-18-VM] reboot/stop
2016-08-24 08:53:01,563 DEBUG [o.a.c.n.t.AdvancedNetworkTopology]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) SETUP DHCP
PVLAN RULES
2016-08-24 08:53:01,576 DEBUG [c.c.n.r.NetworkHelperImpl]
(Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Router
requires upgrade. Unable to send command to router:18, router template version
: null, minimal required version : 4.6.0
{unformatted}
> Attaching to PVLAN on VMware dvSwtich fails on VR reboot
> --------------------------------------------------------
>
> Key: CLOUDSTACK-9475
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-9475
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: VMware
> Affects Versions: 4.6.0, 4.6.1, 4.6.2, 4.7.0, 4.7.1, 4.8.0, 4.9.0
> Reporter: John Burwell
>
> When restarting a VR using a PVLAN on a VMware dvSwitch, the VR fails to
> attach. An inspection of logs reveals that the cause is the following
> ClassCastException:
> {code}
> java.lang.ClassCastException:
> com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be cast to
> com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
> 2016-08-24 08:53:01,259 DEBUG [c.c.h.v.r.VmwareResource]
> (DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StartCommand) Prepare volume at new device
> {"capacityInKB":0,"key":-2,"backing":{"diskMode":"persistent","fileName":"[90b2ea22317f3a16b696cf32ae35387f]
>
> r-18-VM/ROOT-18.vmdk","datastore":{"value":"datastore-11324","type":"Datastore"}},"connectable":{"startConnected":true,"allowGuestControl":false,"connected":true},"controllerKey":1000,"unitNumber":0}
> 2016-08-24 08:53:01,259 DEBUG [c.c.h.v.r.VmwareResource]
> (DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StartCommand) VM r-18-VM will be started with NIC
> device type: E1000
> 2016-08-24 08:53:01,259 INFO [c.c.h.v.r.VmwareResource]
> (DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StartCommand) Prepare NIC device based on NicTO:
> {"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e5c5fb9-e9be-4f7b-bb6e-43a94fcdda11","uuid":"eef6de62-85ff-47f4-b916-0a237cfa51d9","ip":"192.168.20.10","netmask":"255.255.255.0","gateway":"192.168.20.1","mac":"06:8c:66:00:01:35","dns1":"10.220.90.107","dns2":"10.220.98.107","broadcastType":"Pvlan","type":"Guest","broadcastUri":"pvlan://1900-i1901","isolationUri":"vlan://1900","isSecurityGroupEnabled":false,"name":"extdvs,,vmwaredvs"}
> 2016-08-24 08:53:01,267 INFO [c.c.h.v.r.VmwareResource]
> (DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StartCommand) Prepare network on vmwaredvs extdvs with
> name prefix: cloud.guest
> 2016-08-24 08:53:01,310 INFO [c.c.h.v.m.HypervisorHostHelper]
> (DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StartCommand) Found Distributed Virtual Port group
> cloud.guest.1900.s1900.200.1-extdvs
> 2016-08-24 08:53:01,341 DEBUG [c.c.h.v.m.HypervisorHostHelper]
> (DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StartCommand) Checking if configuration of dvPortGroup
> [cloud.guest.1900.s1900.200.1-extdvs] has changed.
> 2016-08-24 08:53:01,341 INFO [c.c.h.v.u.VmwareHelper]
> (DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StartCommand) [ignored]failed toi get message for
> exception: com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be
> cast to com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
> 2016-08-24 08:53:01,376 WARN [c.c.h.v.r.VmwareResource]
> (DirectAgent-171:ctx-4979098f vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StartCommand) StartCommand failed due to Exception:
> java.lang.ClassCastException
> Message: com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be
> cast to com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
> java.lang.ClassCastException:
> com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be cast to
> com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
> at
> com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.isSpecMatch(HypervisorHostHelper.java:836)
> at
> com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.createPortGroup(HypervisorHostHelper.java:729)
> at
> com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.prepareNetwork(HypervisorHostHelper.java:547)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.prepareNetworkFromNicInfo(VmwareResource.java:2667)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1813)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:450)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:302)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2016-08-24 08:53:01,378 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-171:ctx-4979098f) Seq 1-8381198906536498178: Cancelling because
> one of the answers is false and it is stop on error.
> 2016-08-24 08:53:01,378 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-171:ctx-4979098f) Seq 1-8381198906536498178: Response Received:
> 2016-08-24 08:53:01,379 DEBUG [c.c.a.t.Request]
> (DirectAgent-171:ctx-4979098f) Seq 1-8381198906536498178: Processing: { Ans:
> , MgmtId: 182213231, via: 1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1,
> Flags: 10,
> [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":18,"name":"r-18-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":268435456,"hostName":"r-18-VM","arch":"x86_64","os":"Debian
> GNU/Linux 5.0 (64-bit)","platformEmulator":"debian5Guest","bootArgs":"
> template=domP name=r-18-VM eth0ip=192.168.20.10 eth0mask=255.255.255.0
> gateway=192.168.20.1 domain=guest.vdc cidrsize=24 dhcprange=192.168.20.1
> eth1ip=10.220.88.156 eth1mask=255.255.255.0 mgmtcidr=10.220.0.0/16
> localgw=10.220.88.254 type=dhcpsrvr disable_rp_filter=true extra_pubnics=2
> dns1=10.220.90.107 dns2=10.220.98.107
> baremetalnotificationsecuritykey=6U0RW2iZI8feq96HIXwqfSrNCEQQKydW9DI3KPAaqRK7WKtlzOkeYx4gEPrutQAdEqjYI8mcnuSfEoRgoXm12Q
>
> baremetalnotificationapikey=cOJIV9t57rHsswQBdmjdhZVcoKpCxBfLUXEAx96kwlDjDcRqwM_fs8TJqHkkyWKLxprTvCWmG2hImftYNancdg
> host=vdc-lablon12-cpman1.lablon12.cp.vdc port=8080
> nic_macs=06:8c:66:00:01:35|02:00:61:81:00:07","enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"v71e3kK7x0vmPBc6cOs9pw","params":{"vmware.reserve.cpu":"false","nicAdapter":"E1000","vmware.reserve.mem":"false"},"uuid":"61793ca9-2a53-4438-8721-e36f9053447f","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"6453a5fa-831c-4532-99c7-0659e37ff026","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"90b2ea22-317f-3a16-b696-cf32ae35387f","id":1,"poolType":"NetworkFilesystem","host":"vdc-lablon12-sa01.nfs.lablon12.cp.vdc","path":"/vol/LABLON12_VMS40_HDD1","port":2049,"url":"NetworkFilesystem://vdc-lablon12-sa01.nfs.lablon12.cp.vdc/vol/LABLON12_VMS40_HDD1/?ROLE=Primary&STOREUUID=90b2ea22-317f-3a16-b696-cf32ae35387f"}},"name":"ROOT-18","size":3145728000,"path":"ROOT-18","volumeId":22,"vmName":"r-18-VM","accountId":1,"format":"OVA","provisioningType":"THIN","id":22,"deviceId":0,"hypervisorType":"VMware"}},"diskSeq":0,"path":"ROOT-18","type":"ROOT","_details":{"storageHost":"vdc-lablon12-sa01.nfs.lablon12.cp.vdc","managed":"false","storagePort":"2049","volumeSize":"3145728000"}}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":true,"nicUuid":"1e5c5fb9-e9be-4f7b-bb6e-43a94fcdda11","uuid":"eef6de62-85ff-47f4-b916-0a237cfa51d9","ip":"192.168.20.10","netmask":"255.255.255.0","gateway":"192.168.20.1","mac":"06:8c:66:00:01:35","dns1":"10.220.90.107","dns2":"10.220.98.107","broadcastType":"Pvlan","type":"Guest","broadcastUri":"pvlan://1900-i1901","isolationUri":"vlan://1900","isSecurityGroupEnabled":false,"name":"extdvs,,vmwaredvs"},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"ecc7cea9-bee5-4aa0-a9c5-91ad3de01358","uuid":"0b709cbb-59aa-4c4e-b351-69cc817122c8","ip":"10.220.88.156","netmask":"255.255.255.0","gateway":"10.220.88.254","mac":"02:00:61:81:00:07","broadcastType":"Native","type":"Control","isSecurityGroupEnabled":false,"name":"extdvs,1211,vmwaredvs"}]},"result":false,"details":"StartCommand
> failed due to Exception: java.lang.ClassCastException\nMessage:
> com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be cast to
> com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec\n","wait":0}}] }
> 2016-08-24 08:53:01,379 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
> 1-8381198906536498178: Received: { Ans: , MgmtId: 182213231, via:
> 1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10, { StartAnswer } }
> 2016-08-24 08:53:01,394 INFO [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Unable to
> start VM on Host[-1-Routing] due to StartCommand failed due to Exception:
> java.lang.ClassCastException
> Message: com.vmware.vim25.VmwareDistributedVirtualSwitchPvlanSpec cannot be
> cast to com.vmware.vim25.VmwareDistributedVirtualSwitchVlanIdSpec
> 2016-08-24 08:53:01,402 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Cleaning up
> resources for the vm VM[DomainRouter|r-18-VM] in Starting state
> 2016-08-24 08:53:01,411 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
> 1-8381198906536498179: Sending { Cmd , MgmtId: 182213231, via:
> 1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName":"r-18-VM","wait":0}}]
> }
> 2016-08-24 08:53:01,411 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
> 1-8381198906536498179: Executing: { Cmd , MgmtId: 182213231, via:
> 1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName":"r-18-VM","wait":0}}]
> }
> 2016-08-24 08:53:01,411 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-341:ctx-c0b6184d) Seq 1-8381198906536498179: Executing request
> 2016-08-24 08:53:01,411 INFO [c.c.h.v.r.VmwareResource]
> (DirectAgent-341:ctx-c0b6184d vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StopCommand) Executing resource StopCommand:
> {"isProxy":false,"executeInSequence":true,"checkBeforeCleanup":false,"vmName":"r-18-VM","wait":0}
> 2016-08-24 08:53:01,444 DEBUG [c.c.h.v.m.HostMO]
> (DirectAgent-341:ctx-c0b6184d vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StopCommand) find VM r-18-VM on host
> 2016-08-24 08:53:01,444 INFO [c.c.h.v.m.HostMO]
> (DirectAgent-341:ctx-c0b6184d vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StopCommand) VM r-18-VM not found in host cache
> 2016-08-24 08:53:01,444 DEBUG [c.c.h.v.m.HostMO]
> (DirectAgent-341:ctx-c0b6184d vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StopCommand) load VM cache on host
> 2016-08-24 08:53:01,471 INFO [c.c.h.v.r.VmwareResource]
> (DirectAgentCronJob-320:ctx-4af48a10) Scan hung worker VM to recycle
> 2016-08-24 08:53:01,543 INFO [c.c.h.v.r.VmwareResource]
> (DirectAgent-341:ctx-c0b6184d vdc-lablon12-vh06.lablon12.cp.vdc,
> job-141/job-144, cmd: StopCommand) VM r-18-VM is already in stopped state
> 2016-08-24 08:53:01,543 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-341:ctx-c0b6184d) Seq 1-8381198906536498179: Response Received:
> 2016-08-24 08:53:01,543 DEBUG [c.c.a.t.Request]
> (DirectAgent-341:ctx-c0b6184d) Seq 1-8381198906536498179: Processing: { Ans:
> , MgmtId: 182213231, via: 1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1,
> Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM
> r-18-VM is already in stopped state","wait":0}}] }
> 2016-08-24 08:53:01,544 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Seq
> 1-8381198906536498179: Received: { Ans: , MgmtId: 182213231, via:
> 1(vdc-lablon12-vh06.lablon12.cp.vdc), Ver: v1, Flags: 10, { StopAnswer } }
> 2016-08-24 08:53:01,555 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Successfully
> updated user statistics as a part of domR VM[DomainRouter|r-18-VM] reboot/stop
> 2016-08-24 08:53:01,563 DEBUG [o.a.c.n.t.AdvancedNetworkTopology]
> (Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) SETUP DHCP
> PVLAN RULES
> 2016-08-24 08:53:01,576 DEBUG [c.c.n.r.NetworkHelperImpl]
> (Work-Job-Executor-44:ctx-25c3621e job-141/job-144 ctx-385f0d58) Router
> requires upgrade. Unable to send command to router:18, router template
> version : null, minimal required version : 4.6.0
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
