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:29:12 UTC
[jira] [Commented] (CLOUDSTACK-7986) [F5 LB] Failed to execute
IPAssocCommand due to com.cloud.utils.exception.ExecutionException:
Exception caught in Networking::urn:iControl:Networking/VLAN::create()
[ https://issues.apache.org/jira/browse/CLOUDSTACK-7986?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14227594#comment-14227594 ]
Sudhansu Sahu commented on CLOUDSTACK-7986:
-------------------------------------------
Seems like the list VLAN api response has been modified in 11.x.
After analyzing the logs, I found that the VLAN creation is succesful, but there is a logic which verifies the VLAN creation (see the code snippet below).
_vlanApi.create(vlanNames, vlanTags, vlanMemberEntries, commonEnabledState, new long[]{10L}, new String[]{"00:00:00:00:00:00"});
if (!getVlans().contains(vlanName)) {
throw new ExecutionException("Failed to create vlan with tag " + vlanTag);
}
SOAP result for getVlans() is:
{noformat}
<return s:type="A:Array" A:arrayType="y:string[9]">
<item>/Common/vlan-902</item>
<item>/Common/vlan-905</item>
<item>/Common/vlan-906</item>
<item>/Common/vlan-904</item>
<item>/Common/vlan-903</item>
<item>/Common/vlan44</item>
<item>/Common/vlan-908</item>
<item>/Common/vlan-910</item>
<item>/Common/vlan-900</item>
</return>
{noformat}
we are looking for vlanName: vlan-906 in this list. which is not in the list (valan is prefixed with the partion name "/Common/")
As it was working 10.x so the list VLAN response might have been modified in 11.x. Now all VLANs are prefixed with the partition / path info.
> [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
>
> 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)