You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sudhansu Sahu (JIRA)" <ji...@apache.org> on 2014/11/27 13:27:12 UTC
[jira] [Created] (CLOUDSTACK-7986) [F5 LB] Failed to execute
IPAssocCommand due to com.cloud.utils.exception.ExecutionException:
Exception caught in Networking::urn:iControl:Networking/VLAN::create()
Sudhansu Sahu created CLOUDSTACK-7986:
-----------------------------------------
Summary: [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.4.0, 4.3.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
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)