Return-Path: X-Original-To: apmail-incubator-cloudstack-dev-archive@minotaur.apache.org Delivered-To: apmail-incubator-cloudstack-dev-archive@minotaur.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id AD186E158 for ; Thu, 17 Jan 2013 05:46:14 +0000 (UTC) Received: (qmail 20042 invoked by uid 500); 17 Jan 2013 05:46:14 -0000 Delivered-To: apmail-incubator-cloudstack-dev-archive@incubator.apache.org Received: (qmail 19756 invoked by uid 500); 17 Jan 2013 05:46:14 -0000 Mailing-List: contact cloudstack-dev-help@incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: cloudstack-dev@incubator.apache.org Delivered-To: mailing list cloudstack-dev@incubator.apache.org Received: (qmail 19733 invoked by uid 99); 17 Jan 2013 05:46:13 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 17 Jan 2013 05:46:13 +0000 Date: Thu, 17 Jan 2013 05:46:12 +0000 (UTC) From: "Abhinav Roy (JIRA)" To: cloudstack-dev@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CLOUDSTACK-938) s2s VPN trouble MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-938?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13555887#comment-13555887 ] Abhinav Roy commented on CLOUDSTACK-938: ---------------------------------------- Hi Sheng, I tested this feature in my environment but with the same customer VPN gateway details as used by Richard and here are my findings :- VPC VR logs :- ========================================================== 1. root@r-9-VM:/var/log# ifconfig eth0 Link encap:Ethernet HWaddr 0e:00:a9:fe:00:04 inet addr:169.254.0.4 Bcast:169.254.255.255 Mask:255.255.0.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:1023 errors:0 dropped:0 overruns:0 frame:0 TX packets:668 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:105813 (103.3 KiB) TX bytes:175004 (170.9 KiB) eth1 Link encap:Ethernet HWaddr 06:3c:62:00:00:10 inet addr:10.102.195.74 Bcast:10.102.195.255 Mask:255.255.252.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:53518 errors:0 dropped:0 overruns:0 frame:0 TX packets:2 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:3766292 (3.5 MiB) TX bytes:84 (84.0 B) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 UP LOOPBACK RUNNING MTU:16436 Metric:1 RX packets:6 errors:0 dropped:0 overruns:0 frame:0 TX packets:6 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:0 RX bytes:414 (414.0 B) TX bytes:414 (414.0 B) 2. Nics. NIC 1 Type Traffic Type Control Network Name Netmask 255.255.0.0 IP Address 169.254.0.4 ID a1b03f69-3606-486e-a7d6-504878bf6184 Network ID 7a44608b-60a0-488a-b2db-2187fa346ef0 Isolation URI Broadcast URI NIC 2 (Default) Type Traffic Type Public Network Name Netmask 255.255.252.0 IP Address 10.102.195.74 ID b3d3de74-1f6a-4f81-9f27-7d23682ca948 Network ID 18d5e28a-ac84-4ed1-87a4-65346f4660f3 Isolation URI vlan://untagged Broadcast URI vlan://untagged Here we see that the NIC-2 which is Eth1 has the public IP. But lets see in the cloud.log, here Eth1 is not treated as the public interface Jan 16 10:29:11 r-9-VM sshd[1427]: Server listening on 169.254.0.4 port 3922. Jan 16 10:29:11 r-9-VM sshd[1427]: error: Bind to port 3922 on 169.254.0.4 failed: Address already in use. Jan 16 10:29:20 r-9-VM sshd[1612]: Did not receive identification string from 169.254.0.1 Jan 16 10:29:20 r-9-VM sshd[1613]: Accepted publickey for root from 169.254.0.1 port 59845 ssh2 Wed Jan 16 10:28:51 UTC 2013 Executing cloud-early-config Wed Jan 16 10:28:51 UTC 2013 Detected that we are running inside kvm guest Wed Jan 16 10:28:51 UTC 2013 Patching scripts oldmd5=e1defa60190950fbd3d5e9c15c5b7c28 newmd5=89f718b371578db5f8caa40a1da141f1 Wed Jan 16 10:28:51 UTC 2013 Patching cloud service Wed Jan 16 10:28:53 UTC 2013 Rebooting system since we patched init scripts Wed Jan 16 10:29:09 UTC 2013 Executing cloud-early-config Wed Jan 16 10:29:09 UTC 2013 Detected that we are running inside kvm guest Wed Jan 16 10:29:09 UTC 2013 Patching cloud service Wed Jan 16 10:29:11 UTC 2013 Setting up VPC virtual router system vm Wed Jan 16 10:29:11 UTC 2013 Setting up apache web server for VPC Wed Jan 16 10:29:11 UTC 2013 Enable service dnsmasq = 1 Wed Jan 16 10:29:11 UTC 2013 Enable service haproxy = 1 Wed Jan 16 10:29:11 UTC 2013 Enable service cloud = 0 Wed Jan 16 10:29:11 UTC 2013 cloud: Tuning rp_filter on public interfaces Wed Jan 16 10:29:11 UTC 2013 rpfilter public interfaces : Wed Jan 16 10:29:11 UTC 2013 cloud: disable rp_filter on public interfaces Wed Jan 16 10:29:11 UTC 2013 cloud: Enabling rp_filter on Non-public interfaces(eth0,eth1,lo) ----------------------------------->>>> Here we see that it treats eth1 also as non-public interface Wed Jan 16 10:29:11 UTC 2013 cloud: enable_fwding = 1 Wed Jan 16 10:29:11 UTC 2013 enable_fwding = 1 4. Auth.log Jan 16 10:29:11 r-9-VM sshd[1427]: Server listening on 169.254.0.4 port 3922. Jan 16 10:29:11 r-9-VM sshd[1427]: error: Bind to port 3922 on 169.254.0.4 failed: Address already in use. Jan 16 10:29:20 r-9-VM sshd[1612]: Did not receive identification string from 169.254.0.1 Jan 16 10:29:20 r-9-VM sshd[1613]: Accepted publickey for root from 169.254.0.1 port 59845 ssh2 Jan 16 10:29:20 r-9-VM sshd[1613]: pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:20 r-9-VM sshd[1613]: Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:20 r-9-VM sshd[1613]: pam_unix(sshd:session): session closed for user root Jan 16 10:29:20 r-9-VM sshd[1618]: Accepted publickey for root from 169.254.0.1 port 59846 ssh2 Jan 16 10:29:20 r-9-VM sshd[1618]: pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:20 r-9-VM sshd[1618]: Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:20 r-9-VM sshd[1618]: pam_unix(sshd:session): session closed for user root Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo 1 Table_eth1 Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip rule add fwmark 1 table Table_eth1 Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth1 Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush cache Jan 16 10:29:20 r-9-VM sshd[1648]: Accepted publickey for root from 169.254.0.1 port 59847 ssh2 Jan 16 10:29:20 r-9-VM sshd[1648]: pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link show eth1 Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev eth1 10.102.195.74/22 brd + Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link set eth1 up Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/usr/bin/arping -c 3 -I eth1 -A -U -s 10.102.195.74 10.102.195.74 Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables-save -t mangle Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -i eth1 -m state --state NEW -j CONNMARK --set-mark 1 Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add 10.102.192.0/22 dev eth1 table Table_eth1 proto static Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 10.102.192.1 table Table_eth1 proto static Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route flush cache Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 10.102.192.1 Jan 16 10:29:22 r-9-VM sshd[1648]: Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:22 r-9-VM sshd[1648]: pam_unix(sshd:session): session closed for user root Jan 16 10:29:23 r-9-VM sshd[1708]: Accepted publickey for root from 169.254.0.1 port 59848 ssh2 Jan 16 10:29:23 r-9-VM sshd[1708]: pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D FORWARD -s 10.1.1.1/16 ! -d 10.1.1.1/16 -j ACCEPT Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A FORWARD -s 10.1.1.1/16 ! -d 10.1.1.1/16 -j ACCEPT Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -D POSTROUTING -j SNAT -o eth1 --to-source 10.102.195.74 Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -A POSTROUTING -j SNAT -o eth1 --to-source 10.102.195.74 Jan 16 10:29:23 r-9-VM sshd[1708]: Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:23 r-9-VM sshd[1708]: pam_unix(sshd:session): session closed for user root Jan 16 10:29:23 r-9-VM sshd[1739]: Accepted publickey for root from 169.254.0.1 port 59849 ssh2 Jan 16 10:29:23 r-9-VM sshd[1739]: pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:23 r-9-VM sshd[1739]: Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:23 r-9-VM sshd[1739]: pam_unix(sshd:session): session closed for user root Jan 16 10:29:52 r-9-VM sshd[1754]: Accepted publickey for root from 169.254.0.1 port 59850 ssh2 Jan 16 10:29:52 r-9-VM sshd[1754]: pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:34:27 r-9-VM sshd[1765]: Accepted publickey for root from 169.254.0.1 port 59852 ssh2 Jan 16 10:34:27 r-9-VM sshd[1765]: pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:34:27 r-9-VM sshd[1765]: Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:34:27 r-9-VM sshd[1765]: pam_unix(sshd:session): session closed for user root Jan 16 10:35:01 r-9-VM CRON[1769]: pam_unix(cron:session): session opened for user root by (uid=0) --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- VR Logs : ============================================================ 1. ifconfig eth0 Link encap:Ethernet HWaddr 02:00:0c:43:00:02 inet addr:10.1.1.1 Bcast:10.1.1.255 Mask:255.255.255.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:20507 errors:0 dropped:0 overruns:0 frame:0 TX packets:11563 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:1533963 (1.4 MiB) TX bytes:9939565 (9.4 MiB) eth1 Link encap:Ethernet HWaddr 0e:00:a9:fe:03:12 inet addr:169.254.3.18 Bcast:169.254.255.255 Mask:255.255.0.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:53809 errors:0 dropped:0 overruns:0 frame:0 TX packets:42063 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:8224278 (7.8 MiB) TX bytes:7977935 (7.6 MiB) eth2 Link encap:Ethernet HWaddr 06:33:c4:00:00:0d inet addr:10.102.195.71 Bcast:10.102.195.255 Mask:255.255.252.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:525762888 errors:0 dropped:0 overruns:0 frame:0 TX packets:8664 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:499682970 (476.5 MiB) TX bytes:732206 (715.0 KiB) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 UP LOOPBACK RUNNING MTU:16436 Metric:1 RX packets:331 errors:0 dropped:0 overruns:0 frame:0 TX packets:331 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:0 RX bytes:29179 (28.4 KiB) TX bytes:29179 (28.4 KiB) 2. Nics NIC 1 Type Isolated Traffic Type Guest Network Name VM-1 Netmask 255.255.255.0 IP Address 10.1.1.1 ID 4925b18a-1b80-401f-994c-4c1c7f21f4d6 Network ID ddd99741-549d-4e23-adad-b489df77898d Isolation URI vlan://714 Broadcast URI vlan://714 NIC 2 Type Traffic Type Control Network Name Netmask 255.255.0.0 IP Address 169.254.3.18 ID b8919075-7479-4d6b-864a-9c68e807f428 Network ID 7a44608b-60a0-488a-b2db-2187fa346ef0 Isolation URI Broadcast URI NIC 3 (Default) Type Traffic Type Public Network Name Netmask 255.255.252.0 IP Address 10.102.195.71 ID 33c8ec2e-4956-4223-b1e2-1e5fcb795fcc Network ID 18d5e28a-ac84-4ed1-87a4-65346f4660f3 Isolation URI vlan://untagged Broadcast URI vlan://untagged Here we see that Nic3 i.e eth2 has the public IP and same is there in the cloud.log Tue Jan 8 11:32:37 UTC 2013 Executing cloud-early-config Tue Jan 8 11:32:37 UTC 2013 Detected that we are running inside kvm guest Tue Jan 8 11:32:37 UTC 2013 Patching scripts oldmd5=e1defa60190950fbd3d5e9c15c5b7c28 newmd5=89f718b371578db5f8caa40a1da141f1 Tue Jan 8 11:32:37 UTC 2013 Patching cloud service Tue Jan 8 11:32:38 UTC 2013 Rebooting system since we patched init scripts Tue Jan 8 11:32:41 UTC 2013 Setting up virtual router system vm Tue Jan 8 11:33:03 UTC 2013 Executing cloud-early-config Tue Jan 8 11:33:03 UTC 2013 Detected that we are running inside kvm guest Tue Jan 8 11:33:03 UTC 2013 Patching cloud service Tue Jan 8 11:33:04 UTC 2013 Setting up virtual router system vm Tue Jan 8 11:33:07 UTC 2013 Checking udev NIC assignment order changes Tue Jan 8 11:33:07 UTC 2013 Setting up dnsmasq Tue Jan 8 11:33:07 UTC 2013 Setting up apache web server Tue Jan 8 11:33:07 UTC 2013 Enable service dnsmasq = 1 Tue Jan 8 11:33:07 UTC 2013 Enable service haproxy = 1 Tue Jan 8 11:33:07 UTC 2013 Enable service cloud-passwd-srvr = 1 Tue Jan 8 11:33:07 UTC 2013 Enable service cloud = 0 Tue Jan 8 11:33:07 UTC 2013 cloud: Tuning rp_filter on public interfaces Tue Jan 8 11:33:07 UTC 2013 rpfilter public interfaces : eth2 Tue Jan 8 11:33:07 UTC 2013 cloud: disable rp_filter on public interfaces Tue Jan 8 11:33:07 UTC 2013 cloud: disable rp_filter on public interface: eth2 Tue Jan 8 11:33:07 UTC 2013 cloud: Enabling rp_filter on Non-public interfaces(eth0,eth1,lo) Tue Jan 8 11:33:07 UTC 2013 cloud: enable_fwding = 1 Tue Jan 8 11:33:07 UTC 2013 enable_fwding = 1 ------------------------------------------------------------------------------------------------------------------------------------- Management server logs : ============================================================ 1. Management server log 2013-01-16 16:04:21,867 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-7:null) Access granted to Acct[2-admin] to Domain:1/ by DomainChecker 2013-01-16 16:04:26,822 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null) Ping from 3 2013-01-16 16:04:29,777 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:null) Ping from 4 2013-01-16 16:04:30,975 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-2:null) Ping from 1 2013-01-16 16:04:33,776 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-2:null) submit async job-13, details: AsyncJobVO {id:13, userId: 2, accountId: 2, sessionKey: null, instanceType: None, instanceId: 2, cmd: com.cloud.api.commands.CreateVpnConnectionCmd, cmdOriginator: null, cmdInfo: {"id":"2","response":"json","sessionkey":"GDFeOLnqYO9IrSat5FlkpyhAxS8\u003d","s2scustomergatewayid":"5ea05ac3-eba6-475a-a7a7-e272117d7ded","ctxUserId":"2","s2svpngatewayid":"568f2fab-171d-4a58-8af3-7c75fa84e078","_":"1358332456155","ctxAccountId":"2","ctxStartEventId":"103"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 129936880108802, completeMsid: null, lastUpdated: null, lastPolled: null, created: null} 2013-01-16 16:04:33,780 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Executing com.cloud.api.commands.CreateVpnConnectionCmd for job-13 2013-01-16 16:04:33,785 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Sync job-13 execution on object vpc.2 2013-01-16 16:04:33,789 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) job com.cloud.api.commands.CreateVpnConnectionCmd for job-13 was queued, processing the queue. 2013-01-16 16:04:33,793 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Executing sync queue item: SyncQueueItemVO {id:5, queueId: 5, contentType: AsyncJob, contentId: 13, lastProcessMsid: 129936880108802, lastprocessNumber: 2, created: Wed Jan 16 16:04:33 IST 2013} 2013-01-16 16:04:33,794 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Schedule queued job-13 2013-01-16 16:04:33,798 DEBUG [cloud.async.SyncQueueManagerImpl] (Job-Executor-17:job-13) There is a pending process in sync queue(id: 5) 2013-01-16 16:04:33,800 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-18:job-13) Executing com.cloud.api.commands.CreateVpnConnectionCmd for job-13 2013-01-16 16:04:33,829 DEBUG [agent.transport.Request] (Job-Executor-18:job-13) Seq 1-1026775662: Sending { Cmd , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100101, [{"routing.Site2SiteVpnCfgCommand":{"create":true,"localPublicIp":"10.102.195.74","localGuestCidr":"10.1.1.1/16","localPublicGateway":"10.102.192.1","peerGatewayIp":"217.70.20.213","peerGuestCidrList":"192.168.10.0/24","ipsecPsk":"blablablablablabla","ikePolicy":"3des-md5","espPolicy":"3des-md5","ikeLifetime":86400,"espLifetime":3600,"dpd":false,"accessDetails":{"zone.network.type":"Advanced","router.ip":"169.254.0.4","router.name":"r-9-VM"},"wait":0}}] } 2013-01-16 16:04:33,988 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 1-1026775662: Processing: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100, [{"Answer":{"result":false,"details":"Configure site to site VPN failed due to bash: /opt/cloud/bin/ipsectunnel: No such file or directory","wait":0}}] } 2013-01-16 16:04:33,988 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-9:null) Seq 1-1026775662: No more commands found 2013-01-16 16:04:33,988 DEBUG [agent.transport.Request] (Job-Executor-18:job-13) Seq 1-1026775662: Received: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100, { Answer } } 2013-01-16 16:04:33,992 WARN [api.commands.CreateVpnConnectionCmd] (Job-Executor-18:job-13) Exception: com.cloud.exception.ResourceUnavailableException: Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN at com.cloud.network.vpn.Site2SiteVpnManagerImpl.startVpnConnection(Site2SiteVpnManagerImpl.java:343) at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34) at com.cloud.api.commands.CreateVpnConnectionCmd.execute(CreateVpnConnectionCmd.java:119) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138) at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) 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-16 16:04:33,999 WARN [cloud.api.ApiDispatcher] (Job-Executor-18:job-13) class com.cloud.api.ServerApiException : Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN 2013-01-16 16:04:33,999 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-18:job-13) Complete async job-13, jobStatus: 2, resultCode: 530, result: Error Code: 534 Error text: Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN 2013-01-16 16:04:34,021 DEBUG [cloud.async.SyncQueueManagerImpl] (Job-Executor-18:job-13) Sync queue (5) is currently empty 2013-01-16 16:04:35,944 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-01-16 16:04:36,089 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-01-16 16:04:36,679 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 1 routers. 2013-01-16 16:04:38,797 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-22:null) Async job-13 completed 2013-01-16 16:04:49,740 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running... 2013-01-16 16:04:49,794 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 3-578493520: Received: { Ans: , MgmtId: 129936880108802, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-01-16 16:04:49,881 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-1026775663: Received: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-01-16 16:05:04,596 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) HostStatsCollector is running... 2013-01-16 16:05:05,188 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-1026775664: Received: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } } 2013-01-16 16:05:05,944 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-01-16 16:05:06,090 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2. Catalina logs WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:) unable to find stats for account: 2 WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:) unable to find stats for account: 2 INFO [cloud.ha.HighAvailabilityManagerImpl] (HA-4:) checking health of usage server WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:) unable to find stats for account: 2 WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:) unable to find stats for account: 2 INFO [cloud.ha.HighAvailabilityManagerImpl] (HA-1:) checking health of usage server WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:) unable to find stats for account: 2 WARN [network.element.VpcVirtualRouterElement] (Job-Executor-14:job-11) Network Ntwk[200|Public|1] is not associated with any VPC WARN [network.element.VpcVirtualRouterElement] (Job-Executor-14:job-11) Network Ntwk[202|Control|3] is not associated with any VPC WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:) unable to find stats for account: 2 WARN [api.commands.CreateVpnConnectionCmd] (Job-Executor-18:job-13) Exception: com.cloud.exception.ResourceUnavailableException: Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN at com.cloud.network.vpn.Site2SiteVpnManagerImpl.startVpnConnection(Site2SiteVpnManagerImpl.java:343) at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34) at com.cloud.api.commands.CreateVpnConnectionCmd.execute(CreateVpnConnectionCmd.java:119) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138) at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) 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) WARN [cloud.api.ApiDispatcher] (Job-Executor-18:job-13) class com.cloud.api.ServerApiException : Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN > s2s VPN trouble > --------------- > > Key: CLOUDSTACK-938 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-938 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the default.) > Components: Network Controller > Affects Versions: 4.0.0, 4.0.1 > Environment: CentOS 6.3 x86_64 > CS - 4.0.1-0.11 > Reporter: Richard Shevel > Priority: Blocker > Fix For: 4.0.1, 4.1.0 > > Attachments: after_restart_VPC.zip, auth.log, catalina.zip, management-server_afer_upgrade2.zip, management-server_after_upgrade.zip, management-server.zip, messages, r-292-vm_log.tar.gz > > > Dear colleagues, the problem is clearly a bug: > I created a VPC > Further, in my VPN Customer Gateway to the settings > Gateway 217.70.20.213 > CIDR list 192.168.10.0/24 > IPsec Preshared-Key blablablablablabla > IKE Encryption 3des > IKE Hash md5 > IKE DH None > ESP Encryption 3des > ESP Hash md5 > Perfect Forward Secrecy None > IKE lifetime (second) 86 400 > ESP Lifetime (second) 28 800 > Dead Peer Detection Yes > In the setting of VPC I create VPN Gateway > When creating a VPN Connection get the error: > Resource [Site2SiteVpnConnection:15] is unreachable: Failed to apply site-to-site VPN > catalina.out: > WARN [cloud.api.ApiDispatcher] (Job-Executor-11:job-463) class com.cloud.api.ServerApiException : Resource [Site2SiteVpnConnection:15] is unreachable: Failed to apply site-to-site VPN > WARN [cloud.async.AsyncJobManagerImpl] (Job-Executor-11:job-463) Unable to unregister active job 463 from JMX monitoring > WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Unable to update router r-288-VM's VPN connection status > WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Unable to update router r-288-VM's VPN connection status > WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Unable to update router r-288-VM's VPN connection status > WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Unable to update router r-288-VM's VPN connection status > WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:) Unable to update router r-288-VM's VPN connection status > management-server.log: > 2013-01-09 21:27:54,587 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-4:null) Ping from 5 > 2013-01-09 21:27:54,623 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-2:null) Ping from 3 > 2013-01-09 21:28:17,546 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM > 2013-01-09 21:28:17,656 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy > 2013-01-09 21:28:18,306 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 3 routers. > 2013-01-09 21:28:18,316 DEBUG [agent.transport.Request] (RouterStatusMonitor-1:null) Seq 5-223284290: Sending { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"CheckS2SVpnConnectionsCommand":{"vpnIps":[],"accessDetails":{"router.ip":"169.254.1.232","router.name":"r-288-VM"},"wait":30}}] } > 2013-01-09 21:28:18,458 DEBUG [agent.transport.Request] (AgentManager-Handler-3:null) Seq 5-223284290: Processing: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"CheckS2SVpnConnectionsAnswer":{"ipToConnected":{},"ipToDetail":{},"details":"CheckS2SVpnConneciontsCommand failed","result":false,"wait":0}}] } > 2013-01-09 21:28:18,458 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-3:null) Seq 5-223284290: No more commands found > 2013-01-09 21:28:18,458 DEBUG [agent.transport.Request] (RouterStatusMonitor-1:null) Seq 5-223284290: Received: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, { CheckS2SVpnConnectionsAnswer } } > 2013-01-09 21:28:18,458 DEBUG [agent.manager.AgentManagerImpl] (RouterStatusMonitor-1:null) Details from executing class com.cloud.agent.api.CheckS2SVpnConnectionsCommand: CheckS2SVpnConneciontsCommand failed > 2013-01-09 21:28:18,458 WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Unable to update router r-288-VM's VPN connection status > 2013-01-09 21:28:43,063 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) StorageCollector is running... > 2013-01-09 21:28:43,117 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 17-292881626: Received: { Ans: , MgmtId: 52239887788, via: 17, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } > 2013-01-09 21:28:45,185 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 3-1166872144: Received: { Ans: , MgmtId: 52239887788, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } > 2013-01-09 21:28:47,545 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM > 2013-01-09 21:28:47,655 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy > 2013-01-09 21:28:48,305 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 3 routers. > 2013-01-09 21:28:48,328 DEBUG [agent.transport.Request] (RouterStatusMonitor-1:null) Seq 5-223284291: Sending { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"CheckS2SVpnConnectionsCommand":{"vpnIps":[],"accessDetails":{"router.ip":"169.254.1.232","router.name":"r-288-VM"},"wait":30}}] } > 2013-01-09 21:28:48,430 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 5-223284291: Processing: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"CheckS2SVpnConnectionsAnswer":{"ipToConnected":{},"ipToDetail":{},"details":"CheckS2SVpnConneciontsCommand failed","result":false,"wait":0}}] } > 2013-01-09 21:28:48,430 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-9:null) Seq 5-223284291: No more commands found > 2013-01-09 21:28:48,430 DEBUG [agent.transport.Request] (RouterStatusMonitor-1:null) Seq 5-223284291: Received: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, { CheckS2SVpnConnectionsAnswer } } > 2013-01-09 21:28:48,430 DEBUG [agent.manager.AgentManagerImpl] (RouterStatusMonitor-1:null) Details from executing class com.cloud.agent.api.CheckS2SVpnConnectionsCommand: CheckS2SVpnConneciontsCommand failed > 2013-01-09 21:28:48,430 WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Unable to update router r-288-VM's VPN connection status > 2013-01-09 21:28:49,298 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-7:null) Ping from 11 > 2013-01-09 21:28:49,299 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null) Ping from 17 > 2013-01-09 21:28:51,594 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) HostStatsCollector is running... -- 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