pfSense

at last i found my periodically ipsec disconnect problem after researching in redmine,i'm using pptp from home to connect corporate PF 2.0 RC1 firewall.
Same issue as Chris Buechler described in bug 1421 (http://redmine.pfsense.org/issues/1421),today i noticed that after my pptp disconnect all ipsec tunnels disconnecting.I can supply any log and configs for deeper research.

my pf info

2.0-RC1 (i386)
built on Tue Apr 12 11:38:49 EDT 2011

any fix for this bug?

is it possible to rise priority from normal to high?because i have to disable PPTP VPN on my production firewalls with 2.0 rc1 or downgrade to pf 1.2.3

Only if you're willing to pay to have it fixed. Otherwise it gets fixed when we get to it.

Hi,

Im having the same problem on my pf box.

And it would appreciate if this is rise priority to high since Pptp is the only vpn solution that works out of the box on the apple mobile devices(iphone,ipad,itouch), since neither Ipsec, Openvpn or L2tp work on these devices. Also Openvpn free solutions for mac osx is slow compared to windows free solutions ( I have test it with a pay solution for mac and works good). So although this may seem like a small bug it does disable vpn out of the box solutions for most of the mac comunity using pf box with pptp and ipsec conections at work.

Currently my pf version is:
2.0-RC1 (amd64)
built on Thu Apr 14 17:41:34 EDT 2011

IPsec works fine with iOS devices. The free OpenVPN client on OS X works fine too, it uses the same underlying software as Viscosity, there is functionally no difference beyond the GUI.

We can't replicate this, I can connect and disconnect PPTP all day long and IPsec never drops a packet. Someone who can will need to do some digging and add details on exactly what causes this. Or at least post full System, IPsec and PPTP logs here from before and after it happens.

Just a guess here, but last I knew, PPTP issued a pfctl -k (src) -k (dst) when disconnecting, and if the IPs involved there just happened to be the same two endpoints of an IPsec tunnel, it would kill states between those IPs and drop the tunnel. I don't remember if the intention of the pfctl -k was to kill between the internal IP and other endpoints or if it was external, but it's possible that some shift in the parameters is having an unintended side effect.

Chris,

For the ipsec stuff:
If you can give me a link for a tutorial to get the ipsec working properly on ios i would apreciate it, because i have looked at a few forums post that always sugest pptp as ipsec never managed to connect.

About the logs:
I did spend some time looking at the logs of pptp, ipsec. I will ask for a test window next weekend, so I can generate some logs replicating this problem. Besides the ipsec and pptp tunnel logs, do need any other log in specific?

PS: From my perspective all I got it to see its that allways about 1 to 2 min after a user successfully disconnects ( pulling the plug on the connection usually does not drop the tunnels ) from pptp, the ipsec tunnels send a new handshake thinking that the tunnels went down, after that the only way bring the tunnels back is turn off the ipsec service, clicking start on the gui does not bring them back up. Disabling DPD dosent drop the tunnels from the gui perspective but does start to give timeouts. Also I got to see the other firewall log and it does not show any outstanding log information about the drop of the tunnel.

Jim P wrote:

Just a guess here, but last I knew, PPTP issued a pfctl -k (src) -k (dst) when disconnecting, and if the IPs involved there just happened to be the same two endpoints of an IPsec tunnel, it would kill states between those IPs and drop the tunnel. I don't remember if the intention of the pfctl -k was to kill between the internal IP and other endpoints or if it was external, but it's possible that some shift in the parameters is having an unintended side effect.

Jim,
In my case endpoints of the ipsec tunnel are different from the pptp clients, the only thing in common is the ip of the pf box. But maybe it has something to do with the pfctl -k command since it usually drops if there is a successful logout from the pptp client.

Sorry for the double post just refreshed my browser now.

need exact logs, copy and paste.

I don't think it's state killing related, Ermal had someone remove that and it didn't change anything, and ESP and UDP traffic will just open a new state immediately upon receipt of the next packet. I also tried it a few times earlier between the same two public IPs as an IPsec connection and it has no effect.

I am trying to replicate after updating to 2.0-RC1 (amd64) built on Sat May 7 23:04:11 EDT 2011 , but i am unable to replicate it as it happens under high load.

But since i am testing remotely I found that disconnecting from pptp does drop a openvpn connection on a different computer with the same end points. So it seems PPTP still seems do drop stuff not related to the ports it uses. Also Ipsec logs still shows, racoon: WARNING: unrecognized route message with rtm_type: 4, every time a pptp user connects or disconnects, and im gussing that this error is what drops the ipsec tunnels under highload, a simple ping is not enough to timeout and drop the tunnel.

Openvpn Log: http://pastebin.com/Zea4nEJy
PPTP Log: http://pastebin.com/UvNyxzrE
IPsec Log: http://pastebin.com/Nv1H4YU3

I'm also experiencing the same issue and have had to disable PPTP on our 2.0-RC1 (i386). I get the same message in the logs as referenced above:

racoon: WARNING: unrecognized route message with rtm_type: 4

I am getting this error message repeated 4 times in the log, and appears to be for each IPSEC tunnel I have established. The PPTP tunnels stay active, whereas the IPSEC tunnels drop after about 1 minute regardless if there is constant traffic going across the link or not. After the IPSEC tunnel is dropped, the tunnels cannot be re-established unless IPSEC is disabled and re-enabled in the settings page.

I will attempt to paste some logs tonight when I can freely take down our IPSEC tunnels, but the logs posted by Harry above pretty much reflect exactly what i am seeing in mine.

Thanks to anyone who takes a look into this or has any input. I really appreciate it!

The "unrecognized route message ..." log indicates some sort of routing table change that could impact racoon. Run 'route monitor' via SSH option 8 then replicate the issue, and post the full output of that command here.

With an IPSEC connection running, this is the log when I connected to the PPTP, then disconnected. After the IPSEC will not work until you restart it.

got message of size 172 on Thu May 19 23:38:52 2011
RTM_GET: Report Metrics: len 172, pid: 13095, seq 2, errno 0, flags:<UP,DONE>
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK>
192.168.2.0 (255) ffff ffff ff

got message of size 172 on Thu May 19 23:38:52 2011
RTM_DELETE: Delete Route: len 172, pid: 13095, seq 3, errno 22, flags:<UP,DONE,LLINFO>
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK>
192.168.2.192 (255) ffff ffff ff

got message of size 172 on Thu May 19 23:38:52 2011
RTM_GET: Report Metrics: len 172, pid: 13095, seq 4, errno 0, flags:<UP,DONE>
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK>
192.168.2.0 (255) ffff ffff ff

got message of size 172 on Thu May 19 23:38:52 2011
RTM_ADD: Add Route: len 172, pid: 13095, seq 5, errno 0, flags:<DONE,LLINFO,STATIC,PROTO2>
locks: inits: <expire>
sockaddrs: <DST,GATEWAY,NETMASK>
192.168.2.192 0.90.fb.2a.9.e5 (0) 0 ffff ffff

got message of size 96 on Thu May 19 23:38:57 2011
RTM_IFINFO: iface status change: len 96, if# 9, link: unknown, flags:<UP,PTP,RUNNING,NOARP,SIMPLEX,MULTICAST>

got message of size 164 on Thu May 19 23:38:57 2011
RTM_GET: Report Metrics: len 164, pid: 14528, seq 1, errno 0, flags:<UP,HOST,DONE>
locks: inits:
sockaddrs: <DST,GATEWAY>
192.168.2.192

got message of size 172 on Thu May 19 23:38:57 2011
RTM_GET: Report Metrics: len 172, pid: 14528, seq 2, errno 0, flags:<UP,DONE>
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK>
192.168.2.0 (255) ffff ffff ff

got message of size 172 on Thu May 19 23:38:57 2011
RTM_DELETE: Delete Route: len 172, pid: 14528, seq 3, errno 0, flags:<UP,DONE,LLINFO>
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK>
192.168.2.192 (255) ffff ffff ff

got message of size 164 on Thu May 19 23:38:57 2011
RTM_DELETE: Delete Route: len 164, pid: 0, seq 0, errno 0, flags:<HOST>
locks: inits:
sockaddrs: <DST,GATEWAY>
192.168.2.192

got message of size 116 on Thu May 19 23:38:57 2011
RTM_DELADDR: address being removed from iface: len 116, metric 0, flags:<UP>
sockaddrs: <NETMASK,IFP,IFA,BRD>
255.255.255.255 pptpd0 mail.iisrp.com 192.168.2.192

got message of size 96 on Thu May 19 23:38:57 2011
RTM_IFINFO: iface status change: len 96, if# 9, link: unknown, flags:<PTP,RUNNING,NOARP,SIMPLEX,MULTICAST>

got message of size 96 on Thu May 19 23:38:57 2011
RTM_IFINFO: iface status change: len 96, if# 9, link: unknown, flags:<PTP,NOARP,SIMPLEX,MULTICAST>

Still replicated this bug after updating to 2.0-RC2 (amd64) built on Thu Jun 2 10:50:48 EDT 2011.

I had the ipsec tunnels running and decided to active the pptp to try to replicated, I connected a user leaved it connected for sometime and then decided to disconnect some time after all tunnels went down. This time i used radius for the pptp and it showed more log in the pptp after disconect.

Jun 3 10:11:59 <-- someuser 192.168.202.120
Jun 3 09:28:11 --> someuser 192.168.202.120

PPTP Log: http://pastebin.com/KVDMTz4m
IPsec Log: http://pastebin.com/3xTPYbEp

harry,same problem i have got on 2.0-RC2 (i386),problem not resolved.I think it's not normal priority case because of PPTP and IPSEC are coorporate futures.Our developers have to rise priority.

I've got the same problem on a 2.0-RC2 (i386)built on Mon Jun 6 00:12:42 EDT 2011 running under vmWare.
the problem is not only when the user disconnects, but also when a user forgets to disconnect and the PPTP connection drops. I've got to restart the racoon service after this happens.

Luca Sari wrote:

I've got the same problem on a 2.0-RC2 (i386)built on Mon Jun 6 00:12:42 EDT 2011 running under vmWare.
the problem is not only when the user disconnects, but also when a user forgets to disconnect and the PPTP connection drops. I've got to restart the racoon service after this happens.

Luca,
Since the devs seem unable to replicate this bug. Could you make a clone of your vmware minus sensitive stuff, available for the dev to see if they are finally able to replicate the bug and fix it.

Devs,
Please rise the priority, as Hafiz said "PPTP and IPSEC are coorporate futures". And Mobile Ipsec or OpenVpn ( for some devices ) works most of the time, but sometimes the ports are not open to our employees in our clients corporate networks.

Harry it's so simple to replicate the bug.

Steps to replicate bug.

1)Make ipsec VPN tunnel between 2 PF 2.0RC2,
2)Configure Pptp vpn server on one of PF's.
3)Make pptp client connection to pptp vpn server and disconnect.
4)After pptp client disconnect,see dropped ipsec vpn tunnel.

