[Openswan Users] IPSEC SA only being installed on one side

Wed Jan 14 14:11:35 EST 2009

Just moving to 1.6.20rc1 did not correct my rekeying issues, it did 
improve them but I still had some failures, including failures between two 
servers with only two switches between them.

Last Thursday I changed the OSPF options of the quagga ospfd process 
running on each of my vpn servers so that it would route round problems 
faster. The increased traffic appears to have sorted out the rekeying 
issues.

I have been testing the vpn servers so the only traffic flowing between 
them has been 5 pings every 60 seconds (for monitoring) and 2 OSPF hellos 
every 10 seconds. I have now configured OSPF to hello every second and 
this change appears to have sorted out the rekeying issues. Though I have 
no idea why.

Tim

On Mon, 5 Jan 2009, opsenswan at thefeds.net wrote:

> 2.6.20rc1 has been running for three days and is much better.
>
> I would say it is perfect for phase 2 rekeying but there are two incidents
> I am still investigating.
>
> My monitoring is still picking up quite a few incidents where I have no
> phase 1 SA but this could be because I only have a 60 second rekeying
> margin (to mitigate the effects of the rekeying problems). I will push out
> new configs with a higher rekeying margin and see what happens.
>
> Thanks
> Tim
>
> On Thu, 1 Jan 2009, Paul Wouters wrote:
>
>> On Tue, 30 Dec 2008, openswan at thefeds.net wrote:
>>
>> There have been some fixes to rekeying lately. Please try the latest
>> test release (2.6.20rc1). Though this bug might still exist.
>>
>> Paul
>>
>>> Date: Tue, 30 Dec 2008 18:35:42 +0000 (GMT)
>>> From:  <openswan at thefeds.net>
>>> To:  <users at openswan.org>
>>> Subject: [Openswan Users] IPSEC SA only being installed on one side
>>>
>>> I am trying to track down a problem I am having quite frequently where my
>>> phase 1 SA is fine (and thus DPD doesn't see any problems) but my phase 2
>>> SAs aren't in step and thus traffic can't get through.
>>>
>>> The problem appears to be that sometimes when a new phase 2 SA is
>>> negotiated one side is happy and installs the SA, but the other side
>>> (never the initiator) doesn't install the SA. The side with the newer SA
>>> then sends packets encrypted with the new SPI which the other side cannot
>>> understand.
>>>
>>> I have the following extracts from /var/log/secure:
>>>
>>> The initiator:
>>> Dec 30 12:40:04 vpn01d pluto[4943]: "tun02a01d" #442: STATE_MAIN_I4:
>>> ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_256
>>> prf=oakley_sha group=modp1536}
>>> Dec 30 12:40:04 vpn01d pluto[4943]: "tun02a01d" #442: Dead Peer Detection
>>> (RFC 3706): enabled
>>> Dec 30 14:32:40 vpn01d pluto[4943]: "tun02a01d" #455: initiating Quick
>>> Mode PSK+ENCRYPT+PFS+UP+IKEv2ALLOW to replace #428 {using isakmp#442
>>> msgid:1ff67d30 proposal=AES(12)_256-SHA1(2)_160
>>> pfsgroup=OAKLEY_GROUP_MODP1536}
>>> Dec 30 14:32:40 vpn01d pluto[4943]: "tun02a01d" #455: Dead Peer Detection
>>> (RFC 3706): enabled
>>> Dec 30 14:32:40 vpn01d pluto[4943]: "tun02a01d" #455: transition from
>>> state STATE_QUICK_I1 to state STATE_QUICK_I2
>>> Dec 30 14:32:40 vpn01d pluto[4943]: "tun02a01d" #455: STATE_QUICK_I2: sent
>>> QI2, IPsec SA established transport mode {ESP=>0x0f2d2e3a <0x36134870
>>> xfrm=AES_256-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
>>> Dec 30 14:32:50 vpn01d pluto[4943]: "tun02a01d" #455: message ignored
>>> because it contains an unexpected payload type (ISAKMP_NEXT_HASH)
>>> Dec 30 14:32:50 vpn01d pluto[4943]: "tun02a01d" #455: sending encrypted
>>> notification INVALID_PAYLOAD_TYPE to <vpn02a ip>:500
>>>
>>> The reciever:
>>> Dec 30 12:40:04 vpn02a pluto[547]: "tun02a01d" #480: STATE_MAIN_R3: sent
>>> MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_256
>>> prf=oakley_sha group=modp1536}
>>> Dec 30 12:40:04 vpn02a pluto[547]: "tun02a01d" #480: Dead Peer Detection
>>> (RFC 3706): enabled
>>> Dec 30 14:32:40 vpn02a pluto[547]: "tun02a01d" #480: the peer proposed:
>>> <vpn02a ip>/32:0/0 -> <vpn02d ip>/32:0/0
>>> Dec 30 14:32:40 vpn02a pluto[547]: "tun02a01d" #515: responding to Quick
>>> Mode proposal {msgid:1ff67d30}
>>> Dec 30 14:32:40 vpn02a pluto[547]: "tun02a01d" #515:     us:
>>> <vpn02a ip><<vpn02a ip>>[+S=C]---<vpn02a nh>
>>> Dec 30 14:32:40 vpn02a pluto[547]: "tun02a01d" #515:   them:
>>> <vpn01d nh>---<vpn01d ip><<vpn01d ip>>[+S=C]
>>> Dec 30 14:32:40 vpn02a pluto[547]: "tun02a01d" #515: keeping
>>> refhim=4294901761 during rekey
>>> Dec 30 14:32:40 vpn02a pluto[547]: "tun02a01d" #515: transition from state
>>> STATE_QUICK_R0 to state STATE_QUICK_R1
>>> Dec 30 14:32:40 vpn02a pluto[547]: "tun02a01d" #515: STATE_QUICK_R1: sent
>>> QR1, inbound IPsec SA installed, expecting QI2
>>> Dec 30 14:32:40 vpn02a pluto[547]: packet from <vpn01d ip>:500:
>>> Informational Exchange is for an unknown (expired?) SA
>>> Dec 30 14:32:50 vpn02a pluto[547]: "tun02a01d" #480: ignoring
>>> informational payload, type INVALID_PAYLOAD_TYPE msgid=00000000
>>> Dec 30 14:32:50 vpn02a pluto[547]: "tun02a01d" #480: received and ignored
>>> informational message
>>>
>>> I then end up with the following SAs on vpn02a:
>>> 000 #523: "tun02a01d":500 STATE_MAIN_R3 (sent MR3, ISAKMP SA established);
>>> EVENT_SA_REPLACE in 9590s; newest ISAKMP; lastdpd=2s(seq in:24780 out:0);
>>> idle; import:not set
>>> 000 #480: "tun02a01d":500 STATE_MAIN_R3 (sent MR3, ISAKMP SA established);
>>> EVENT_SA_REPLACE in 2449s; lastdpd=1210s(seq in:7855 out:0); idle;
>>> import:not set
>>> 000 #470: "tun02a01d":500 STATE_QUICK_R2 (IPsec SA established);
>>> EVENT_SA_REPLACE in 2026s; newest IPSEC; eroute owner; isakmp#454; idle;
>>> import:not set
>>> 000 #470: "tun02a01d" esp.f2d777e3@<vpn01d ip> esp.8ca1e089@<vpn02a ip>
>>> ref=0 refhim=4294901761
>>>
>>> and vpn01d:
>>> 000 #466: "tun02a01d":500 STATE_MAIN_I4 (ISAKMP SA established);
>>> EVENT_SA_REPLACE in 5934s; newest ISAKMP; lastdpd=1s(seq in:3752 out:0);
>>> idle; import:admin initiate
>>> 000 #455: "tun02a01d":500 STATE_QUICK_I2 (sent QI2, IPsec SA established);
>>> EVENT_SA_REPLACE in 5593s; newest IPSEC; eroute owner; isakmp#442; idle;
>>> import:admin initiate
>>> 000 #455: "tun02a01d" esp.f2d2e3a@<vpn02a ip> esp.36134870@<vpn01d ip>
>>> ref=0 refhim=4294901761
>>> 000 #442: "tun02a01d":500 STATE_MAIN_I4 (ISAKMP SA established);
>>> EVENT_SA_EXPIRE in 6050s; lastdpd=1209s(seq in:17036 out:0); idle;
>>> import:admin initiate
>>> 000 #428: "tun02a01d":500 STATE_QUICK_I2 (sent QI2, IPsec SA established);
>>> EVENT_SA_EXPIRE in 5627s; isakmp#411; idle; import:admin initiate
>>> 000 #428: "tun02a01d" esp.8ca1e089@<vpn02a ip> esp.f2d777e3@<vpn01d ip>
>>> ref=0 refhim=4294901761
>>>
>>> So you can see that vpn02a does have esp.36134870@<vpn01d ip>
>>> esp.f2d2e3a@<vpn02a ip> installed and as that is newest on vpn01d that is
>>> what it is using for all traffic to vpn02a.
>>>
>>> I am guessing that the log entry of:
>>> Dec 30 14:32:40 vpn02a pluto[547]: packet from <vpn01d ip>:500:
>>> Informational Exchange is for an unknown (expired?) SA
>>> May be the QI2 packet from vpn01d that vpn01d doesn't understand? I
>>> thought at one time that the phase 1 SA may be expiring at this point, but
>>> I am seeing this happen far too often for that. Plus as the logs show the
>>> phase 1 SA was renegotiated 112 minutes and 48 seconds earlier and I have
>>> a key life of 240 minutes with a rekeying margin of 120 minutes and a
>>> rekeying fuzz of 1% so the next phase 1 rekeying isn't due for another 6
>>> minutes to 7 minutes 12 seconds. I do see the phase 1 rekey happen in the
>>> logs 6 minutes and 25 seconds later.
>>>
>>> Does anyone have any idea how I can go about finding out why the recieving
>>> end sometimes doesn't install the new phase 2 SA?
>>>
>>> Thanks in advance for any help
>>> Tim
>>> _______________________________________________
>>> Users at openswan.org
>>> http://lists.openswan.org/mailman/listinfo/users
>>> Building and Integrating Virtual Private Networks with Openswan:
>>> http://www.amazon.com/gp/product/1904811256/104-3099591-2946327?n=283155
>>>
>>
> _______________________________________________
> Users at openswan.org
> http://lists.openswan.org/mailman/listinfo/users
> Building and Integrating Virtual Private Networks with Openswan:
> http://www.amazon.com/gp/product/1904811256/104-3099591-2946327?n=283155
>