No I haven't tried different algorithms yet, that was the next thing I
was going to try but I was trying to hold off on that until I had
further information. The pfSense firewall is actually a replacement for
a failed Netgear FVX538 which already had an AES-256 based VPN setup. I
was trying to preserve those settings as the PIX515e is on a production
system and I want to change as little as possible, but I will try to
drop down to less secure algorithms if that appears to be the only
option. However, there appears to be some exchange between the
firewalls. Here's a few iterations of the cycle that happens:
Oct 14 12:36:58 racoon: INFO: initiate new phase 1 negotiation:
216.62.203.233[500]<=>206.127.8.197[500]
Oct 14 12:36:58 racoon: INFO: begin Identity Protection mode.
Oct 14 12:36:58 racoon: INFO: received Vendor ID:
draft-ietf-ipsra-isakmp-xauth-06.txt
Oct 14 12:36:58 racoon: INFO: received Vendor ID: DPD
Oct 14 12:36:58 racoon: INFO: received Vendor ID: CISCO-UNITY
Oct 14 12:37:07 racoon: ERROR: phase2 negotiation failed due to time
up waiting for phase1. ESP 206.127.8.197[500]->216.62.203.233[500]
Oct 14 12:37:07 racoon: INFO: delete phase 2 handler.
Oct 14 12:37:20 racoon: INFO: request for establishing IPsec-SA was
queued due to no phase1 found.
Oct 14 12:37:29 racoon: ERROR: phase2 negotiation failed due to time
up waiting for phase1. ESP 206.127.8.197[500]->216.62.203.233[500]
Oct 14 12:37:29 racoon: INFO: delete phase 2 handler.
Oct 14 12:37:42 racoon: INFO: request for establishing IPsec-SA was
queued due to no phase1 found.
Oct 14 12:37:51 racoon: ERROR: phase2 negotiation failed due to time
up waiting for phase1. ESP 206.127.8.197[500]->216.62.203.233[500]
Oct 14 12:37:51 racoon: INFO: delete phase 2 handler.
Oct 14 12:37:58 racoon: ERROR: phase1 negotiation failed due to time
up. 4c0f83756ba7c7cc:237eb55e492c3461
Oct 14 12:38:04 racoon: INFO: IPsec-SA request for 206.127.8.197
queued due to no phase1 found.
Oct 14 12:38:04 racoon: INFO: initiate new phase 1 negotiation:
216.62.203.233[500]<=>206.127.8.197[500]
Oct 14 12:38:04 racoon: INFO: begin Identity Protection mode.
Oct 14 12:38:04 racoon: INFO: received Vendor ID:
draft-ietf-ipsra-isakmp-xauth-06.txt
Oct 14 12:38:04 racoon: INFO: received Vendor ID: DPD
Oct 14 12:38:04 racoon: INFO: received Vendor ID: CISCO-UNITY
Oct 14 12:38:13 racoon: ERROR: phase2 negotiation failed due to time
up waiting for phase1. ESP 206.127.8.197[500]->216.62.203.233[500]
Oct 14 12:38:13 racoon: INFO: delete phase 2 handler.
Oct 14 12:38:26 racoon: INFO: request for establishing IPsec-SA was
queued due to no phase1 found.
Oct 14 12:38:35 racoon: ERROR: phase2 negotiation failed due to time
up waiting for phase1. ESP 206.127.8.197[500]->216.62.203.233[500]
Oct 14 12:38:35 racoon: INFO: delete phase 2 handler.
Oct 14 12:38:48 racoon: INFO: request for establishing IPsec-SA was
queued due to no phase1 found.
Oct 14 12:38:57 racoon: ERROR: phase2 negotiation failed due to time
up waiting for phase1. ESP 206.127.8.197[500]->216.62.203.233[500]
Oct 14 12:38:57 racoon: INFO: delete phase 2 handler.
Oct 14 12:39:04 racoon: ERROR: phase1 negotiation failed due to time
up. 0f2d11d859b2019d:237eb55e14e46837
Oct 14 12:39:10 racoon: INFO: IPsec-SA request for 206.127.8.197
queued due to no phase1 found.
Oct 14 12:39:10 racoon: INFO: initiate new phase 1 negotiation:
216.62.203.233[500]<=>206.127.8.197[500]
Oct 14 12:39:10 racoon: INFO: begin Identity Protection mode.
Oct 14 12:39:10 racoon: INFO: received Vendor ID:
draft-ietf-ipsra-isakmp-xauth-06.txt
Oct 14 12:39:10 racoon: INFO: received Vendor ID: DPD
Oct 14 12:39:10 racoon: INFO: received Vendor ID: CISCO-UNITY
Oct 14 12:39:19 racoon: ERROR: phase2 negotiation failed due to time
up waiting for phase1. ESP 206.127.8.197[500]->216.62.203.233[500]
Oct 14 12:39:19 racoon: INFO: delete phase 2 handler.
Oct 14 12:39:32 racoon: INFO: request for establishing IPsec-SA was
queued due to no phase1 found.
Oct 14 12:39:41 racoon: ERROR: phase2 negotiation failed due to time
up waiting for phase1. ESP 206.127.8.197[500]->216.62.203.233[500]
Oct 14 12:39:41 racoon: INFO: delete phase 2 handler.
Now all I see are timeouts for Phase1. I don't see any mismatches. The
only errors I see are on local socket setup:
*racoon: WARNING: setsockopt(UDP_ENCAP_ESPINUDP_NON_IKE): Invalid argument *
The above is what I think is specifically causing the problem, and this
happens before Phase1 immediately after applying VPN settings. I don't
know exactly what this setsockopt() call is supposed to do, but it looks
like racoon is trying to enable an option that the BSD kernel doesn't
support. From a little googling, it looks like IPSEC_NAT_T support
needs to be compiled into the BSD kernel for this to work. I'm more of
a Linux guy, is there someway to check for this in the pfSense kernel?
Do other pfSense users get this error on working VPN tunnels?
On the PIX515e side, I'm not sure what logging information to give you,
not exactly a Cisco expert. When I do a 'show ipsec sa' no security
association has been setup. There's no SPI or ESP information. Do you
want packet logging or something?
-ryan
Captain Bablam wrote:
Good morning Ryan,
Can you send the pix debugs as well? I think you are right, this
looks like a phase 1 setup problem, it maybe that PF and the pix are
having trouble playing nice on the negotiation of your current phase 1
params. If you send the pix debugs I think I will have a better idea
of where the negotiation is failing. Also did you try different hash
and encryption algs for phase 1 as a test?
Wade B
On 10/14/06, J. Ryan Earl <[EMAIL PROTECTED]> wrote:
I'm trying out a pfSense based firewall for my local office, and I'm
trying to setup a VPN to a Cisco PIX 515e in one of our production
datacenters. I believe I am encountering some sort of error on the
pfSense firewall. Stage1 exchange continually times out. I've
quadruple checked all of the VPN parameters on both side and they are
consistent. I notice whenever I "apply" VPN changes I get the following
errors at the beginning of the VPN system log:
Oct 14 11:19:53 racoon: INFO: @(#)ipsec-tools 0.6.6
(http://ipsec-tools.sourceforge.net)
Oct 14 11:19:53 racoon: INFO: @(#)This product linked OpenSSL
0.9.7e-p1 25 Oct 2004 (http://www.openssl.org/)
Oct 14 11:19:53 racoon: INFO: fe80::1%lo0[500] used as isakmp port
(fd=13)
Oct 14 11:19:53 racoon: INFO: ::1[500] used as isakmp port (fd=14)
Oct 14 11:19:53 racoon: INFO: 127.0.0.1[500] used as isakmp port
(fd=15)
Oct 14 11:19:53 racoon: WARNING:
setsockopt(UDP_ENCAP_ESPINUDP_NON_IKE): Invalid argument
Oct 14 11:19:53 racoon: INFO: 192.168.2.254[500] used as isakmp port
(fd=16)
Oct 14 11:19:53 racoon: WARNING:
setsockopt(UDP_ENCAP_ESPINUDP_NON_IKE): Invalid argument
Oct 14 11:19:53 racoon: INFO: fe80::250:daff:fe28:ca4%xl2[500] used
as isakmp port (fd=17)
Oct 14 11:19:53 racoon: INFO: 216.62.203.233[500] used as isakmp
port (fd=18)
Oct 14 11:19:53 racoon: WARNING:
setsockopt(UDP_ENCAP_ESPINUDP_NON_IKE): Invalid argument
Oct 14 11:19:53 racoon: INFO: fe80::201:2ff:fe3f:58a7%xl1[500] used
as isakmp port (fd=19)
Oct 14 11:19:53 racoon: INFO: 209.198.142.210[500] used as isakmp
port (fd=20)
Oct 14 11:19:53 racoon: WARNING:
setsockopt(UDP_ENCAP_ESPINUDP_NON_IKE): Invalid argument
Oct 14 11:19:53 racoon: INFO: fe80::201:2ff:fe3c:a553%xl0[500] used
as isakmp port (fd=21)
I'm thinking this is the root cause of my problem, not a difference in
configuration between the VPN tunnel end-points. Does anyone know what
would cause this and how to fix it?
Thank in advance,
-ryan
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
