Uploaded image for project: 'CloudStack'
  1. CloudStack
  2. CLOUDSTACK-9475

Attaching to PVLAN on VMware dvSwtich fails on VR reboot

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Open
    • Major
    • Resolution: Unresolved
    • 4.6.0, 4.6.1, 4.6.2, 4.7.0, 4.7.1, 4.8.0, 4.9.0
    • None
    • VMware
    • Security Level: Public (Anyone can view this level - this is the default.)
    • None

    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:

      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

      Attachments

        Activity

          People

            Unassigned Unassigned
            jburwell John Burwell
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated: