[
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
