IPsec fails to renegotiate after loss of a peer

Eugene · May 20, 2009, 2:38 AM

It seems SAD entries you have (setkey -D) after the tunnel fails are different from those that were used when this tunnel was established (your log), no? I see different spi's.
I suspect the tunnel goes up again as soon as you setkey -F ?

jimp · May 20, 2009, 4:56 PM

@Eugene:

It seems SAD entries you have (setkey -D) after the tunnel fails are different from those that were used when this tunnel was established (your log), no? I see different spi's.
I suspect the tunnel goes up again as soon as you setkey -F ?

The SPIs shown in the SAD entries are different than the SPI shown for the ISAKMP-SA which racoon deletes. They're not the same thing, as you can see from the log when it connects:

May 20 12:53:15 pfsense-123test racoon: INFO: IPsec-SA request for x.x.x.49 queued due to no phase1 found.
May 20 12:53:15 pfsense-123test racoon: INFO: initiate new phase 1 negotiation: x.x.x.40[500]<=>x.x.x.49[500]
May 20 12:53:15 pfsense-123test racoon: INFO: begin Aggressive mode.
May 20 12:53:16 pfsense-123test racoon: INFO: received Vendor ID: CISCO-UNITY
May 20 12:53:16 pfsense-123test racoon: INFO: received Vendor ID: draft-ietf-ipsra-isakmp-xauth-06.txt
May 20 12:53:16 pfsense-123test racoon: INFO: received Vendor ID: DPD
May 20 12:53:16 pfsense-123test racoon: NOTIFY: couldn't find the proper pskey, try to get one by the peer's address.
May 20 12:53:16 pfsense-123test racoon: INFO: ISAKMP-SA established x.x.x.40[500]-x.x.x.49[500] spi:1a985545ad4bdc71:345805a19d6bbb0e
May 20 12:53:16 pfsense-123test racoon: INFO: initiate new phase 2 negotiation: x.x.x.40[500]<=>x.x.x.49[500]
May 20 12:53:16 pfsense-123test racoon: ERROR: unknown Informational exchange received.
May 20 12:53:16 pfsense-123test racoon: ERROR: unknown Informational exchange received.
May 20 12:53:16 pfsense-123test racoon: WARNING: ignore RESPONDER-LIFETIME notification.
May 20 12:53:16 pfsense-123test racoon: INFO: IPsec-SA established: ESP x.x.x.49[0]->x.x.x.40[0] spi=208784171(0xc71cb2b)
May 20 12:53:16 pfsense-123test racoon: INFO: IPsec-SA established: ESP x.x.x.40[500]->x.x.x.49[500] spi=28110911(0x1acf03f)

Note that the ISAKMP-SA has one set of SPIs, and the IPSec-SA has another, different set, which if I check setkey right now, does match up:

pfsense-123test# setkey -D
x.x.x.40 x.x.x.49 
        esp mode=any spi=28110911(0x01acf03f) reqid=16389(0x00004005)
        E: 3des-cbc  dc09605c 0317db13 830e984a 533e9c2c edfbf6dc 8695f896
        A: hmac-sha1  dddfdfef 52667b41 2174ebb4 217ae230 d458a5a7
        seq=0x00000026 replay=4 flags=0x00000000 state=mature 
        created: May 20 12:53:16 2009   current: May 20 12:56:21 2009
        diff: 185(s)    hard: 86400(s)  soft: 69120(s)
        last: May 20 12:54:51 2009      hard: 0(s)      soft: 0(s)
        current: 5168(bytes)    hard: 0(bytes)  soft: 0(bytes)
        allocated: 38   hard: 0 soft: 0
        sadb_seq=1 pid=14572 refcnt=2
x.x.x.49 x.x.x.40 
        esp mode=tunnel spi=208784171(0x0c71cb2b) reqid=16390(0x00004006)
        E: 3des-cbc  2c130655 2b2d2a16 0333993b dff3264d f7251968 f2c3565b
        A: hmac-sha1  34236785 b00b9344 19b671bd a5d710f9 ff1222f6
        seq=0x00000026 replay=4 flags=0x00000000 state=mature 
        created: May 20 12:53:16 2009   current: May 20 12:56:21 2009
        diff: 185(s)    hard: 86400(s)  soft: 69120(s)
        last: May 20 12:54:51 2009      hard: 0(s)      soft: 0(s)
        current: 3952(bytes)    hard: 0(bytes)  soft: 0(bytes)
        allocated: 38   hard: 0 soft: 0
        sadb_seq=0 pid=14572 refcnt=1