Chris Buechler wrote:

We can't replicate this, I can connect and disconnect PPTP all day long and IPsec never drops a packet. Someone who can will need to do some digging and add details on exactly what causes this. Or at least post full System, IPsec and PPTP logs here from before and after it happens.

Hafiz,
Im not part of the dev team, I have replicated the bug. But Chris Buechler who is one of the developers could not replicate it. Thats why I have been trying to provide as much log as posible.

But your steps could be updated into the description of this ticket.

Try it with 90ecc0b62f8b363d9497b4754133738edb9bc633

Harry Gonzalez wrote:

Luca Sari wrote:

I've got the same problem on a 2.0-RC2 (i386)built on Mon Jun 6 00:12:42 EDT 2011 running under vmWare.
the problem is not only when the user disconnects, but also when a user forgets to disconnect and the PPTP connection drops. I've got to restart the racoon service after this happens.

Luca,
Since the devs seem unable to replicate this bug. Could you make a clone of your vmware minus sensitive stuff, available for the dev to see if they are finally able to replicate the bug and fix it.

Devs,
Please rise the priority, as Hafiz said "PPTP and IPSEC are coorporate futures". And Mobile Ipsec or OpenVpn ( for some devices ) works most of the time, but sometimes the ports are not open to our employees in our clients corporate networks.

