brandon arms created CLOUDSTACK-1084:
----------------------------------------
Summary: vpc static one to one nat failure
Key: CLOUDSTACK-1084
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-1084
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: VMware
Affects Versions: 4.0.0
Reporter: brandon arms
Priority: Blocker
static nat rule fails for vpc:
acquire ip address log:
2013-01-29 14:34:05,584 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-13:null) Associate IP address called by the user 6 account 6
2013-01-29 14:34:05,585 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-13:null) Associate IP address lock acquired
2013-01-29 14:34:05,589 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-13:null) Got 8.25.163.133 to assign for account 6 in zone 3
2013-01-29 14:34:05,602 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-13:null) Releasing lock account Acct[6-barms]
2013-01-29 14:34:05,603 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-13:null) Associate IP address lock released
2013-01-29 14:34:05,615 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-13:null) submit async job-353, details: AsyncJobVO {id:353,
userId: 6, accountId: 6, sessionKey: null, instanceType: IpAddress, instanceId:
17, cmd: com.cloud.api.commands.AssociateIPAddrCmd, cmdOriginator: null,
cmdInfo:
{"id":"17","response":"json","sessionkey":"c5ysvZL+Nxs2EwFefOsNuWL6/NY\u003d","ctxUserId":"6","_":"1359488045538","ctxAccountId":"6","vpcid":"1606e883-6750-42be-b42b-663cb56dba46","ctxStartEventId":"1519"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 143316583244,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-01-29 14:34:05,618 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-12:job-353) Executing com.cloud.api.commands.AssociateIPAddrCmd
for job-353
2013-01-29 14:34:05,628 DEBUG [network.vpc.VpcManagerImpl]
(Job-Executor-12:job-353) Associating ip Ip[8.25.163.133-3] to vpc [VPC
[8-Tenant1-VPC]
2013-01-29 14:34:05,638 DEBUG [network.vpc.VpcManagerImpl]
(Job-Executor-12:job-353) Successfully assigned ip Ip[8.25.163.133-3] to vpc
[VPC [8-Tenant1-VPC]
2013-01-29 14:34:05,644 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-12:job-353) Complete async job-353, jobStatus: 1, resultCode: 0,
result: com.cloud.api.response.IPAddressResponse@3e8d1fbf
2013-01-29 14:34:05,649 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-12:job-353) Done executing
com.cloud.api.commands.AssociateIPAddrCmd for job-353
2013-01-29 14:34:10,653 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-23:null) Async job-353 completed
enable static nat (failure):
2013-01-29 14:36:13,741 DEBUG [network.rules.RulesManagerImpl]
(catalina-exec-3:null) The ip is not associated with the VPC network id=238, so
assigning
2013-01-29 14:36:13,745 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-3:null) Associating ip Ip[8.25.163.133-3] to network
Ntwk[238|Guest|12]
2013-01-29 14:36:13,752 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-3:null) Successfully associated ip address 8.25.163.133 to
network Ntwk[238|Guest|12]
2013-01-29 14:36:13,770 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl] (catalina-exec-3:null)
Applying vpc ip association in network Ntwk[238|Guest|12]
2013-01-29 14:36:13,786 DEBUG [agent.transport.Request] (catalina-exec-3:null)
Seq 10-328139827: Sending { Cmd , MgmtId: 143316583244, via: 10, Ver: v1,
Flags: 100001,
[{"routing.IpAssocVpcCommand":{"ipAddresses":[{"accountId":6,"publicIp":"8.25.163.133","sourceNat":false,"add":true,"oneToOneNat":true,"firstIP":false,"vlanId":"500","vlanGateway":"8.25.163.129","vlanNetmask":"255.255.255.240","vifMacAddress":"06:4b:ce:00:00:1c","networkRate":200,"trafficType":"Public","networkName":"vSwitch1"}],"accessDetails":{"router.guest.ip":"8.25.163.131","zone.network.type":"Advanced","router.ip":"172.31.200.166","router.name":"r-64-VM"},"wait":0}}]
}
2013-01-29 14:36:13,786 DEBUG [agent.transport.Request] (catalina-exec-3:null)
Seq 10-328139827: Executing: { Cmd , MgmtId: 143316583244, via: 10, Ver: v1,
Flags: 100001,
[{"routing.IpAssocVpcCommand":{"ipAddresses":[{"accountId":6,"publicIp":"8.25.163.133","sourceNat":false,"add":true,"oneToOneNat":true,"firstIP":false,"vlanId":"500","vlanGateway":"8.25.163.129","vlanNetmask":"255.255.255.240","vifMacAddress":"06:4b:ce:00:00:1c","networkRate":200,"trafficType":"Public","networkName":"vSwitch1"}],"accessDetails":{"router.guest.ip":"8.25.163.131","zone.network.type":"Advanced","router.ip":"172.31.200.166","router.name":"r-64-VM"},"wait":0}}]
}
2013-01-29 14:36:13,786 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-409:null) Seq 10-328139827: Executing request
2013-01-29 14:36:13,787 INFO [vmware.resource.VmwareResource]
(DirectAgent-409:172.31.200.140) Executing resource IpAssocVpcCommand
{"ipAddresses":[{"accountId":6,"publicIp":"8.25.163.133","sourceNat":false,"add":true,"oneToOneNat":true,"firstIP":false,"vlanId":"500","vlanGateway":"8.25.163.129","vlanNetmask":"255.255.255.240","vifMacAddress":"06:4b:ce:00:00:1c","networkRate":200,"trafficType":"Public","networkName":"vSwitch1"}],"accessDetails":{"router.guest.ip":"8.25.163.131","zone.network.type":"Advanced","router.ip":"172.31.200.166","router.name":"r-64-VM"},"wait":0}
2013-01-29 14:36:13,787 DEBUG [vmware.resource.VmwareResource]
(DirectAgent-409:172.31.200.140) Use router's private IP for SSH control. IP :
172.31.200.166
2013-01-29 14:36:13,787 INFO [vmware.resource.VmwareResource]
(DirectAgent-409:172.31.200.140) Executing resource assignVPCPublicIpAddress.
domrName: r-64-VM, routerIp: 172.31.200.166, ip:
{"accountId":6,"publicIp":"8.25.163.133","sourceNat":false,"add":true,"oneToOneNat":true,"firstIP":false,"vlanId":"500","vlanGateway":"8.25.163.129","vlanNetmask":"255.255.255.240","vifMacAddress":"06:4b:ce:00:00:1c","networkRate":200,"trafficType":"Public","networkName":"vSwitch1"}
2013-01-29 14:36:13,787 INFO [vmware.resource.VmwareResource]
(DirectAgent-409:172.31.200.140) findRouterEthDeviceIndex. mac:
06:4b:ce:00:00:1c
2013-01-29 14:36:15,002 DEBUG [vmware.resource.VmwareResource]
(DirectAgent-409:172.31.200.140) Run domr script ip address show eth0 | grep
link/ether | sed -e 's/^[ ]*//' | cut -d' ' -f2
2013-01-29 14:36:16,235 DEBUG [vmware.resource.VmwareResource]
(DirectAgent-409:172.31.200.140) result: true, output: 02:00:21:c2:00:18
2013-01-29 14:36:16,253 DEBUG [vmware.resource.VmwareResource]
(DirectAgent-409:172.31.200.140) Run domr script ip address show eth1 | grep
link/ether | sed -e 's/^[ ]*//' | cut -d' ' -f2
2013-01-29 14:36:17,424 DEBUG [vmware.resource.VmwareResource]
(DirectAgent-409:172.31.200.140) result: true, output: 06:4b:ce:00:00:1c
2013-01-29 14:36:18,674 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-409:null) Seq 10-328139827: Response Received:
2013-01-29 14:36:18,675 DEBUG [agent.transport.Request] (DirectAgent-409:null)
Seq 10-328139827: Processing: { Ans: , MgmtId: 143316583244, via: 10, Ver: v1,
Flags: 0, [{"routing.IpAssocAnswer":{"results":["8.25.163.133 -
success"],"result":true,"wait":0}}] }
2013-01-29 14:36:18,675 DEBUG [agent.transport.Request] (catalina-exec-3:null)
Seq 10-328139827: Received: { Ans: , MgmtId: 143316583244, via: 10, Ver: v1,
Flags: 0, { IpAssocAnswer } }
2013-01-29 14:36:18,680 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl] (catalina-exec-3:null)
Applying static nat rules in network Ntwk[238|Guest|12]
2013-01-29 14:36:18,689 DEBUG [agent.transport.Request] (catalina-exec-3:null)
Seq 10-328139828: Sending { Cmd , MgmtId: 143316583244, via: 10, Ver: v1,
Flags: 100001,
[{"routing.SetStaticNatRulesCommand":{"rules":[{"dstIp":"10.1.201.187","id":0,"srcIp":"8.25.163.133","revoked":false,"alreadyAdded":false,"purpose":"StaticNat","icmpType":0,"icmpCode":0}],"vpcId":8,"accessDetails":{"router.guest.ip":"10.1.201.129","zone.network.type":"Advanced","router.ip":"172.31.200.166","router.name":"r-64-VM"},"wait":0}}]
}
2013-01-29 14:36:18,689 DEBUG [agent.transport.Request] (catalina-exec-3:null)
Seq 10-328139828: Executing: { Cmd , MgmtId: 143316583244, via: 10, Ver: v1,
Flags: 100001,
[{"routing.SetStaticNatRulesCommand":{"rules":[{"dstIp":"10.1.201.187","id":0,"srcIp":"8.25.163.133","revoked":false,"alreadyAdded":false,"purpose":"StaticNat","icmpType":0,"icmpCode":0}],"vpcId":8,"accessDetails":{"router.guest.ip":"10.1.201.129","zone.network.type":"Advanced","router.ip":"172.31.200.166","router.name":"r-64-VM"},"wait":0}}]
}
2013-01-29 14:36:18,689 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-138:null) Seq 10-328139828: Executing request
2013-01-29 14:36:18,690 INFO [vmware.resource.VmwareResource]
(DirectAgent-138:172.31.200.140) Executing resource SetFirewallRuleCommand:
{"rules":[{"dstIp":"10.1.201.187","id":0,"srcIp":"8.25.163.133","revoked":false,"alreadyAdded":false,"purpose":"StaticNat","icmpType":0,"icmpCode":0}],"vpcId":8,"accessDetails":{"router.guest.ip":"10.1.201.129","zone.network.type":"Advanced","router.ip":"172.31.200.166","router.name":"r-64-VM"},"wait":0}
2013-01-29 14:36:18,691 DEBUG [vmware.resource.VmwareResource]
(DirectAgent-138:172.31.200.140) Use router's private IP for SSH control. IP :
172.31.200.166
2013-01-29 14:36:19,997 ERROR [utils.ssh.SshHelper]
(DirectAgent-138:172.31.200.140) SSH execution of command /root/firewall.sh -A
-l 8.25.163.133 -r 10.1.201.187 -d 0:0 -G has an error status code in return.
result output: Bad argument `8.25.163.133'
Try `iptables -h' or 'iptables --help' for more information.
Bad argument `8.25.163.133'
Try `iptables -h' or 'iptables --help' for more information.
iptables v1.4.8: option `--set-mark' requires an argument
Try `iptables -h' or 'iptables --help' for more information.
iptables: No chain/target/match by that name.
Bad argument `8.25.163.133'
Try `iptables -h' or 'iptables --help' for more information.
Bad argument `eth0'
Try `iptables -h' or 'iptables --help' for more information.
Bad argument `8.25.163.133'
Try `iptables -h' or 'iptables --help' for more information.
iptables: No chain/target/match by that name.
iptables: No chain/target/match by that name.
Bad argument `8.25.163.133'
Try `iptables -h' or 'iptables --help' for more information.
2013-01-29 14:36:20,001 DEBUG [vmware.resource.VmwareResource]
(DirectAgent-138:172.31.200.140) Executing script on domain router
172.31.200.166: /root/firewall.sh -A -l 8.25.163.133 -r 10.1.201.187 -d 0:0
-G
2013-01-29 14:36:20,001 ERROR [vmware.resource.VmwareResource]
(DirectAgent-138:172.31.200.140) SetStaticNatRulesCommand failure on setting
one rule. args: -A -l 8.25.163.133 -r 10.1.201.187 -d 0:0 -G
2013-01-29 14:36:20,005 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-138:null) Seq 10-328139828: Response Received:
2013-01-29 14:36:20,005 DEBUG [agent.transport.Request] (DirectAgent-138:null)
Seq 10-328139828: Processing: { Ans: , MgmtId: 143316583244, via: 10, Ver: v1,
Flags: 0,
[{"routing.SetStaticNatRulesAnswer":{"results":["Failed"],"result":false,"wait":0}}]
}
2013-01-29 14:36:20,005 DEBUG [agent.transport.Request] (catalina-exec-3:null)
Seq 10-328139828: Received: { Ans: , MgmtId: 143316583244, via: 10, Ver: v1,
Flags: 0, { SetStaticNatRulesAnswer } }
2013-01-29 14:36:20,006 WARN [network.rules.RulesManagerImpl]
(catalina-exec-3:null) Failed to create static nat rule due to
com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:3] is
unreachable: Unable to apply static nat rules on router
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3135)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyStaticNats(VirtualNetworkApplianceManagerImpl.java:3183)
at
com.cloud.network.element.VirtualRouterElement.applyStaticNats(VirtualRouterElement.java:604)
at
com.cloud.network.NetworkManagerImpl.applyStaticNats(NetworkManagerImpl.java:4937)
at
com.cloud.network.rules.RulesManagerImpl.applyStaticNatForIp(RulesManagerImpl.java:1283)
at
com.cloud.network.rules.RulesManagerImpl.enableStaticNat(RulesManagerImpl.java:472)
at
com.cloud.event.ActionEventCallback.intercept(ActionEventCallback.java:36)
at
com.cloud.api.commands.EnableStaticNatCmd.execute(EnableStaticNatCmd.java:111)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
at com.cloud.api.ApiServer.queueCommand(ApiServer.java:543)
at com.cloud.api.ApiServer.handleRequest(ApiServer.java:422)
at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:304)
at com.cloud.api.ApiServlet.doGet(ApiServlet.java:63)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
at
org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:889)
at
org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:721)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2268)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2013-01-29 14:36:20,009 WARN [network.rules.RulesManagerImpl]
(catalina-exec-3:null) Failed to enable static nat rule for ip address 17 on
the backend
2013-01-29 14:36:20,014 DEBUG [network.vpc.VpcManagerImpl]
(catalina-exec-3:null) Releasing VPC ip address Ip[8.25.163.133-3] from vpc
network id=238
2013-01-29 14:36:20,036 DEBUG [network.vpc.VpcManagerImpl]
(catalina-exec-3:null) IP address Ip[8.25.163.133-3] is no longer associated
with the network inside vpc id=8
2013-01-29 14:36:20,036 DEBUG [network.vpc.VpcManagerImpl]
(catalina-exec-3:null) Successfully released VPC ip address Ip[8.25.163.133-3]
back to VPC pool
2013-01-29 14:36:20,039 WARN [cloud.api.ApiDispatcher] (catalina-exec-3:null)
class com.cloud.api.ServerApiException : Failed to enable static nat
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
