[Swan] DPD Bug

Nick Howitt n1ck.h0w1tt at gmail.com
Fri Feb 22 23:27:27 EET 2013


I think I've just hit a DPD bug. I have dpdaction set to restart_by_peer 
as I use FQDN's in my conn definition and I want to force the conn 
definition to be re-read to re-evaluate the FQDN's.

I recently got this log snippet:

Feb 19 09:37:39 server pluto[25698]: "MumIn" #415: DPD: No response from 
peer - declaring peer dead
Feb 19 09:37:39 server pluto[25698]: "MumIn" #415: DPD: Restarting all 
connections that share this peer
Feb 19 09:37:40 server pluto[25698]: "MumIn" #415: terminating SAs using 
this connection
Feb 19 09:37:40 server pluto[25698]: "MumIn" #426: deleting state 
(STATE_QUICK_R2)
Feb 19 09:37:40 server pluto[25698]: "MumIn" #424: deleting state 
(STATE_QUICK_R2)
Feb 19 09:37:40 server pluto[25698]: "MumIn" #415: deleting state 
(STATE_MAIN_R3)
Feb 19 09:37:40 server pluto[25698]: "MumIn" #428: deleting state 
(STATE_QUICK_R2)
Feb 19 09:37:40 server pluto[25698]: "MumIn" #427: deleting state 
(STATE_MAIN_R3)
Feb 19 09:37:40 server pluto[25698]: "MumIn" #429: initiating Main Mode
Feb 19 09:39:15 server pluto[25698]: packet from 86.14.142.156:500: 
received Vendor ID payload [Dead Peer Detection]
Feb 19 09:39:15 server pluto[25698]: packet from 86.14.142.156:500: 
received Vendor ID payload [RFC 3947] meth=115, but port floating is off
Feb 19 09:39:15 server pluto[25698]: packet from 86.14.142.156:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] meth=108, but 
port floating is off
Feb 19 09:39:15 server pluto[25698]: packet from 86.14.142.156:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, 
but port floating is off
Feb 19 09:39:15 server pluto[25698]: packet from 86.14.142.156:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but 
port floating is off
Feb 19 09:39:15 server pluto[25698]: packet from 86.14.142.156:500: 
ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: responding to Main Mode
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: transition from state 
STATE_MAIN_R0 to state STATE_MAIN_R1
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: STATE_MAIN_R1: sent 
MR1, expecting MI2
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: transition from state 
STATE_MAIN_R1 to state STATE_MAIN_R2
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: STATE_MAIN_R2: sent 
MR2, expecting MI3
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: ignoring 
informational payload, type IPSEC_INITIAL_CONTACT msgid=00000000
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: Main mode peer ID is 
ID_IPV4_ADDR: '86.14.142.156'
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: transition from state 
STATE_MAIN_R2 to state STATE_MAIN_R3
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: STATE_MAIN_R3: sent 
MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_256 
prf=oakley_sha group=modp2048}
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: Dead Peer Detection 
(RFC 3706): enabled
Feb 19 09:39:15 server pluto[25698]: "MumIn" #430: the peer proposed: 
192.168.2.0/24:0/0 -> 192.168.10.0/24:0/0
Feb 19 09:39:15 server pluto[25698]: "MumIn" #431: responding to Quick 
Mode proposal {msgid:a23866c3}
Feb 19 09:39:15 server pluto[25698]: "MumIn" #431:     us: 
192.168.2.0/24===82.19.147.85[@Nick]
Feb 19 09:39:15 server pluto[25698]: "MumIn" #431:   them: 
86.14.142.156<damim.dtdns.net>===192.168.10.0/24
Feb 19 09:39:15 server pluto[25698]: "MumIn" #431: transition from state 
STATE_QUICK_R0 to state STATE_QUICK_R1
Feb 19 09:39:15 server pluto[25698]: "MumIn" #431: STATE_QUICK_R1: sent 
QR1, inbound IPsec SA installed, expecting QI2
Feb 19 09:39:16 server pluto[25698]: "MumIn" #431: Dead Peer Detection 
(RFC 3706): enabled
Feb 19 09:39:16 server pluto[25698]: "MumIn" #431: transition from state 
STATE_QUICK_R1 to state STATE_QUICK_R2
Feb 19 09:39:16 server pluto[25698]: "MumIn" #431: STATE_QUICK_R2: IPsec 
SA established tunnel mode {ESP=>0xe7284fac <0x8be43449 
xfrm=AES_256-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
Feb 19 09:45:12 server pluto[25698]: pending Quick Mode with 
86.14.142.156 "MumIn" took too long -- replacing phase 1
Feb 19 09:45:12 server pluto[25698]: "MumIn": terminating SAs using this 
connection
Feb 19 09:45:12 server pluto[25698]: "MumIn" #429: deleting state 
(STATE_MAIN_I1)

The problem I have is that the conn is defined with "auto=add" so why am 
I seeing a "Feb 19 09:37:40 server pluto[25698]: "MumIn" #429: 
initiating Main Mode" message which you should only get with auto=start. 
The Draytek router at the other end has the tunnel defined as dial-out 
only so it will not accept Openswan initiating. Because of that you get 
the "pending Quick Mode with 86.14.142.156 "MumIn" took too long -- 
replacing phase 1" message. This then kills the tunnel and it 
renegotiates every 5 minutes.

Regards,

Nick


More information about the Swan mailing list