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

Thu Jan 1 19:52:10 EST 2009

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
> 