incubator-cloudstack-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Abhinav Roy (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-938) s2s VPN trouble
Date Thu, 17 Jan 2013 05:46:12 GMT

    [ 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

Mime
View raw message