[ https://issues.apache.org/jira/browse/CLOUDSTACK-7986?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Rajani Karuturi updated CLOUDSTACK-7986: ---------------------------------------- Fix Version/s: 4.3.2 4.4.3 4.6.0 4.5.0 > [F5 LB] Failed to execute IPAssocCommand due to > com.cloud.utils.exception.ExecutionException: Exception caught in > Networking::urn:iControl:Networking/VLAN::create() > -------------------------------------------------------------------------------------------------------------------------------------------------------------------- > > Key: CLOUDSTACK-7986 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7986 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: Network Devices > Affects Versions: 4.3.0, 4.4.0, 4.5.0 > Environment: Red Hat Enterprise Linux Server release 6.3 (Santiago) > IG-IP 11.3.0 Build 39.0 VE Trial 11.3.0-HF1 (based on BIGIP 11.3.0HF6) > Reporter: Sudhansu Sahu > Assignee: Sudhansu Sahu > Fix For: 4.5.0, 4.6.0, 4.4.3, 4.3.2 > > > When trying to launch a VM on a network that uses the network offering (with > LB provided by the F5) the following errors are observed in the logs and the > creation ultimately fails: > {noformat} > 71831 2014-11-26 12:19:34,403 DEBUG > [c.c.n.ExternalLoadBalancerDeviceManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Allocated > external load balancer device:1 for the network: 205 > 71832 2014-11-26 12:19:34,428 DEBUG [c.c.a.t.Request] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Seq > 4-5343239482898383377: Sending { Cmd , MgmtId: 7407677735140, via: > 4(200-F5BigIpLoadBalancer-10.147.60.5 1), Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.routing.IpAssocCommand":{"ipAddresses":[{"accountId":2,"sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"broadcastUri":"910","vlanGateway":"10.0.160.37","vla > > nNetmask":"255.255.240.0","networkRate":200,"newNic":false}],"accessDetails":{},"wait":0}}] > } > 71833 2014-11-26 12:19:34,429 DEBUG [c.c.a.t.Request] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Seq > 4-5343239482898383377: Executing: { Cmd , MgmtId: 7407677735140, via: > 4(200-F5BigIpLoadBalancer-10.147.6 0.51), Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.routing.IpAssocCommand":{"ipAddresses":[{"accountId":2,"sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"broadcastUri":"910","vlanGateway":"10.0.160.37"," > > vlanNetmask":"255.255.240.0","networkRate":200,"newNic":false}],"accessDetails":{},"wait":0}}] > } > 71834 2014-11-26 12:19:34,429 DEBUG [c.c.a.m.DirectAgentAttache] > (DirectAgent-217:ctx-40025c4d) Seq 4-5343239482898383377: Executing request > 71835 2014-11-26 12:19:34,731 DEBUG [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Creating a guest VLAN with tag 910 > 71836 2014-11-26 12:19:35,616 DEBUG [c.c.a.ApiServlet] > (catalina-exec-19:ctx-6bfff176) ===START=== 10.252.192.47 -- GET > command=queryAsyncJobResult&jobId=33e182fe-ab28-470c-a483-a16bd40e05d9&response=json&sessionkey=cUbJKOPdiHo > sLJ06cqS8y66FEMU%3D&_=1416984574574 > 71837 2014-11-26 12:19:35,711 ERROR [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Failed to execute IPAssocCommand due to > com.cloud.utils.exception.ExecutionException: Failed to create vlan with tag > 910 > 71838 2014-11-26 12:19:35,734 DEBUG [c.c.a.ApiServlet] > (catalina-exec-19:ctx-6bfff176 ctx-f76b168b) ===END=== 10.252.192.47 -- GET > command=queryAsyncJobResult&jobId=33e182fe-ab28-470c-a483-a16bd40e05d9&response=json&sessionkey= > cUbJKOPdiHosLJ06cqS8y66FEMU%3D&_=1416984574574 > 71839 2014-11-26 12:19:35,842 ERROR [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Retrying IpAssocCommand. Number of retries > remaining: 1 > 71840 2014-11-26 12:19:36,053 DEBUG [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Creating a guest VLAN with tag 910 > 71841 2014-11-26 12:19:36,233 ERROR [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Exception caught in > Networking::urn:iControl:Networking/VLAN::create() > 71842 Exception: Common::OperationFailed > 71843 primary_error_code : 16908390 (0x01020066) > 71844 secondary_error_code : 0 > 71845 error_string : 01020066:3: The requested VLAN > (/Common/vlan-910) already exists in partition Common. > 71846 2014-11-26 12:19:36,234 ERROR [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Failed to execute IPAssocCommand due to > com.cloud.utils.exception.ExecutionException: Exception caught in > Networking::urn:iControl:Netwo rking/VLAN::create() > 71847 Exception: Common::OperationFailed > 71848 primary_error_code : 16908390 (0x01020066) > 71849 secondary_error_code : 0 > 71850 error_string : 01020066:3: The requested VLAN > (/Common/vlan-910) already exists in partition Common. > 71851 2014-11-26 12:19:36,318 ERROR [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Retrying IpAssocCommand. Number of retries > remaining: 0 > 71852 2014-11-26 12:19:36,529 DEBUG [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Creating a guest VLAN with tag 910 > 71853 2014-11-26 12:19:36,562 ERROR [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Exception caught in > Networking::urn:iControl:Networking/VLAN::create() > 71854 Exception: Common::OperationFailed > 71855 primary_error_code : 16908390 (0x01020066) > 71856 secondary_error_code : 0 > 71857 error_string : 01020066:3: The requested VLAN > (/Common/vlan-910) already exists in partition Common. > 71858 2014-11-26 12:19:36,563 ERROR [c.c.n.r.F5BigIpResource] > (DirectAgent-217:ctx-40025c4d) Failed to execute IPAssocCommand due to > com.cloud.utils.exception.ExecutionException: Exception caught in > Networking::urn:iControl:Netwo rking/VLAN::create() > 71859 Exception: Common::OperationFailed > 71860 primary_error_code : 16908390 (0x01020066) > 71861 secondary_error_code : 0 > 71862 error_string : 01020066:3: The requested VLAN > (/Common/vlan-910) already exists in partition Common. > 71863 2014-11-26 12:19:36,563 DEBUG [c.c.a.m.DirectAgentAttache] > (DirectAgent-217:ctx-40025c4d) Seq 4-5343239482898383377: Response Received: > 71864 2014-11-26 12:19:36,563 DEBUG [c.c.a.t.Request] > (DirectAgent-217:ctx-40025c4d) Seq 4-5343239482898383377: Processing: { Ans: > , MgmtId: 7407677735140, via: 4, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.routing.IpAssocAnswer > ":{"results":["Failed"],"result":false,"wait":0}}] } > 71865 2014-11-26 12:19:36,563 DEBUG [c.c.a.t.Request] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Seq > 4-5343239482898383377: Received: { Ans: , MgmtId: 7407677735140, via: 4, > Ver: v1, Flags: 10, { IpAssocAn swer } } > 71866 2014-11-26 12:19:36,563 ERROR > [c.c.n.ExternalLoadBalancerDeviceManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) External > load balancer was unable to implement the guest network on the external > load balancer in zone bpkvmwstorezone > 71867 2014-11-26 12:19:36,570 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Cleaning up > because we're unable to implement the network Ntwk[205|Guest|15] > 71868 2014-11-26 12:19:36,589 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Lock is > acquired for network Ntwk[205|Guest|15] as a part of network shutdown > 71869 2014-11-26 12:19:36,597 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Releasing 0 > port forwarding rules for network id=205 as a part of shutdownNetworkRules > 71870 2014-11-26 12:19:36,598 DEBUG [c.c.n.f.FirewallManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) There are > no rules to forward to the network elements > 71871 2014-11-26 12:19:36,599 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Releasing 0 > static nat rules for network id=205 as a part of shutdownNetworkRules > 71872 2014-11-26 12:19:36,599 DEBUG [c.c.n.f.FirewallManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) There are > no rules to forward to the network elements > 71873 2014-11-26 12:19:36,601 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Revoking 0 > Public load balancing rules for network id=205 > 71874 2014-11-26 12:19:36,601 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) There are > no Load Balancing Rules to forward to the network elements > 71875 2014-11-26 12:19:36,602 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Revoking 0 > Internal load balancing rules for network id=205 > 71876 2014-11-26 12:19:36,603 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) There are > no Load Balancing Rules to forward to the network elements > 71877 2014-11-26 12:19:36,604 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Releasing 0 > firewall ingress rules for network id=205 as a part of shutdownNetworkRules > 71878 2014-11-26 12:19:36,604 DEBUG [c.c.n.f.FirewallManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) There are > no rules to forward to the network elements > 71879 2014-11-26 12:19:36,606 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Releasing 0 > firewall egress rules for network id=205 as a part of shutdownNetworkRules > 71880 2014-11-26 12:19:36,607 DEBUG [c.c.n.f.FirewallManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) There are > no rules to forward to the network elements > 71881 2014-11-26 12:19:36,609 DEBUG [c.c.n.r.RulesManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Found 0 > static nat rules to apply for network id 205 > 71882 2014-11-26 12:19:36,631 DEBUG [c.c.n.e.VirtualRouterElement] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Virtual > router elemnt doesn't need to associate ip addresses on the backend; virtual > router does n't exist in the network 205 > 71883 2014-11-26 12:19:36,632 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Sending > network shutdown to F5BigIP > 71884 2014-11-26 12:19:36,648 WARN > [c.c.n.ExternalLoadBalancerDeviceManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Network > shutdwon requested on external load balancer element, which did not imple > ment the network. Either network implement failed half way through or > already network shutdown is completed. So just returning. > 71885 2014-11-26 12:19:36,656 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Sending > network shutdown to VirtualRouter > 71886 2014-11-26 12:19:36,673 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Network > id=205 is shutdown successfully, cleaning up corresponding resources now. > 71887 2014-11-26 12:19:36,676 DEBUG [c.c.n.g.GuestNetworkGuru] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Releasing > vnet for the network id=205 > 71888 2014-11-26 12:19:36,710 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Lock is > released for network Ntwk[205|Guest|15] as a part of network shutdown > 71889 2014-11-26 12:19:36,710 DEBUG [o.a.c.e.o.NetworkOrchestrator] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Lock is > released for network id 205 as a part of network implement > 71890 2014-11-26 12:19:36,711 INFO [c.c.v.VirtualMachineManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) Unable to > contact resource. > 71891 com.cloud.exception.ResourceUnavailableException: Resource > [Network:205] is unreachable: External load balancer was unable to implement > the guest network on the external load balancer in zone bpkvmwstorezone > 71892 at > com.cloud.network.ExternalLoadBalancerDeviceManagerImpl.manageGuestNetworkWithExternalLoadBalancer(ExternalLoadBalancerDeviceManagerImpl.java:1058) > 71893 at > com.cloud.network.element.F5ExternalLoadBalancerElement.implement(F5ExternalLoadBalancerElement.java:158) > 71894 at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetworkElementsAndResources(NetworkOrchestrator.java:1101) > 71895 at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetwork(NetworkOrchestrator.java:1008) > 71896 at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetwork(NetworkOrchestrator.java:938) > 71897 at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1293) > 71898 at > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:983) > 71899 at > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4436) > 71900 at sun.reflect.GeneratedMethodAccessor300.invoke(Unknown > Source) > 71901 at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > 71902 at java.lang.reflect.Method.invoke(Method.java:601) > 71903 at > com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) > 71904 at > com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4592) > 71905 at > com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:103) > 71906 at > org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:536) > 71907 at > org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) > 71908 at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56) > 71909 at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103) > 71910 at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53) > 71911 at > org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46) > 71912 at > org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:493) > 71913 at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > 71914 at > java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > 71915 at java.util.concurrent.FutureTask.run(FutureTask.java:166) > 71916 at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > 71917 at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > 71918 at java.lang.Thread.run(Thread.java:722) > 71919 2014-11-26 12:19:36,712 WARN [c.c.v.VirtualMachineManagerImpl] > (Work-Job-Executor-133:ctx-434a0b57 job-269/job-270 ctx-cd8df97f) unexpected > ResourceUnavailableException : com.cloud.network.Network > 71920 com.cloud.exception.ResourceUnavailableException: Resource > [Network:205] is unreachable: External load balancer was unable to implement > the guest network on the external load balancer in zone bpkvmwstorezone > 71921 at > com.cloud.network.ExternalLoadBalancerDeviceManagerImpl.manageGuestNetworkWithExternalLoadBalancer(ExternalLoadBalancerDeviceManagerImpl.java:1058) > 71922 at > com.cloud.network.element.F5ExternalLoadBalancerElement.implement(F5ExternalLoadBalancerElement.java:158) > 71923 at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetworkElementsAndResources(NetworkOrchestrator.java:1101) > 71924 at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetwork(NetworkOrchestrator.java:1008) > 71925 at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.implementNetwork(NetworkOrchestrator.java:938) > 71926 at > org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1293) > 71927 at > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:983) > 71928 at > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4436) > 71929 at sun.reflect.GeneratedMethodAccessor300.invoke(Unknown > Source) > 71930 at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > 71931 at java.lang.reflect.Method.invoke(Method.java:601) > 71932 at > com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) > 71933 at > com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4592) > 71934 at > com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:103) > 71935 at > org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:536) > 71936 at > org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) > 71937 at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56) > 71938 at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103) > 71939 at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53) > 71940 at > org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46) > 71941 at > org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:493) > 71942 at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > 71943 at > java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > 71944 at java.util.concurrent.FutureTask.run(FutureTask.java:166) > 71945 at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > 71946 at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > 71947 at java.lang.Thread.run(Thread.java:722) > {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)