Harry, even if I copy the whole machine, they wouldn't be able to connect to my IPSec tunnels, so it'll be useless...
the only thing I can say is that I have more than only 1 user configured for the PPTP, and 4 different phase 1 ipsec tunnels, with some of them with 2 phase 2. what about the others that have the same problem? do you all have only 1 phase 1 and 1 phase 2 or do you have different type of configuration?

Jim same problem is continued ,i have to restart racoon service after pptp client disconnect,here is log.

Jun 21 13:25:41 racoon: [FabMetro]: INFO: IPsec-SA established: ESP xxx.xxx.xxx.xxx⁵⁰⁰->yyy.yyy.yyy.yyyy⁵⁰⁰ spi=59103446(0x385d8d6)
Jun 21 13:25:41 racoon: [FabMetro]: INFO: IPsec-SA established: ESP xxx.xxx.xxx.xxx⁵⁰⁰->yyy.yyy.yyy.yyyy⁵⁰⁰ spi=253697681(0xf1f1e91)
Jun 21 13:25:41 racoon: [FabMetro]: INFO: initiate new phase 2 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:25:40 racoon: [FabMetro]: INFO: ISAKMP-SA established xxx.xxx.xxx.xxx⁵⁰⁰-yyy.yyy.yyy.yyyy⁵⁰⁰ spi:057f71db730144e8:1617c77fcaaaf4d2
Jun 21 13:25:40 racoon: INFO: received broken Microsoft ID: FRAGMENTATION
Jun 21 13:25:40 racoon: INFO: received Vendor ID: DPD
Jun 21 13:25:40 racoon: INFO: begin Identity Protection mode.
Jun 21 13:25:40 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:25:40 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:25:39 racoon: ERROR: such policy already exists. anyway replace it: 192.168.0.0/16⁰ 192.168.55.0/24⁰ proto=any dir=in
Jun 21 13:25:39 racoon: ERROR: such policy already exists. anyway replace it: 192.168.55.0/24⁰ 192.168.0.0/16⁰ proto=any dir=out
Jun 21 13:25:39 racoon: ERROR: such policy already exists. anyway replace it: 192.168.55.0/24⁰ 192.168.55.1/32⁰ proto=any dir=in
Jun 21 13:25:39 racoon: ERROR: such policy already exists. anyway replace it: 192.168.55.1/32⁰ 192.168.55.0/24⁰ proto=any dir=out
Jun 21 13:25:39 racoon: INFO: unsupported PF_KEY message REGISTER
Jun 21 13:25:39 racoon: [Self]: INFO: xxx.xxx.xxx.xxx⁵⁰⁰ used as isakmp port (fd=15)
Jun 21 13:25:39 racoon: [Self]: INFO: xxx.xxx.xxx.xxx⁵⁰⁰ used for NAT-T
Jun 21 13:25:39 racoon: [Self]: INFO: xxx.xxx.xxx.xxx⁴⁵⁰⁰ used as isakmp port (fd=14)
Jun 21 13:25:39 racoon: [Self]: INFO: xxx.xxx.xxx.xxx⁴⁵⁰⁰ used for NAT-T
Jun 21 13:25:39 racoon: INFO: Reading configuration from "/var/etc/racoon.conf"
Jun 21 13:25:39 racoon: INFO: (#)This product linked OpenSSL 0.9.8n 24 Mar 2010 (http://www.openssl.org/)
Jun 21 13:25:39 racoon: INFO: (#)ipsec-tools 0.8.0 (http://ipsec-tools.sourceforge.net)
Jun 21 13:25:34 racoon: INFO: racoon process 20249 shutdown
Jun 21 13:25:34 racoon: INFO: caught signal 15
Jun 21 13:25:18 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:25:18 racoon: ERROR: phase1 negotiation failed due to send error. 8cc71341ac3d21b4:0000000000000000
Jun 21 13:25:18 racoon: INFO: begin Identity Protection mode.
Jun 21 13:25:18 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:25:18 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:25:13 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:25:13 racoon: ERROR: phase1 negotiation failed due to send error. 0ef4b4866d2f53b4:0000000000000000
Jun 21 13:25:13 racoon: INFO: begin Identity Protection mode.
Jun 21 13:25:13 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:25:13 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:49 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:49 racoon: ERROR: phase1 negotiation failed due to send error. c295413d3219fe18:0000000000000000
Jun 21 13:24:49 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:49 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:49 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:43 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:43 racoon: ERROR: phase1 negotiation failed due to send error. 0a00ca3daeb59162:0000000000000000
Jun 21 13:24:43 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:43 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:43 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:26 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:26 racoon: ERROR: phase1 negotiation failed due to send error. de0cce45d3a7e540:0000000000000000
Jun 21 13:24:26 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:26 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:26 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:15 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:15 racoon: ERROR: phase1 negotiation failed due to send error. 09cc7c4806aabbc4:0000000000000000
Jun 21 13:24:15 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:15 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:15 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:05 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:05 racoon: ERROR: phase1 negotiation failed due to send error. 995a69388413a05f:0000000000000000
Jun 21 13:24:05 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:05 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:05 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:00 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:00 racoon: ERROR: phase1 negotiation failed due to send error. 9e9b6a57389f66dd:0000000000000000
Jun 21 13:24:00 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:00 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:00 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:23:41 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:23:41 racoon: ERROR: phase1 negotiation failed due to send error. e364f27534a4b502:0000000000000000
Jun 21 13:23:41 racoon: INFO: begin Identity Protection mode.
Jun 21 13:23:41 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:23:41 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:23:39 racoon: [FabMetro]: INFO: ISAKMP-SA deleted xxx.xxx.xxx.xxx⁵⁰⁰-yyy.yyy.yyy.yyyy⁵⁰⁰ spi:b5af5953c8f51632:148c68101e17ec82
Jun 21 13:23:39 racoon: INFO: purged ISAKMP-SA spi=b5af5953c8f51632:148c68101e17ec82.
Jun 21 13:23:39 racoon: INFO: purging ISAKMP-SA spi=b5af5953c8f51632:148c68101e17ec82.
Jun 21 13:23:39 racoon: [FabMetro]: [yyy.yyy.yyy.yyyy] INFO: DPD: remote (ISAKMP-SA spi=b5af5953c8f51632:148c68101e17ec82) seems to be dead.
Jun 21 13:23:39 racoon: [FabMetro]: INFO: ISAKMP-SA deleted xxx.xxx.xxx.xxx⁵⁰⁰-yyy.yyy.yyy.yyyy⁵⁰⁰ spi:83af516d52d83868:007ab32b5aa9c8c4
Jun 21 13:23:39 racoon: INFO: purged ISAKMP-SA spi=83af516d52d83868:007ab32b5aa9c8c4.
Jun 21 13:23:39 racoon: INFO: purged IPsec-SA spi=233684429.
Jun 21 13:23:39 racoon: INFO: Unknown IPsec-SA spi=233684429, hmmmm?
Jun 21 13:23:39 racoon: INFO: purged IPsec-SA spi=136266941.
Jun 21 13:23:39 racoon: INFO: Unknown IPsec-SA spi=136266941, hmmmm?
Jun 21 13:23:39 racoon: INFO: purging ISAKMP-SA spi=83af516d52d83868:007ab32b5aa9c8c4.
Jun 21 13:23:39 racoon: [FabMetro]: [yyy.yyy.yyy.yyyy] INFO: DPD: remote (ISAKMP-SA spi=83af516d52d83868:007ab32b5aa9c8c4) seems to be dead.
Jun 21 13:23:04 racoon: ERROR: failed to start post getspi.
Jun 21 13:23:04 racoon: ERROR: phase2 negotiation failed due to send error. b5af5953c8f51632:148c68101e17ec82:0000f009
Jun 21 13:23:04 racoon: [FabMetro]: INFO: IPsec-SA expired: ESP/Tunnel yyy.yyy.yyy.yyyy⁵⁰⁰->xxx.xxx.xxx.xxx⁵⁰⁰ spi=233684429(0xdedbdcd)
Jun 21 13:23:04 racoon: [FabMetro]: INFO: initiate new phase 2 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:23:04 racoon: [FabMetro]: INFO: IPsec-SA expired: ESP xxx.xxx.xxx.xxx⁵⁰⁰->yyy.yyy.yyy.yyyy⁵⁰⁰ spi=136266941(0x81f44bd)
Jun 21 13:22:29 racoon: WARNING: unrecognized route message with rtm_type: 4
Jun 21 13:22:29 racoon: WARNING: unrecognized route message with rtm_type: 4
Jun 21 13:22:03 racoon: WARNING: unrecognized route message with rtm_type: 4
Jun 21 13:22:03 racoon: WARNING: unrecognized route message with rtm_type: 4
Jun 21 13:22:03 racoon: WARNING: unrecognized route message with rtm_type: 4

Hafiz Rafiyev wrote:

Jim same problem is continued ,i have to restart racoon service after pptp client disconnect,here is log.

2.0-RC3 (i386) built on Mon Jun 20 20:22:37 EDT 2011

Jun 21 13:25:41 racoon: [FabMetro]: INFO: IPsec-SA established: ESP xxx.xxx.xxx.xxx⁵⁰⁰->yyy.yyy.yyy.yyyy⁵⁰⁰ spi=59103446(0x385d8d6)
Jun 21 13:25:41 racoon: [FabMetro]: INFO: IPsec-SA established: ESP xxx.xxx.xxx.xxx⁵⁰⁰->yyy.yyy.yyy.yyyy⁵⁰⁰ spi=253697681(0xf1f1e91)
Jun 21 13:25:41 racoon: [FabMetro]: INFO: initiate new phase 2 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:25:40 racoon: [FabMetro]: INFO: ISAKMP-SA established xxx.xxx.xxx.xxx⁵⁰⁰-yyy.yyy.yyy.yyyy⁵⁰⁰ spi:057f71db730144e8:1617c77fcaaaf4d2
Jun 21 13:25:40 racoon: INFO: received broken Microsoft ID: FRAGMENTATION
Jun 21 13:25:40 racoon: INFO: received Vendor ID: DPD
Jun 21 13:25:40 racoon: INFO: begin Identity Protection mode.
Jun 21 13:25:40 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:25:40 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:25:39 racoon: ERROR: such policy already exists. anyway replace it: 192.168.0.0/16⁰ 192.168.55.0/24⁰ proto=any dir=in
Jun 21 13:25:39 racoon: ERROR: such policy already exists. anyway replace it: 192.168.55.0/24⁰ 192.168.0.0/16⁰ proto=any dir=out
Jun 21 13:25:39 racoon: ERROR: such policy already exists. anyway replace it: 192.168.55.0/24⁰ 192.168.55.1/32⁰ proto=any dir=in
Jun 21 13:25:39 racoon: ERROR: such policy already exists. anyway replace it: 192.168.55.1/32⁰ 192.168.55.0/24⁰ proto=any dir=out
Jun 21 13:25:39 racoon: INFO: unsupported PF_KEY message REGISTER
Jun 21 13:25:39 racoon: [Self]: INFO: xxx.xxx.xxx.xxx⁵⁰⁰ used as isakmp port (fd=15)
Jun 21 13:25:39 racoon: [Self]: INFO: xxx.xxx.xxx.xxx⁵⁰⁰ used for NAT-T
Jun 21 13:25:39 racoon: [Self]: INFO: xxx.xxx.xxx.xxx⁴⁵⁰⁰ used as isakmp port (fd=14)
Jun 21 13:25:39 racoon: [Self]: INFO: xxx.xxx.xxx.xxx⁴⁵⁰⁰ used for NAT-T
Jun 21 13:25:39 racoon: INFO: Reading configuration from "/var/etc/racoon.conf"
Jun 21 13:25:39 racoon: INFO: (#)This product linked OpenSSL 0.9.8n 24 Mar 2010 (http://www.openssl.org/)
Jun 21 13:25:39 racoon: INFO: (#)ipsec-tools 0.8.0 (http://ipsec-tools.sourceforge.net)
Jun 21 13:25:34 racoon: INFO: racoon process 20249 shutdown
Jun 21 13:25:34 racoon: INFO: caught signal 15
Jun 21 13:25:18 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:25:18 racoon: ERROR: phase1 negotiation failed due to send error. 8cc71341ac3d21b4:0000000000000000
Jun 21 13:25:18 racoon: INFO: begin Identity Protection mode.
Jun 21 13:25:18 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:25:18 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:25:13 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:25:13 racoon: ERROR: phase1 negotiation failed due to send error. 0ef4b4866d2f53b4:0000000000000000
Jun 21 13:25:13 racoon: INFO: begin Identity Protection mode.
Jun 21 13:25:13 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:25:13 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:49 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:49 racoon: ERROR: phase1 negotiation failed due to send error. c295413d3219fe18:0000000000000000
Jun 21 13:24:49 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:49 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:49 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:43 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:43 racoon: ERROR: phase1 negotiation failed due to send error. 0a00ca3daeb59162:0000000000000000
Jun 21 13:24:43 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:43 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:43 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:26 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:26 racoon: ERROR: phase1 negotiation failed due to send error. de0cce45d3a7e540:0000000000000000
Jun 21 13:24:26 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:26 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:26 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:15 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:15 racoon: ERROR: phase1 negotiation failed due to send error. 09cc7c4806aabbc4:0000000000000000
Jun 21 13:24:15 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:15 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:15 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:05 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:05 racoon: ERROR: phase1 negotiation failed due to send error. 995a69388413a05f:0000000000000000
Jun 21 13:24:05 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:05 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:05 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:24:00 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:24:00 racoon: ERROR: phase1 negotiation failed due to send error. 9e9b6a57389f66dd:0000000000000000
Jun 21 13:24:00 racoon: INFO: begin Identity Protection mode.
Jun 21 13:24:00 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:24:00 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:23:41 racoon: ERROR: failed to begin ipsec sa negotication.
Jun 21 13:23:41 racoon: ERROR: phase1 negotiation failed due to send error. e364f27534a4b502:0000000000000000
Jun 21 13:23:41 racoon: INFO: begin Identity Protection mode.
Jun 21 13:23:41 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:23:41 racoon: [FabMetro]: INFO: IPsec-SA request for yyy.yyy.yyy.yyyy queued due to no phase1 found.
Jun 21 13:23:39 racoon: [FabMetro]: INFO: ISAKMP-SA deleted xxx.xxx.xxx.xxx⁵⁰⁰-yyy.yyy.yyy.yyyy⁵⁰⁰ spi:b5af5953c8f51632:148c68101e17ec82
Jun 21 13:23:39 racoon: INFO: purged ISAKMP-SA spi=b5af5953c8f51632:148c68101e17ec82.
Jun 21 13:23:39 racoon: INFO: purging ISAKMP-SA spi=b5af5953c8f51632:148c68101e17ec82.
Jun 21 13:23:39 racoon: [FabMetro]: [yyy.yyy.yyy.yyyy] INFO: DPD: remote (ISAKMP-SA spi=b5af5953c8f51632:148c68101e17ec82) seems to be dead.
Jun 21 13:23:39 racoon: [FabMetro]: INFO: ISAKMP-SA deleted xxx.xxx.xxx.xxx⁵⁰⁰-yyy.yyy.yyy.yyyy⁵⁰⁰ spi:83af516d52d83868:007ab32b5aa9c8c4
Jun 21 13:23:39 racoon: INFO: purged ISAKMP-SA spi=83af516d52d83868:007ab32b5aa9c8c4.
Jun 21 13:23:39 racoon: INFO: purged IPsec-SA spi=233684429.
Jun 21 13:23:39 racoon: INFO: Unknown IPsec-SA spi=233684429, hmmmm?
Jun 21 13:23:39 racoon: INFO: purged IPsec-SA spi=136266941.
Jun 21 13:23:39 racoon: INFO: Unknown IPsec-SA spi=136266941, hmmmm?
Jun 21 13:23:39 racoon: INFO: purging ISAKMP-SA spi=83af516d52d83868:007ab32b5aa9c8c4.
Jun 21 13:23:39 racoon: [FabMetro]: [yyy.yyy.yyy.yyyy] INFO: DPD: remote (ISAKMP-SA spi=83af516d52d83868:007ab32b5aa9c8c4) seems to be dead.
Jun 21 13:23:04 racoon: ERROR: failed to start post getspi.
Jun 21 13:23:04 racoon: ERROR: phase2 negotiation failed due to send error. b5af5953c8f51632:148c68101e17ec82:0000f009
Jun 21 13:23:04 racoon: [FabMetro]: INFO: IPsec-SA expired: ESP/Tunnel yyy.yyy.yyy.yyyy⁵⁰⁰->xxx.xxx.xxx.xxx⁵⁰⁰ spi=233684429(0xdedbdcd)
Jun 21 13:23:04 racoon: [FabMetro]: INFO: initiate new phase 2 negotiation: xxx.xxx.xxx.xxx⁵⁰⁰<=>yyy.yyy.yyy.yyyy⁵⁰⁰
Jun 21 13:23:04 racoon: [FabMetro]: INFO: IPsec-SA expired: ESP xxx.xxx.xxx.xxx⁵⁰⁰->yyy.yyy.yyy.yyyy⁵⁰⁰ spi=136266941(0x81f44bd)
Jun 21 13:22:29 racoon: WARNING: unrecognized route message with rtm_type: 4
Jun 21 13:22:29 racoon: WARNING: unrecognized route message with rtm_type: 4
Jun 21 13:22:03 racoon: WARNING: unrecognized route message with rtm_type: 4
Jun 21 13:22:03 racoon: WARNING: unrecognized route message with rtm_type: 4
Jun 21 13:22:03 racoon: WARNING: unrecognized route message with rtm_type: 4

Jim P wrote:

Try it with 90ecc0b62f8b363d9497b4754133738edb9bc633

I have tried this on a "2.0-RC1 (amd64) built on Tue May 10 09:43:49 EDT 2011" install with the same results - IPsec VPNs still drop after the pptp user disconnects.

Editing an IPsec tunnel brings the VPNs back up.

Going to be installing RC3 soon, but I don't really expect the behavior to change - will be testing regardless.

Just updated to 2.0-RC3 (amd64) built on Tue Jun 21 23:37:22 EDT 2011 which has the patch that Jim P linked to - same thing, no effect.

This one got me too, going to have to back out one system and go back to 1.2.3, any idea when this will be addressed?

Can you please test latest snapshots and see if this happends again.

I can, on another system, had to remove the one failing from production. Should know something by tomorrow.

Thanks

Ermal Luçi wrote:

Can you please test latest snapshots and see if this happends again.

Just tested on 2.0-RC3 (amd64) built on Mon Jul 4 16:49:48 EDT 2011.

No change, IPsec VPNs still all drop after 20-40 seconds after a PPTP user disconnects. Note that they don't all drop at exactly the same time watching pings over a couple of the VPNs. Disabling/enabling an IPsec VPN gets them all to come back up.

That snapshot was not created after Ermal's note. Please wait for the next new snapshot. It should be uploading soon.

Jim P wrote:

That snapshot was not created after Ermal's note. Please wait for the next new snapshot. It should be uploading soon.

when scheduling new snap?

They're up now, the branch changed on the snapshots so the links were not pointing to the right place. Also, auto update is looking at the old location. Go to the firmware settings and re-select the right link for your architecture from the drop-down and then save, and check again.

Just tested the latest snapshot 2.0-RC3 (amd64) built on Thu Jul 7 16:01:09 EDT 2011 - no change. All VPNs still drop after a while. Re-saving a configuration and applying gets things working again.

Ermal Luçi wrote:

Can you please test latest snapshots and see if this happends again.

Ermal any changes with last snapshot(2.0-RC3 (i386) built on Thu Jul 7 16:08:10 EDT 2011)

system log:

Jul 8 06:15:03 php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.

ipsec log:

Jul 8 06:24:30 racoon: ERROR: failed to begin ipsec sa negotication.
Jul 8 06:24:30 racoon: ERROR: phase1 negotiation failed due to send error. 7830f133e3c2a38f:0000000000000000
Jul 8 06:24:30 racoon: INFO: begin Identity Protection mode.
Jul 8 06:24:30 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: 111.111.111.111⁵⁰⁰<=>222.222.222.222⁵⁰⁰
Jul 8 06:24:30 racoon: [FabMetro]: INFO: IPsec-SA request for 222.222.222.222 queued due to no phase1 found.
Jul 8 06:24:27 racoon: ERROR: failed to begin ipsec sa negotication.
Jul 8 06:24:27 racoon: ERROR: phase1 negotiation failed due to send error. 8047652d1bd605f4:0000000000000000
Jul 8 06:24:27 racoon: INFO: begin Identity Protection mode.
Jul 8 06:24:27 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: 111.111.111.111⁵⁰⁰<=>222.222.222.222⁵⁰⁰
Jul 8 06:24:27 racoon: [FabMetro]: INFO: IPsec-SA request for 222.222.222.222 queued due to no phase1 found.
Jul 8 06:24:07 racoon: ERROR: failed to begin ipsec sa negotication.
Jul 8 06:24:07 racoon: ERROR: phase1 negotiation failed due to send error. 792f9ef12935ad9f:0000000000000000
Jul 8 06:24:07 racoon: INFO: begin Identity Protection mode.
Jul 8 06:24:07 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: 111.111.111.111⁵⁰⁰<=>222.222.222.222⁵⁰⁰
Jul 8 06:24:07 racoon: [FabMetro]: INFO: IPsec-SA request for 222.222.222.222 queued due to no phase1 found.
Jul 8 06:24:04 racoon: [FabMetro]: INFO: ISAKMP-SA deleted 111.111.111.111⁵⁰⁰-222.222.222.222⁵⁰⁰ spi:e3c9f3b87147c306:f0993e2e8225cbfc
Jul 8 06:24:04 racoon: INFO: purged ISAKMP-SA spi=e3c9f3b87147c306:f0993e2e8225cbfc.
Jul 8 06:24:04 racoon: INFO: purged IPsec-SA spi=151053141.
Jul 8 06:24:04 racoon: INFO: purged IPsec-SA spi=171855494.
Jul 8 06:24:04 racoon: INFO: purging ISAKMP-SA spi=e3c9f3b87147c306:f0993e2e8225cbfc.
Jul 8 06:24:04 racoon: [FabMetro]: [222.222.222.222] INFO: DPD: remote (ISAKMP-SA spi=e3c9f3b87147c306:f0993e2e8225cbfc) seems to be dead.
Jul 8 06:23:11 racoon: WARNING: unrecognized route message with rtm_type: 4
Jul 8 06:23:11 racoon: WARNING: unrecognized route message with rtm_type: 4
Jul 8 06:23:05 racoon: WARNING: unrecognized route message with rtm_type: 4
Jul 8 06:23:05 racoon: WARNING: unrecognized route message with rtm_type: 4
Jul 8 06:23:05 racoon: WARNING: unrecognized route message with rtm_type: 4
Jul 8 06:15:04 racoon: INFO: unsupported PF_KEY message REGISTER
Jul 8 06:02:36 racoon: [FabMetro]: INFO: IPsec-SA established: ESP 111.111.111.111⁵⁰⁰->222.222.222.222⁵⁰⁰ spi=171855494(0xa3e4e86)
Jul 8 06:02:36 racoon: [FabMetro]: INFO: IPsec-SA established: ESP 111.111.111.111⁵⁰⁰->222.222.222.222⁵⁰⁰ spi=151053141(0x900e355)
Jul 8 06:02:36 racoon: [FabMetro]: INFO: initiate new phase 2 negotiation: 111.111.111.111⁵⁰⁰<=>222.222.222.222⁵⁰⁰
Jul 8 06:02:35 racoon: [FabMetro]: INFO: ISAKMP-SA established 111.111.111.111⁵⁰⁰-222.222.222.222⁵⁰⁰ spi:e3c9f3b87147c306:f0993e2e8225cbfc
Jul 8 06:02:35 racoon: INFO: received broken Microsoft ID: FRAGMENTATION
Jul 8 06:02:35 racoon: INFO: received Vendor ID: DPD
Jul 8 06:02:35 racoon: INFO: begin Identity Protection mode.
Jul 8 06:02:35 racoon: [FabMetro]: INFO: initiate new phase 1 negotiation: 111.111.111.111⁵⁰⁰<=>222.222.222.222⁵⁰⁰
Jul 8 06:02:35 racoon: [FabMetro]: INFO: IPsec-SA request for 222.222.222.222 queued due to no phase1 found.
Jul 8 06:02:32 racoon: ERROR: such policy already exists. anyway replace it: 192.168.0.0/16⁰ 192.168.55.0/24⁰ proto=any dir=in
Jul 8 06:02:32 racoon: ERROR: such policy already exists. anyway replace it: 192.168.55.0/24⁰ 192.168.0.0/16⁰ proto=any dir=out
Jul 8 06:02:32 racoon: ERROR: such policy already exists. anyway replace it: 192.168.55.0/24⁰ 192.168.55.1/32⁰ proto=any dir=in
Jul 8 06:02:32 racoon: ERROR: such policy already exists. anyway replace it: 192.168.55.1/32⁰ 192.168.55.0/24⁰ proto=any dir=out
Jul 8 06:02:32 racoon: INFO: unsupported PF_KEY message REGISTER
Jul 8 06:02:32 racoon: [Self]: INFO: 111.111.111.111⁵⁰⁰ used as isakmp port (fd=15)
Jul 8 06:02:32 racoon: [Self]: INFO: 111.111.111.111⁵⁰⁰ used for NAT-T
Jul 8 06:02:32 racoon: [Self]: INFO: 111.111.111.111⁴⁵⁰⁰ used as isakmp port (fd=14)
Jul 8 06:02:32 racoon: [Self]: INFO: 111.111.111.111⁴⁵⁰⁰ used for NAT-T
Jul 8 06:02:32 racoon: INFO: Reading configuration from "/var/etc/racoon.conf"
Jul 8 06:02:32 racoon: INFO: (#)This product linked OpenSSL 0.9.8n 24 Mar 2010 (http://www.openssl.org/)
Jul 8 06:02:32 racoon: INFO: (#)ipsec-tools 0.8.0 (http://ipsec-tools.sourceforge.net)
Jul 8 06:02:26 racoon: INFO: racoon process 63834 shutdown
Jul 8 06:02:26 racoon: INFO: caught signal 15
Jul 8 06:02:26 racoon: INFO: unsupported PF_KEY message REGISTER
Jul 8 06:02:26 racoon: [Self]: INFO: 111.111.111.111⁵⁰⁰ used as isakmp port (fd=14)
Jul 8 06:02:26 racoon: [Self]: INFO: 111.111.111.111⁵⁰⁰ used for NAT-T
Jul 8 06:02:26 racoon: [Self]: INFO: 111.111.111.111⁴⁵⁰⁰ used as isakmp port (fd=13)
Jul 8 06:02:26 racoon: [Self]: INFO: 111.111.111.111⁴⁵⁰⁰ used for NAT-T
Jul 8 06:02:26 racoon: INFO: Reading configuration from "/var/etc/racoon.conf"
Jul 8 06:02:26 racoon: INFO: (#)This product linked OpenSSL 0.9.8n 24 Mar 2010 (http://www.openssl.org/)
Jul 8 06:02:26 racoon: INFO: (#)ipsec-tools 0.8.0 (http://ipsec-tools.sourceforge.net)

Can you please post the system logs more complete not the ipsec related part?

Ermal Luçi wrote:

Can you please post the system logs more complete not the ipsec related part?

Ermal,I specially cleared system logs,and disconnect pptp vpn client.Any system log appeared.Only same ipsec logs as i send before.

Well i need the system logs since seems something is resetting ipsec daemon.

Jul 8 06:02:26 racoon: INFO: racoon process 63834 shutdown

I think that restart is user-triggered, people restart racoon to fix it. The log that looks interesting to me is:

Jun 21 13:25:18 racoon: ERROR: phase1 negotiation failed due to send error. 

i have to restart racoon service in order it works properly after pptp client disconnect.But i'm not sure this shutdown related to my racoon restart.

Hi, Is there any estimated hours to resolve this issue, I'm willing to pay to resolve this issue since it's a stopper bug for us, but I'd like to have an estimate first.

Regards, Pablo

Pablo - I emailed you.

I've been watching/experiencing this bug for a while now and it's also now a stopper for us too. I'm also open to paying for quicker resolution.

someone who can replicate this and can get us access to their system, please email me (cmb at pfsense dot org).

Chris Buechler wrote:

someone who can replicate this and can get us access to their system, please email me (cmb at pfsense dot org).

I emailed connection infos cmb at pfsense dot org

Ermal Luçi wrote:

I have put a fix in latest snapshots.

@Hafiz Rafiyev,
i have put the fix on your box so you can test directly without need to upgrade.

Please give feedback if this helps you.
Though really you should not use the WAN or any interface ip as a localip for PPTP!

Hafiz Rafiyev wrote:

Ermal Luçi wrote:

I have put a fix in latest snapshots.

@Hafiz Rafiyev,
i have put the fix on your box so you can test directly without need to upgrade.

Please give feedback if this helps you.
Though really you should not use the WAN or any interface ip as a localip for PPTP!

Ermal agian ipsec dropped after pptp client disconnect:(You see my pptp vpn conf,anything wrong with pptp conf?because this conf working on 1.2.3.

I also upgraded new snap today,but nothing changed.Ermal you can test yourself ipsec drop after pptp client disconnect on my PF.Please mail rafibeyli@gmail.com if you want connect again.

please change status to new,because it's unresolved

Is there any progress on this issue?

Also looking for a progress/status report here. Thanks.

Chris, I have to admit, I have not checked it in the past few weeks but replication was simple. Build a pfSense, create a few regular ipsec tunnels, then configure and enable PPTP and establish a connection for a few minutes and disconnect. it brings down all ipsec sessions until racoon is restarted or the box is restarted. I originally deployed 5 v2.0 RC3 units and have since reloaded them to 1.2.3 to avoid this. If a some money is needed, we can help. How much? Otherwise, I am forced to stay on 1.2.3 in a production environment. I would be happy to stand up a 2.0 unit hang it off a static IP for you to access, I can even build a few ipsec tunnels so you can test the PPTP part of this.

Thanks
Derrick

chris ,i gave to Ermal connection info to my pf 2.0 rc3 box.You can easily replicate this bug on my pf box because i have enabled pptp server and ipsec tunnels.

regards

hafiz

I paid to get this some attention. Ticket ID: QDS-175569

Hopefully you can reproduce yourself or use the above provided examples. If not, I can look into providing access to a system (I'd rather alternatives attempted first).

Thanks Chris!

Hi Chris,

we here at KRLS received your email this morning regarding this issue.
I would be more than happy to provide you with more logs.
I am able to reproduce the error although i would like to wait till after hours to replicate.
Tonight I will replicate the issue and gather logs, let me know if there is anything else we can do to help.

Thanks,
Ross Berryman

I have a test system running pfSense 2.0 amd64 here which I am able to duplicate the issue on that I can give access to pfSense developers.

Please contact me for access.

Me Too
Test environment
H/W: P4 2.8/DDR 512M
OS: pfsense 2.0 release

PPTP client disconnect kills all IPsec VPNs. Need to re-start IPSec Service will return to normal.
But if PPTP client disconnect they Kills all IPSec VPNs. Watch IPSec Service Shows normal operation can not successfully completed IPSec link.

Chris Buechler wrote:

Disconnecting PPTP VPNs drops IPsec under some yet to be determined circumstance, as described in support@ thread "2.0RC1 - PPTP client disconnect kills all IPsec VPNs".

Config to replicate from David Rees is in the projects github repo, if someone who doesn't have access there wants a copy, email me.

any progress abouts this bug?

I second that question! Is there something anyone needs, such as access to an online system that can reproduce this? I can make arrangements for that. Contact me at dconneratdr-it.com

Hafiz Rafiyev wrote:

any progress abouts this bug?

Hafiz Rafiyev wrote:

any progress abouts this bug?

Don't know. Was never contacted after my last comment nearly a month ago. Still have that test system available, BTW.

anybody working on this urgent bug?

Hafiz Rafiyev wrote:

anybody working on this urgent bug?

Not that I am aware of. I also have an embedded test system for their use, but have not been contacted, so either they have it covered or something. I see it's slated to be in the 2.0.1 release. Haven't noticed any RCs for that version.

we're working on it. a partial fix will be in 2.0.1 though not sure we can get it entirely fixed for then (it's coming in just a few days) though it doesn't appear to fix something that people are hitting.

Chris Buechler wrote:

we're working on it. a partial fix will be in 2.0.1 though not sure we can get it entirely fixed for then (it's coming in just a few days) though it doesn't appear to fix something that people are hitting.

Thanks Chris, we eagerly await something to test out.

Looks like Ermal figured out what triggers this - if you have the "PPTP Server IP" configured as your WAN IP, which it should not be, that's what generates a rtmsg that has the same IP as racoon has in its phase 1 structure, which seems to be what triggers the issue.

The PPTP Server IP is not the IP that the PPTP server listens on, it's the one clients get for their end of the routing. It should never be a public IP, or a WAN IP. The typical configuration is the clients get part of the LAN subnet, and the server IP is a different unused IP within the LAN subnet. Alternatively a different private IP subnet can be used, and the server IP will be a different private IP in that case.

Those who can replicate, please change your server IP to be something other than a WAN IP and report back.

Yes, I can confirm that setting that IP to an IP other than the WAN IP does avoid the problem.

I believe we originally set the PPTP server IP to the WAN IP because we host users under multiple subnets by manually setting IPs - I guess we'll have to figure out another way around that.

David: you can still do just that without using the WAN IP there, any unused private IP is fine.

So, does this mean I've been setting up 1.2.3 wrong all this time and it still works? Let me make sure I understand, the "server address" should be a private network geatway? Example 192.168.255.1 and the "remote address range" what you want your PPTP users to be assigned to route into your LAN like 192.168.255.100? I have to tell you, I feel a bit stupid. :^)

Chris Buechler wrote:

Looks like Ermal figured out what triggers this - if you have the "PPTP Server IP" configured as your WAN IP, which it should not be, that's what generates a rtmsg that has the same IP as racoon has in its phase 1 structure, which seems to be what triggers the issue.

The PPTP Server IP is not the IP that the PPTP server listens on, it's the one clients get for their end of the routing. It should never be a public IP, or a WAN IP. The typical configuration is the clients get part of the LAN subnet, and the server IP is a different unused IP within the LAN subnet. Alternatively a different private IP subnet can be used, and the server IP will be a different private IP in that case.

Those who can replicate, please change your server IP to be something other than a WAN IP and report back.

It works (aside from now having this consequence), but yes it is technically not correct, and has never been shown that way if you follow our documentation, to put in a WAN IP for the server IP address.

Chris Buechler wrote:

It works (aside from now having this consequence), but yes it is technically not correct, and has never been shown that way if you follow our documentation, to put in a WAN IP for the server IP address.

lol! I know, RTFM. Well thanks to Ermal for finding the solution to this PEBKAC or ID10T error. Guess I'll go do some testing now and get this deployed right after I sit here and drool, like the idiot I feel like for a few minutes.

As Derrick says,it's running on 1.2.3 with wan ip very well,my opinion it's userful to control pptp Server address box against illegal ip adreses.
i will test pptp server with private ip subnet,thank you for your research

Yes but the 2.0 tries to be smarter in regards to the whole system about events.
This makes a lot of things better but just breaks wrong configurations.

The issue here is that this can go as a fix on 2.0.1 but no auto upgrade can be done?!

The changes to ipsec-tools are a bit too intrusive to teach racoon about interface indexes.
I think the better option would just upgrade existing configs and just forbid to use the assgined addresses there.

sounds fine, just file an alert for already-existing configs that are wrong, and add the input validation to prevent others from configuring that.

http://sourceforge.net/mailarchive/forum.php?thread_name=91C62B8E3E2A4F75893DCBCD634ECACF%40Avitos&forum_name=ipsec-tools-devel

This would be the involved solution which should be committed to ipsec-tools.
Will wait until than.