[strongSwan] IKE_SA rekey issue with shrewsoft

yordanos beyene yordanosb at gmail.com
Wed Mar 26 09:53:26 CET 2014


Hi SS team,


I could not get strongswan to process IKE_SA rekey successfully with
shrewsoft vpn client. I am running strongswan 5.1.2. The strongswan
configuration and charon log is included below.

Strongswan ikelifetime=600s and keylife=120s
Shrewsoft IKE lifetime=1200s and IPsec lifetime is 600s.
This strongswan initiates CHILD_SA and IKE_SA rekey.


Initially IKE_SA and CHILD_SA are successfully established and ESP is
applied  to traffic from client to a server behind vpn gateway. CHILD_SA
rekey succeeds every 120 seconds (keylife time), but tunnel is down after
the first IKE_SA  rekey (600 sec) fails.

I appreciate any patch or configuration tips to address the issue.


*ipsec.conf:*

config setup
        cachecrls=no
        strictcrlpolicy=no
conn %default
        auto=route
        keyingtries=1
conn mypolicy
        keyexchange=ikev1
        aggressive= yes
        left=172.16.50.2
        right=172.16.50.10
        leftsubnet=172.16.40.0/24
        leftid=%any
        rightid=%any
        type=tunnel
        ike=3des-sha1-modp1024!
        esp=3des-sha1!
        ikelifetime=600s
        keylife=120s
        margintime=0s
        rightsourceip=172.16.80.0/24
        leftauth=secret
        rightauth=secret
        rightauth2=xauth-generic
        auto=add
        rekey=yes
        reauth=no