jimp · May 20, 2009, 5:06 PM

@Eugene:

I suspect the tunnel goes up again as soon as you setkey -F ?

That does bring the tunnel back up, but it's still a manual process for something that should be happening automatically… It's easier than restarting things though.

kapara · May 22, 2009, 12:18 AM

This is the version I am running on my Alix Box.

1.2.2
built on Thu Jan 8 23:09:11 EST 2009

jimp · May 28, 2009, 7:22 PM

Great news everybody, it looks like this has been fixed in the development version of ipsec-tools!

I just got ipsec-tools 0.8-alpha20090525+natt to work on my 2.0 test box and things are working as they should.

Previously, DPD was removing the ISAKMP-SA, but not the IPsec-SA that went along with it. Now it appears to be clearing them all out.

Now this is what I'm seeing:

The connection establishes:

2009-05-28 12:51:17: INFO: respond new phase 1 negotiation: x.x.x.41[500]<=>x.x.x.40[500]
2009-05-28 12:51:17: INFO: begin Aggressive mode.
2009-05-28 12:51:17: INFO: received broken Microsoft ID: FRAGMENTATION
2009-05-28 12:51:17: INFO: received Vendor ID: DPD
2009-05-28 12:51:17: NOTIFY: couldn't find the proper pskey, try to get one by the peer's address.
2009-05-28 12:51:17: INFO: ISAKMP-SA established x.x.x.41[500]-x.x.x.40[500] spi:d75d671612ae7e75:07456176d8b6652c
2009-05-28 12:51:17: INFO: received INITIAL-CONTACT
2009-05-28 12:51:18: INFO: respond new phase 2 negotiation: x.x.x.41[500]<=>x.x.x.40[500]
2009-05-28 12:51:18: INFO: IPsec-SA established: ESP x.x.x.41[500]->x.x.x.40[500] spi=118325718(0x70d81d6)
2009-05-28 12:51:18: INFO: IPsec-SA established: ESP x.x.x.41[500]->x.x.x.40[500] spi=224293038(0xd5e70ae)

And then when I unplug the cable:

2009-05-28 12:52:22: INFO: DPD: remote (ISAKMP-SA spi=d75d671612ae7e75:07456176d8b6652c) seems to be dead.
2009-05-28 12:52:22: INFO: purging ISAKMP-SA spi=d75d671612ae7e75:07456176d8b6652c.
2009-05-28 12:52:22: INFO: purged IPsec-SA spi=224293038.
2009-05-28 12:52:22: INFO: purged IPsec-SA spi=118325718.
2009-05-28 12:52:22: INFO: purged ISAKMP-SA spi=d75d671612ae7e75:07456176d8b6652c.
2009-05-28 12:52:23: INFO: ISAKMP-SA deleted x.x.x.41[500]-x.x.x.40[500] spi:d75d671612ae7e75:07456176d8b6652c

And at that point, setkey -D shows nothing in the SA database, which is miles ahead of what I saw previously.

Since I compiled it on an 8-CURRENT box I can't get that same set of ipsec-tools binaries to run on a 1.2.3-RC system. Once I get that going I can confirm it works on my other test cases. I'll have to hunt down another box to (ab)use for more testing, but this looks very promising.

focalguy · May 28, 2009, 7:36 PM

Great news jimp! Thanks for continuing to work on this.

drees · May 28, 2009, 8:21 PM

Awesome! Hopefully this fix can make it into the 1.2.3 release…

jimp · May 28, 2009, 11:36 PM

The test version of ipsec-tools should be making its way into the snapshots fairly soon.

I'll try to post again once I'm sure it's working in a snapshot so that others can try, too.

jimp · May 29, 2009, 3:58 AM

The new ipsec-tools is in the snapshot for 1.2.3-RC1 on FreeBSD 7.2 that can be found here:

http://snapshots.pfsense.org/FreeBSD_RELENG_7_2/pfSense_RELENG_1_2/updates/

So far with the testing I have been able to perform it reestablishes dropped tunnels perfectly with DPD.

