[strongSwan-dev] Strongswan 5.3, IKEv2 & "make before break" - losing DNS configuration on Initiator after IKE lifetime expires

Ken Nelson ken at cazena.com
Wed Nov 18 19:39:32 CET 2015


Hi Tobias,


Thanks for your response, I have a couple follow-on questions.

1.  Regarding the DNS explanation to question #1 below, is this Charon behavior considered erroneous with a defect logged?  If so, when might a fix appear for it?  You mention a “workaround” using refcounting.  Is this something that can be done at the user level?  Or are you proposing a fix to StrongSwan internals?


2.  The below up/down logic still seems erroneous, let me explain by way of example.  Note that I’m using the default up/down script in /usr/libexec/strongswan/_updown as provided by StrongSwan.

2a.  First, the initiator establishes the IPsec tunnel at 17:23:49 with the responder.  Here are the log file entries.  Note that there are no errors in the log, that is, the up/down script correctly installs the iptables entries correctly at 17:23:49.

Nov 11 17:23:46 initiator charon: 00[DMN] Starting IKE charon daemon (strongSwan 5.3.0, Linux 2.6.32-504.el6.x86_64, x86_64)
Nov 11 17:23:46 initiator charon: 00[LIB] openssl FIPS mode(2) - enabled
Nov 11 17:23:46 initiator charon: 00[CFG] loading ca certificates from '/etc/strongswan/ipsec.d/cacerts'
Nov 11 17:23:46 initiator charon: 00[CFG] loading aa certificates from '/etc/strongswan/ipsec.d/aacerts'
Nov 11 17:23:46 initiator charon: 00[CFG] loading ocsp signer certificates from '/etc/strongswan/ipsec.d/ocspcerts'
Nov 11 17:23:46 initiator charon: 00[CFG] loading attribute certificates from '/etc/strongswan/ipsec.d/acerts'
Nov 11 17:23:46 initiator charon: 00[CFG] loading crls from '/etc/strongswan/ipsec.d/crls'
Nov 11 17:23:46 initiator charon: 00[CFG] loading secrets from '/etc/strongswan/ipsec.secrets'
Nov 11 17:23:46 initiator charon: 00[CFG]   loaded IKE secret for %any
Nov 11 17:23:46 initiator charon: 00[CFG]   loaded EAP secret for my-user
Nov 11 17:23:46 initiator charon: 00[LIB] loaded plugins: charon aes des rc2 sha1 sha2 md4 md5 random nonce x509 revocation constraints acert pubkey pkcs1 pkcs8 pkcs12 pgp dnskey sshkey pem openssl fips-prf gmp xcbc cmac hmac ctr ccm curl attr kernel-netlink resolve socket-default farp stroke vici updown eap-identity eap-md5 eap-gtc eap-mschapv2 eap-tls eap-ttls eap-peap xauth-generic xauth-eap xauth-pam xauth-noauth dhcp
Nov 11 17:23:46 initiator charon: 00[JOB] spawning 16 worker threads
Nov 11 17:23:46 initiator charon: 06[CFG] received stroke: add connection 'dm-psk'
Nov 11 17:23:46 initiator charon: 06[CFG] left nor right host is our side, assuming left=local
Nov 11 17:23:46 initiator charon: 06[CFG] added configuration 'dm-psk'
Nov 11 17:23:46 initiator charon: 09[CFG] received stroke: add connection 'dm-pki'
Nov 11 17:23:46 initiator charon: 09[CFG] left nor right host is our side, assuming left=local
Nov 11 17:23:46 initiator charon: 09[LIB]   opening '/etc/strongswan/ipsec.d/certs/czsecgw-client.crt' failed: No such file or directory
Nov 11 17:23:46 initiator charon: 09[LIB] building CRED_CERTIFICATE - ANY failed, tried 1 builders
Nov 11 17:23:46 initiator charon: 09[CFG]   loading certificate from 'czsecgw-client.crt' failed
Nov 11 17:23:46 initiator charon: 09[CFG] added configuration 'dm-pki'
Nov 11 17:23:48 initiator charon: 05[CFG] received stroke: initiate 'dm-psk'
Nov 11 17:23:48 initiator charon: 08[IKE] initiating IKE_SA dm-psk[1] to re.sp.on.der
Nov 11 17:23:48 initiator charon: 08[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HASH_ALG) ]
Nov 11 17:23:48 initiator charon: 08[NET] sending packet: from 10.0.1.36[500] to re.sp.on.der[500] (1436 bytes)
Nov 11 17:23:48 initiator charon: 06[NET] received packet: from re.sp.on.der[500] to 10.0.1.36[500] (456 bytes)
Nov 11 17:23:48 initiator charon: 06[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HASH_ALG) N(MULT_AUTH) ]
Nov 11 17:23:48 initiator charon: 06[IKE] local host is behind NAT, sending keep alives
Nov 11 17:23:48 initiator charon: 06[IKE] remote host is behind NAT
Nov 11 17:23:48 initiator charon: 06[IKE] authentication of 'my-user' (myself) with pre-shared key
Nov 11 17:23:48 initiator charon: 06[IKE] establishing CHILD_SA dm-psk
Nov 11 17:23:48 initiator charon: 06[ENC] generating IKE_AUTH request 1 [ IDi N(INIT_CONTACT) IDr AUTH CPRQ(ADDR DNS) SA TSi TSr N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) N(AUTH_FOLLOWS) ]
Nov 11 17:23:48 initiator charon: 06[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (428 bytes)
Nov 11 17:23:48 initiator charon: 10[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (124 bytes)
Nov 11 17:23:48 initiator charon: 10[ENC] parsed IKE_AUTH response 1 [ IDr AUTH ]
Nov 11 17:23:48 initiator charon: 10[IKE] authentication of 'resonder.domain.com<http://resonder.domain.com>' with pre-shared key successful
Nov 11 17:23:48 initiator charon: 10[ENC] generating IKE_AUTH request 2 [ IDi ]
Nov 11 17:23:48 initiator charon: 10[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (76 bytes)
Nov 11 17:23:48 initiator charon: 09[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (92 bytes)
Nov 11 17:23:48 initiator charon: 09[ENC] parsed IKE_AUTH response 2 [ EAP/REQ/GTC ]
Nov 11 17:23:48 initiator charon: 09[IKE] server requested EAP_GTC authentication (id 0x24)
Nov 11 17:23:48 initiator charon: 09[ENC] generating IKE_AUTH request 3 [ EAP/RES/GTC ]
Nov 11 17:23:48 initiator charon: 09[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (92 bytes)
Nov 11 17:23:49 initiator charon: 11[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (76 bytes)
Nov 11 17:23:49 initiator charon: 11[ENC] parsed IKE_AUTH response 3 [ EAP/SUCC ]
Nov 11 17:23:49 initiator charon: 11[IKE] EAP method EAP_GTC succeeded, no MSK established
Nov 11 17:23:49 initiator charon: 11[IKE] authentication of 'my-user' (myself) with EAP
Nov 11 17:23:49 initiator charon: 11[ENC] generating IKE_AUTH request 4 [ AUTH ]
Nov 11 17:23:49 initiator charon: 11[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (92 bytes)
Nov 11 17:23:49 initiator charon: 12[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (300 bytes)
Nov 11 17:23:49 initiator charon: 12[ENC] parsed IKE_AUTH response 4 [ AUTH CPRP(ADDR U_SPLITINC U_LOCALLAN DNS U_DEFDOM DNS) SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) ]
Nov 11 17:23:49 initiator charon: 12[IKE] authentication of 'resonder.domain.com<http://resonder.domain.com>' with EAP successful
Nov 11 17:23:49 initiator charon: 12[IKE] IKE_SA dm-psk[1] established between 10.0.1.36[my-user]...re.sp.on.der[resonder.domain.com<http://resonder.domain.com>]
Nov 11 17:23:49 initiator charon: 12[IKE] scheduling reauthentication in 9837s
Nov 11 17:23:49 initiator charon: 12[IKE] maximum IKE_SA lifetime 10377s
Nov 11 17:23:49 initiator charon: 12[CFG] handling UNITY_SPLIT_INCLUDE attribute failed
Nov 11 17:23:49 initiator charon: 12[CFG] handling UNITY_LOCAL_LAN attribute failed
Nov 11 17:23:49 initiator charon: 12[IKE] installing DNS server 10.8.194.96 to /etc/resolv.conf
Nov 11 17:23:49 initiator charon: 12[CFG] handling UNITY_DEF_DOMAIN attribute failed
Nov 11 17:23:49 initiator charon: 12[IKE] installing DNS server 10.8.194.96 to /etc/resolv.conf
Nov 11 17:23:49 initiator charon: 12[IKE] installing new virtual IP 10.255.252.2
Nov 11 17:23:49 initiator charon: 12[IKE] CHILD_SA dm-psk{1} established with SPIs cbbf0a75_i 0d8253d3_o and TS 10.255.252.2/32 === 10.8.192.0/19
Nov 11 17:23:49 initiator vpn: + resonder.domain.com<http://resonder.domain.com> 10.8.192.0/19 == re.sp.on.der -- 10.0.1.36 == 10.255.252.2/32
Nov 11 17:23:49 initiator charon: 12[IKE] received AUTH_LIFETIME of 9844s, scheduling reauthentication in 9304s
Nov 11 17:23:49 initiator charon: 12[IKE] peer supports MOBIKE



2b.  At 20:02:51, the re-authentication of IKE_SA begins and at 20:02:52, the CHILD_SA dm-psk{5} is established.  Immediately after that, the updown script is called with event up-client:iptables.  However, all the iptables commands fail.  This is the exact same code that succeeded at tunnel creation time (17:23:49) so it must be the case that StrongSwan has changed the environment so that the iptables commands fail.  After all, why re-install iptables rules that are already correctly installed?

Shortly afterward, still at 20:02:51, the updown script is called a second time with event down-client:iptables.  Again, the environment is set such that the iptables commands fail.  If they succeeded, the commands would remove all of the tunnel routing and the tunnel would effectively be down, which is the purpose of the down event.  Then Charon removes the DNS entry on the initiator.  The tunnel is still up but now the initiator has now lost DNS.

Why make updown script calls at all in the make-before-break case?  If they’re needed, why make the up call before the down call?


Nov 11 20:02:51 initiator charon: 07[IKE] reauthenticating IKE_SA dm-psk[1]
Nov 11 20:02:51 initiator charon: 07[IKE] installing new virtual IP 10.255.252.2
Nov 11 20:02:51 initiator charon: 07[IKE] initiating IKE_SA dm-psk[2] to re.sp.on.der
Nov 11 20:02:51 initiator charon: 07[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HASH_ALG) ]
Nov 11 20:02:51 initiator charon: 07[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (1436 bytes)
Nov 11 20:02:51 initiator charon: 04[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (456 bytes)
Nov 11 20:02:51 initiator charon: 04[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HASH_ALG) N(MULT_AUTH) ]
Nov 11 20:02:51 initiator charon: 04[IKE] local host is behind NAT, sending keep alives
Nov 11 20:02:51 initiator charon: 04[IKE] remote host is behind NAT
Nov 11 20:02:51 initiator charon: 04[IKE] authentication of 'my-user' (myself) with pre-shared key
Nov 11 20:02:51 initiator charon: 04[IKE] establishing CHILD_SA dm-psk
Nov 11 20:02:51 initiator charon: 04[ENC] generating IKE_AUTH request 1 [ IDi IDr AUTH CPRQ(ADDR DNS) SA TSi TSr N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) N(AUTH_FOLLOWS) ]
Nov 11 20:02:51 initiator charon: 04[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (428 bytes)
Nov 11 20:02:51 initiator charon: 06[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (124 bytes)
Nov 11 20:02:51 initiator charon: 06[ENC] parsed IKE_AUTH response 1 [ IDr AUTH ]
Nov 11 20:02:51 initiator charon: 06[IKE] authentication of 'responder.domain.com<http://responder.domain.com>' with pre-shared key successful
Nov 11 20:02:51 initiator charon: 06[ENC] generating IKE_AUTH request 2 [ IDi ]
Nov 11 20:02:51 initiator charon: 06[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (76 bytes)
Nov 11 20:02:51 initiator charon: 13[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (92 bytes)
Nov 11 20:02:51 initiator charon: 13[ENC] parsed IKE_AUTH response 2 [ EAP/REQ/GTC ]
Nov 11 20:02:51 initiator charon: 13[IKE] server requested EAP_GTC authentication (id 0x79)
Nov 11 20:02:51 initiator charon: 13[ENC] generating IKE_AUTH request 3 [ EAP/RES/GTC ]
Nov 11 20:02:51 initiator charon: 13[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (92 bytes)
Nov 11 20:02:51 initiator charon: 09[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (76 bytes)
Nov 11 20:02:51 initiator charon: 09[ENC] parsed IKE_AUTH response 3 [ EAP/SUCC ]
Nov 11 20:02:51 initiator charon: 09[IKE] EAP method EAP_GTC succeeded, no MSK established
Nov 11 20:02:51 initiator charon: 09[IKE] authentication of 'my-user' (myself) with EAP
Nov 11 20:02:51 initiator charon: 09[ENC] generating IKE_AUTH request 4 [ AUTH ]
Nov 11 20:02:51 initiator charon: 09[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (92 bytes)
Nov 11 20:02:52 initiator charon: 15[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (300 bytes)
Nov 11 20:02:52 initiator charon: 15[ENC] parsed IKE_AUTH response 4 [ AUTH CPRP(ADDR U_SPLITINC U_LOCALLAN DNS U_DEFDOM DNS) SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) ]
Nov 11 20:02:52 initiator charon: 15[IKE] authentication of 'responder.domain.com<http://responder.domain.com>' with EAP successful
Nov 11 20:02:52 initiator charon: 15[IKE] IKE_SA dm-psk[2] established between 10.0.1.36[my-user]...re.sp.on.der[responder.domain.com<http://responder.domain.com>]
Nov 11 20:02:52 initiator charon: 15[IKE] scheduling reauthentication in 10092s
Nov 11 20:02:52 initiator charon: 15[IKE] maximum IKE_SA lifetime 10632s
Nov 11 20:02:52 initiator charon: 15[CFG] handling UNITY_SPLIT_INCLUDE attribute failed
Nov 11 20:02:52 initiator charon: 15[CFG] handling UNITY_LOCAL_LAN attribute failed
Nov 11 20:02:52 initiator charon: 15[IKE] installing DNS server 10.8.194.96 to /etc/resolv.conf
Nov 11 20:02:52 initiator charon: 15[CFG] handling UNITY_DEF_DOMAIN attribute failed
Nov 11 20:02:52 initiator charon: 15[IKE] installing DNS server 10.8.194.96 to /etc/resolv.conf
Nov 11 20:02:52 initiator charon: 15[IKE] installing new virtual IP 10.255.252.2
Nov 11 20:02:52 initiator charon: 15[IKE] CHILD_SA dm-psk{5} established with SPIs ce54cd29_i 759cb598_o and TS 10.255.252.2/32 === 10.8.192.0/19
Nov 11 20:02:52 initiator charon: 15[CHD] updown: /usr/libexec/strongswan/_updown: line 300: iptables: command not found
Nov 11 20:02:52 initiator charon: 15[CHD] updown: /usr/libexec/strongswan/_updown: line 303: iptables: command not found
Nov 11 20:02:52 initiator charon: 15[CHD] updown: /usr/libexec/strongswan/_updown: line 312: iptables: command not found
Nov 11 20:02:52 initiator charon: 15[CHD] updown: /usr/libexec/strongswan/_updown: line 315: iptables: command not found
Nov 11 20:02:52 initiator vpn: + responder.domain.com<http://responder.domain.com> 10.8.192.0/19 == re.sp.on.der -- 10.0.1.36 == 10.255.252.2/32
Nov 11 20:02:52 initiator charon: 15[IKE] received AUTH_LIFETIME of 9930s, scheduling reauthentication in 9390s
Nov 11 20:02:52 initiator charon: 15[IKE] peer supports MOBIKE
Nov 11 20:02:52 initiator charon: 10[IKE] deleting IKE_SA dm-psk[1] between 10.0.1.36[my-user]...re.sp.on.der[responder.domain.com<http://responder.domain.com>]
Nov 11 20:02:52 initiator charon: 10[IKE] sending DELETE for IKE_SA dm-psk[1]
Nov 11 20:02:52 initiator charon: 10[ENC] generating INFORMATIONAL request 12 [ D ]
Nov 11 20:02:52 initiator charon: 10[NET] sending packet: from 10.0.1.36[4500] to re.sp.on.der[4500] (76 bytes)
Nov 11 20:02:52 initiator charon: 14[NET] received packet: from re.sp.on.der[4500] to 10.0.1.36[4500] (76 bytes)
Nov 11 20:02:52 initiator charon: 14[ENC] parsed INFORMATIONAL response 12 [ ]
Nov 11 20:02:52 initiator charon: 14[IKE] IKE_SA deleted
Nov 11 20:02:52 initiator charon: 14[CHD] updown: /usr/libexec/strongswan/_updown: line 348: iptables: command not found
Nov 11 20:02:52 initiator charon: 14[CHD] updown: /usr/libexec/strongswan/_updown: line 352: iptables: command not found
Nov 11 20:02:52 initiator charon: 14[CHD] updown: /usr/libexec/strongswan/_updown: line 362: iptables: command not found
Nov 11 20:02:52 initiator charon: 14[CHD] updown: /usr/libexec/strongswan/_updown: line 366: iptables: command not found
Nov 11 20:02:52 initiator vpn: - responder.domain.com<http://responder.domain.com> 10.8.192.0/19 == re.sp.on.der -- 10.0.1.36 == 10.255.252.2/32
Nov 11 20:02:52 initiator charon: 14[IKE] removing DNS server 10.8.194.96 from /etc/resolv.conf
Nov 11 20:02:52 initiator charon: 14[IKE] removing DNS server 10.8.194.96 from /etc/resolv.conf
Nov 11 20:02:52 initiator charon: 14[IKE] removing DNS server 10.8.194.96 from /etc/resolv.conf
Nov 11 20:02:52 initiator charon: 14[IKE] removing DNS server 10.8.194.96 from /etc/resolv.conf
Nov 11 20:03:15 initiator charon: 11[IKE] sending keep alive to re.sp.on.der[4500]
Nov 11 20:03:22 initiator charon: 04[IKE] sending DPD request



On Nov 18, 2015, at 4:18 AM, Tobias Brunner <tobias at strongswan.org<mailto:tobias at strongswan.org>> wrote:

Hi Ken,

Questions

1.  How to prevent Charon from removing the name server configuration
from /etc/resolv.conf in the IKA_SA re-authentication case?

You currently can't.  I guess the resolve plugin could do some
refcounting for installed DNS servers (like we do for virtual IPs in
other plugins), which would workaround that problem.

2.  Why does the up/down script get invoked during IKE_SA
re-authentication?  When “make before break” is enabled, the up/down
script invocation seems backward/awkward.  That is, up/down is invoked
with an ‘up’ notification at the initial establishment of the tunnel,
then again with a second ‘up’ notification during the “make before
break”, then finally with a ‘down’ notification even though the tunnel
is up?!?

Reauthentication in IKEv2 creates a new IKE_SA and a new set of the
already existing CHILD_SAs.  Either the old stuff gets torn down first
(break-before-make) or that's done after completing the new stuff
(make-before-break).  Since every CHILD_SA gets an "up" event when it is
installed, and a "down" event when it is uninstalled what you see is a
logical consequence.  There is no relationship between the SAs unlike
when rekeying is used (where these events are suppressed), so you get an
initial "up" then an "up" for the newly created SA and then a "down" for
the old SA.  While a client that initiates a make-before-break
reauthentication could probably pretend there is some kind of
relationship between these SAs, a server can't do that without using
heuristics to detect reauthentications, like the ones we use for IKEv1
(which might not always work as expected).  If you don't _need_
reauthentication you should probably use rekeying instead.

3. Aside:  why does /usr/libexec/strongswan/_updown fail to find iptables?

No idea.  Perhaps your PATH does not include its location or the user
has no permission to access it (or perhaps due to some hardening
mechanism like SELinux/AppArmor).

Regards,
Tobias


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/dev/attachments/20151118/f039a5fe/attachment-0001.html>


More information about the Dev mailing list