*charon.log*
Mar 25 21:09:57 00[DMN] Starting IKE charon daemon (strongSwan 5.1.2, Linux
2.6.32-220.el6.i686, i686)
Mar 25 21:09:57 00[LIB] openssl FIPS mode(0) - disabled
Mar 25 21:09:57 00[CFG] loading ca certificates from
'/usr/local/etc/ipsec.d/cacerts'
Mar 25 21:09:57 00[CFG] loading aa certificates from
'/usr/local/etc/ipsec.d/aacerts'
Mar 25 21:09:57 00[CFG] loading ocsp signer certificates from
'/usr/local/etc/ipsec.d/ocspcerts'
Mar 25 21:09:57 00[CFG] loading attribute certificates from
'/usr/local/etc/ipsec.d/acerts'
Mar 25 21:09:57 00[CFG] loading crls from '/usr/local/etc/ipsec.d/crls'
Mar 25 21:09:57 00[CFG] loading secrets from '/usr/local/etc/ipsec.secrets'
Mar 25 21:09:57 00[CFG]   loaded EAP secret for jordan
Mar 25 21:09:57 00[CFG]   loaded IKE secret for %any
Mar 25 21:09:57 00[CFG]   loaded IKE secret for %any
Mar 25 21:09:57 00[CFG] opening triplet file
/usr/local/etc/ipsec.d/triplets.dat failed: No such file or directory
Mar 25 21:09:57 00[CFG] loaded 0 RADIUS server configurations
Mar 25 21:09:57 00[CFG] coupling file path unspecified
Mar 25 21:09:57 00[LIB] loaded plugins: charon curl ldap aes des rc2 sha1
sha2 md5 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8
pkcs12 pgp dnskey sshkey pem openssl gcr
ypt fips-prf gmp xcbc cmac hmac attr kernel-netlink resolve socket-default
farp stroke updown eap-identity eap-sim eap-aka eap-aka-3gpp2 eap-md5
eap-gtc eap-mschapv2 eap-radius eap-tls eap-
ttls eap-peap xauth-generic xauth-eap dhcp led duplicheck
Mar 25 21:09:57 00[LIB] unable to load 13 plugin features (11 due to unmet
dependencies)
Mar 25 21:09:57 00[LIB] dropped capabilities, running as uid 200, gid 200
Mar 25 21:09:57 00[JOB] spawning 16 worker threads
Mar 25 21:09:57 08[CFG] received stroke: add connection 'mypolicy'
Mar 25 21:09:57 08[CFG] adding virtual IP address pool 172.16.80.0/24
Mar 25 21:09:57 08[CFG] added configuration 'mypolicy'
Mar 25 21:10:10 09[CFG] rereading secrets
Mar 25 21:10:10 09[CFG] loading secrets from '/usr/local/etc/ipsec.secrets'
Mar 25 21:10:10 09[CFG]   loaded EAP secret for jordan
Mar 25 21:10:10 09[CFG]   loaded IKE secret for %any
Mar 25 21:10:10 09[CFG]   loaded IKE secret for %any
Mar 25 21:11:57 13[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (372 bytes)
Mar 25 21:11:57 13[ENC] parsed AGGRESSIVE request 0 [ SA KE No ID V V V V V
V ]
Mar 25 21:11:57 13[IKE] received XAuth vendor ID
Mar 25 21:11:57 13[IKE] received FRAGMENTATION vendor ID
Mar 25 21:11:57 13[ENC] received unknown vendor ID:
f1:4b:94:b7:bf:f1:fe:f0:27:73:b8:c4:9f:ed:ed:26
Mar 25 21:11:57 13[ENC] received unknown vendor ID:
16:6f:93:2d:55:eb:64:d8:e4:df:4f:d3:7e:23:13:f0:d0:fd:84:51
Mar 25 21:11:57 13[ENC] received unknown vendor ID:
84:04:ad:f9:cd:a0:57:60:b2:ca:29:2e:4b:ff:53:7b
Mar 25 21:11:57 13[IKE] received Cisco Unity vendor ID
Mar 25 21:11:57 13[IKE] 172.16.50.10 is initiating a Aggressive Mode IKE_SA
Mar 25 21:11:57 13[CFG] looking for XAuthInitPSK peer configs matching
172.16.50.2...172.16.50.10[172.16.50.10]
Mar 25 21:11:57 13[CFG] selected peer config "mypolicy"
Mar 25 21:11:57 13[ENC] generating AGGRESSIVE response 0 [ SA KE No ID HASH
V V V ]
Mar 25 21:11:57 13[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (336 bytes)
Mar 25 21:11:57 14[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 25 21:11:57 14[ENC] parsed AGGRESSIVE request 0 [ HASH ]
Mar 25 21:11:57 14[ENC] generating TRANSACTION request 85037345 [ HASH
CPRQ(X_USER X_PWD) ]
Mar 25 21:11:57 14[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 25 21:11:57 14[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (84 bytes)
Mar 25 21:11:57 14[ENC] parsed INFORMATIONAL_V1 request 2336741573 [ HASH
N(INITIAL_CONTACT) ]
Mar 25 21:11:57 16[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (84 bytes)
Mar 25 21:11:57 16[ENC] parsed TRANSACTION response 85037345 [ HASH
CPRP(X_TYPE X_USER X_PWD) ]
Mar 25 21:11:57 16[IKE] XAuth authentication of 'jordan' successful
Mar 25 21:11:57 16[ENC] generating TRANSACTION request 213917962 [ HASH
CPS(X_STATUS) ]
Mar 25 21:11:57 16[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (68 bytes)
Mar 25 21:11:57 02[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (60 bytes)
Mar 25 21:11:57 02[ENC] parsed TRANSACTION response 213917962 [ HASH CP ]
*Mar 25 21:11:57 02[IKE]*
*IKE_SA mypolicy[1] established between
172.16.50.2[172.16.50.2]...172.16.50.10[172.16.50.10]*Mar 25 21:11:57
02[IKE] scheduling rekeying in 600s
Mar 25 21:11:57 02[IKE] maximum IKE_SA lifetime 600s
Mar 25 21:11:57 02[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 25 21:11:57 02[ENC] parsed TRANSACTION request 3957525860 [ HASH
CPRQ(ADDR EXP MASK DNS NBNS U_DEFDOM U_SAVEPWD VER U_FWTYPE) ]
Mar 25 21:11:57 02[IKE] peer requested virtual IP %any
Mar 25 21:11:57 02[CFG] assigning new lease to 'jordan'
Mar 25 21:11:57 02[IKE] assigning virtual IP 172.16.80.1 to peer 'jordan'
Mar 25 21:11:57 02[ENC] generating TRANSACTION response 3957525860 [ HASH
CPRP(ADDR) ]
Mar 25 21:11:57 02[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 25 21:11:58 12[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 25 21:11:58 12[ENC] parsed QUICK_MODE request 2319360488 [ HASH SA No
ID ID ]
Mar 25 21:11:58 12[IKE] received 300s lifetime, configured 120s
Mar 25 21:11:58 12[ENC] generating QUICK_MODE response 2319360488 [ HASH SA
No ID ID ]
Mar 25 21:11:58 12[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (172 bytes)
Mar 25 21:11:58 13[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 25 21:11:58 13[ENC] parsed QUICK_MODE request 2319360488 [ HASH ]

*Mar 25 21:11:58 13[IKE] CHILD_SA mypolicy{1} established with SPIs
cd6cce5e_i da9eca24_o and TS 172.16.40.0/24 <http://172.16.40.0/24> ===
172.16.80.1/32 <http://172.16.80.1/32>*Mar 25 21:13:58 13[KNL] creating
delete job for ESP CHILD_SA with SPI cd6cce5e and reqid {1}
Mar 25 21:13:58 13[IKE] closing expired CHILD_SA mypolicy{1} with SPIs
cd6cce5e_i da9eca24_o and TS 172.16.40.0/24 === 172.16.80.1/32
Mar 25 21:13:58 16[KNL] creating delete job for ESP CHILD_SA with SPI
da9eca24 and reqid {1}
Mar 25 21:13:58 13[IKE] sending DELETE for ESP CHILD_SA with SPI cd6cce5e
Mar 25 21:13:58 13[ENC] generating INFORMATIONAL_V1 request 1247408784 [
HASH D ]
Mar 25 21:13:58 13[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 25 21:13:58 16[JOB] CHILD_SA with reqid 1 not found for delete
Mar 25 21:13:58 10[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 25 21:13:58 10[ENC] parsed QUICK_MODE request 3977682094 [ HASH SA No
ID ID ]
Mar 25 21:13:58 10[IKE] received 300s lifetime, configured 120s
Mar 25 21:13:58 10[ENC] generating QUICK_MODE response 3977682094 [ HASH SA
No ID ID ]
Mar 25 21:13:58 10[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (172 bytes)
Mar 25 21:13:58 09[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 25 21:13:58 09[ENC] parsed QUICK_MODE request 3977682094 [ HASH ]

*Mar 25 21:13:58 09[IKE] CHILD_SA mypolicy{2} established with SPIs
ceeb09c7_i 3914aa7b_o and TS 172.16.40.0/24 <http://172.16.40.0/24> ===
172.16.80.1/32 <http://172.16.80.1/32>*Mar 25 21:15:58 13[KNL] creating
delete job for ESP CHILD_SA with SPI ceeb09c7 and reqid {2}
Mar 25 21:15:58 13[IKE] closing expired CHILD_SA mypolicy{2} with SPIs
ceeb09c7_i 3914aa7b_o and TS 172.16.40.0/24 === 172.16.80.1/32
Mar 25 21:15:58 03[KNL] creating delete job for ESP CHILD_SA with SPI
3914aa7b and reqid {2}
Mar 25 21:15:58 13[IKE] sending DELETE for ESP CHILD_SA with SPI ceeb09c7
Mar 25 21:15:58 13[ENC] generating INFORMATIONAL_V1 request 497504590 [
HASH D ]
Mar 25 21:15:58 13[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 25 21:15:58 03[JOB] CHILD_SA with reqid 2 not found for delete
Mar 25 21:15:59 14[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 25 21:15:59 14[ENC] parsed QUICK_MODE request 2221971296 [ HASH SA No
ID ID ]
Mar 25 21:15:59 14[IKE] received 300s lifetime, configured 120s
Mar 25 21:15:59 14[ENC] generating QUICK_MODE response 2221971296 [ HASH SA
No ID ID ]
Mar 25 21:15:59 14[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (172 bytes)
Mar 25 21:15:59 15[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 25 21:15:59 15[ENC] parsed QUICK_MODE request 2221971296 [ HASH ]

*Mar 25 21:15:59 15[IKE] CHILD_SA mypolicy{3} established with SPIs
cdf7956e_i 8dbf2141_o and TS 172.16.40.0/24 <http://172.16.40.0/24> ===
172.16.80.1/32 <http://172.16.80.1/32>*Mar 25 21:17:59 09[KNL] creating
delete job for ESP CHILD_SA with SPI cdf7956e and reqid {3}
Mar 25 21:17:59 09[IKE] closing expired CHILD_SA mypolicy{3} with SPIs
cdf7956e_i 8dbf2141_o and TS 172.16.40.0/24 === 172.16.80.1/32
Mar 25 21:17:59 09[IKE] sending DELETE for ESP CHILD_SA with SPI cdf7956e
Mar 25 21:17:59 09[ENC] generating INFORMATIONAL_V1 request 2022840555 [
HASH D ]
Mar 25 21:17:59 13[KNL] creating delete job for ESP CHILD_SA with SPI
8dbf2141 and reqid {3}
Mar 25 21:17:59 09[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 25 21:17:59 13[JOB] CHILD_SA with reqid 3 not found for delete
Mar 25 21:18:01 08[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 25 21:18:01 08[ENC] parsed QUICK_MODE request 1207082033 [ HASH SA No
ID ID ]
Mar 25 21:18:01 08[IKE] received 300s lifetime, configured 120s
Mar 25 21:18:01 08[ENC] generating QUICK_MODE response 1207082033 [ HASH SA
No ID ID ]
Mar 25 21:18:01 08[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (172 bytes)
Mar 25 21:18:01 10[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 25 21:18:01 10[ENC] parsed QUICK_MODE request 1207082033 [ HASH ]

*Mar 25 21:18:01 10[IKE] CHILD_SA mypolicy{4} established with SPIs
c827c940_i 287c9785_o and TS 172.16.40.0/24 <http://172.16.40.0/24> ===
172.16.80.1/32 <http://172.16.80.1/32>*Mar 25 21:20:01 13[KNL] creating
delete job for ESP CHILD_SA with SPI c827c940 and reqid {4}
Mar 25 21:20:01 13[IKE] closing expired CHILD_SA mypolicy{4} with SPIs
c827c940_i 287c9785_o and TS 172.16.40.0/24 === 172.16.80.1/32
Mar 25 21:20:01 13[IKE] sending DELETE for ESP CHILD_SA with SPI c827c940
Mar 25 21:20:01 13[ENC] generating INFORMATIONAL_V1 request 4634697 [ HASH
D ]
Mar 25 21:20:01 13[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 25 21:20:06 11[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 25 21:20:06 11[ENC] parsed QUICK_MODE request 1449238607 [ HASH SA No
ID ID ]
Mar 25 21:20:06 11[IKE] received 300s lifetime, configured 120s
Mar 25 21:20:06 11[ENC] generating QUICK_MODE response 1449238607 [ HASH SA
No ID ID ]
Mar 25 21:20:06 11[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (172 bytes)
Mar 25 21:20:06 12[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 25 21:20:06 12[ENC] parsed QUICK_MODE request 1449238607 [ HASH ]

*Mar 25 21:20:06 12[IKE] CHILD_SA mypolicy{5} established with SPIs
c46af437_i fd68bc3b_o and TS 172.16.40.0/24 <http://172.16.40.0/24> ===
172.16.80.1/32 <http://172.16.80.1/32>*Mar 25 21:21:57 10[IKE] initiating
Aggressive Mode IKE_SA mypolicy[2] to 172.16.50.10
Mar 25 21:21:57 10[ENC] generating AGGRESSIVE request 0 [ SA KE No ID V V V
V V ]
Mar 25 21:21:57 10[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (352 bytes)
Mar 25 21:21:57 11[CFG] lease 172.16.80.1 by 'jordan' went offline
Mar 25 21:22:01 14[IKE] sending retransmit 1 of request message ID 0, seq 1
Mar 25 21:22:01 14[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (352 bytes)
Mar 25 21:22:06 03[KNL] creating delete job for ESP CHILD_SA with SPI
c46af437 and reqid {5}
Mar 25 21:22:06 10[KNL] creating delete job for ESP CHILD_SA with SPI
fd68bc3b and reqid {5}
Mar 25 21:22:08 13[IKE] sending retransmit 2 of request message ID 0, seq 1
Mar 25 21:22:08 13[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (352 bytes)
Mar 25 21:22:21 01[IKE] sending retransmit 3 of request message ID 0, seq 1
Mar 25 21:22:21 01[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (352 bytes)
Mar 25 21:22:44 10[IKE] sending retransmit 4 of request message ID 0, seq 1
Mar 25 21:22:44 10[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (352 bytes)
Mar 25 21:23:26 11[IKE] sending retransmit 5 of request message ID 0, seq 1
Mar 25 21:23:26 11[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (352 bytes)
Mar 25 21:24:42 02[IKE] giving up after 5 retransmits
*Mar 25 21:24:42 02[IKE] establishing IKE_SA failed, peer not responding*


Thanks!

Jordan.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/users/attachments/20140326/77106cb0/attachment-0001.html>


More information about the Users mailing list