I have tested this Full Update:
http://snapshots.pfsense.org/FreeBSD_RELENG_7_2/pfSense_RELENG_1_2/updates/pfSense-Full-Update-1.2.3-20090528-2046.tgz

And this ISO:
http://snapshots.pfsense.org/FreeBSD_RELENG_7_2/pfSense_RELENG_1_2/livecd_installer/pfSense-1.2.3-20090528-2038.iso.gz

And the proper ipsec-tools is in both, and appears to work.

It should be working its way into the 1.2.3-RC1 based on FreeBSD 7.1 overnight as well.

I would appreciate as much testing as anyone can give this. I know this particular bug is fixed but with any change like this there is the potential to break other things. Please test and report back any issues (Especially people who can test NAT-T). Don't be afraid to report apocalyptic failures or anything else that happens.

Jonb · Jun 29, 2009, 8:19 AM

Whoooooooooo so glad this has been looked at. Serious problems this cause me. Just need the traffic shaper fix now.

fastcon68 · Jul 6, 2009, 10:31 PM

Jimp,
Some new for you, if the partner vpn starts a ping the tunnel reconnects. But it if drops from my end it will not estiablish. Thought I let you know. I try t get some information on the typ of firewall they are using.
RC

jimp · Jul 6, 2009, 10:33 PM

@fastcon68:

Jimp,
Some new for you, if the partner vpn starts a ping the tunnel reconnects. But it if drops from my end it will not estiablish. Thought I let you know. I try t get some information on the typ of firewall they are using.
RC

At the moment we're in a holding pattern waiting on ipsec-tools 0.8 to get some fixes in, and I believe that's the way things are going to go.

There are too many of these issues to fix in ipsec-tools 0.7.2 with patches, unfortunately.

fastcon68 · Jul 6, 2009, 10:54 PM

That's cool. I not updating at the momment. I more concerned with a stable enviroment. I can't afford any more down time.

I am in the process of moving and have a ton of stuff going on.

RC

Rockets · Sep 23, 2009, 12:34 PM

@jimp:

At the moment we're in a holding pattern waiting on ipsec-tools 0.8 to get some fixes in, and I believe that's the way things are going to go.

There are too many of these issues to fix in ipsec-tools 0.7.2 with patches, unfortunately.

Now ipsec-tools 0.7.3 is out any thoughts on using it?

jimp · Sep 23, 2009, 12:38 PM

It was even worse off than 0.8 in some respects. We had to stay at 0.7.2 but drop NAT-T to get some semblance of stability.

Rockets · Sep 23, 2009, 12:57 PM

Is IPsec renegotiating properly now in 1.2.3-RC3?

jimp · Sep 23, 2009, 1:08 PM

Yes, it is working now as far as all my tests have shown both in actual tests and in running it at home and having some Internet stability issues. Seems to work fine as far as I can tell.

Rockets · Sep 23, 2009, 1:51 PM

Jimp wher'd I'd find RC3? It's not on the offical mirrors - only RC1. Or is RC3 a current snapshot? I'm using embedded.

jimp · Sep 23, 2009, 1:57 PM

@Rockets:

Jimp wher'd I'd find RC3? It's not on the offical mirrors - only RC1. Or is RC3 a current snapshot? I'm using embedded.

It's only in snapshots at the moment, but there will probably be an "official" cut of RC3 (or perhaps RC4?) before release.

Here are the NanoBSD (new embedded system) snapshots:
http://snapshots.pfsense.org/FreeBSD_RELENG_7_2/pfSense_RELENG_1_2/nanobsd/?C=M;O=D

bkm · Sep 28, 2009, 12:47 PM

I am seeing an issue that seems to be the same. I am testing RC 1.2.3 20090924. I have tunnels set up to two separate sites to a Netopia router on the other end. The tunnels are working when I leave work in the evening. When I get to work in the morning, they are not working. The IPSec status page (SAD) shows that the tunnels are up. If I restart raccoon, the tunnel status goes down. I then ping a site and everything gets renegotiated and it works again.
I currently have a 28800 lifetime for phase 1 and 86400 for phase 2.
I am willing to test a couple things for a day or two if someone has a suggestion. After that I will need to put my pfsense box into production without the tunnels and I will be limited in what I can try.