[strongSwan] IKE_SA rekey issue with shrewsoft

yordanos beyene yordanosb at gmail.com
Thu Mar 27 09:31:34 CET 2014


Hello again,


I changed the IKE and IPsec lifetime values to force shrew soft vpn client
to initiate CHILD_SA and IKE_SA rekey. IKE_SA rekey failed and eventually
the tunnel went down.

I used the following lifetime values:
Shrew soft vpn client  ike lifetime=1200s and IPsec lifetime is 300s.
Strongswan ikelifetime=3600s and keylife= 600 s

The CHILD_SA are successfully rekeyed until the first IKE_SA is initiated.
After the first IKE_SA rekey,  the IP Pool lease goes down and eventually
vpn connection terminates and I can no more pass traffic.

I noticed that Strongswan negotiates to use the vpn client lifetime but it
practically uses its own lifetime. This seems to be the cause of the issue.
CHILD_SA are not flushed from strongswan vpn gateway until its own
configured lifetime expires.

Below is the strongswan configuration and log files.

Please guide me how to get around this problem. I appreciate if anyone can
share configuration tweaks to get IKE_SA rekey work with shrew soft vpn
client.

I am running strongswan 5.1.2.


Thanks!


*#ipsec.conf*

config setup
        cachecrls=no
        strictcrlpolicy=no

conn %default
        auto=route
        keyingtries=1

conn mypolicy
        keyexchange=ikev1
        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=3600s
        keylife=600s
        margintime=0s
        rightsourceip=172.16.80.0/24
        leftauth=secret
        rightauth=secret
        rightauth2=xauth-generic
        auto=add
        rekey=yes
        reauth=no


[mypc at centos~]#tail -f /var/log/charon.log
Mar 26 20:08:51 00[LIB] dropped capabilities, running as uid 200, gid 200
Mar 26 20:08:51 00[JOB] spawning 16 worker threads
Mar 26 20:08:51 08[CFG] received stroke: add connection 'mypolicy'
Mar 26 20:08:51 08[CFG] adding virtual IP address pool 172.16.80.0/24
Mar 26 20:08:51 08[CFG] added configuration 'mypolicy'
Mar 26 20:09:00 08[CFG] rereading secrets
Mar 26 20:09:00 08[CFG] loading secrets from '/usr/local/etc/ipsec.secrets'
Mar 26 20:09:00 08[CFG]   loaded EAP secret for jordan
Mar 26 20:09:00 08[CFG]   loaded IKE secret for %any
Mar 26 20:09:00 08[CFG]   loaded IKE secret for %any
Mar 26 20:10:33 11[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (312 bytes)
Mar 26 20:10:33 11[ENC] parsed ID_PROT request 0 [ SA V V V V V V ]
Mar 26 20:10:33 11[IKE] received XAuth vendor ID
Mar 26 20:10:33 11[IKE] received FRAGMENTATION vendor ID
Mar 26 20:10:33 11[ENC] received unknown vendor ID:
f1:4b:94:b7:bf:f1:fe:f0:27:73:b8:c4:9f:ed:ed:26
Mar 26 20:10:33 11[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 26 20:10:33 11[ENC] received unknown vendor ID:
84:04:ad:f9:cd:a0:57:60:b2:ca:29:2e:4b:ff:53:7b
Mar 26 20:10:33 11[IKE] received Cisco Unity vendor ID
Mar 26 20:10:33 11[IKE] 172.16.50.10 is initiating a Main Mode IKE_SA
Mar 26 20:10:33 11[ENC] generating ID_PROT response 0 [ SA V V V ]
Mar 26 20:10:33 11[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (132 bytes)
Mar 26 20:10:33 12[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (184 bytes)
Mar 26 20:10:33 12[ENC] parsed ID_PROT request 0 [ KE No ]
Mar 26 20:10:33 12[ENC] generating ID_PROT response 0 [ KE No ]
Mar 26 20:10:33 12[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (196 bytes)
Mar 26 20:10:33 13[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (68 bytes)
Mar 26 20:10:33 13[ENC] parsed ID_PROT request 0 [ ID HASH ]
Mar 26 20:10:33 13[CFG] looking for XAuthInitPSK peer configs matching
172.16.50.2...172.16.50.10[172.16.50.10]
Mar 26 20:10:33 13[CFG] selected peer config "mypolicy"
Mar 26 20:10:33 13[ENC] generating ID_PROT response 0 [ ID HASH ]
Mar 26 20:10:33 13[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (68 bytes)
Mar 26 20:10:33 13[ENC] generating TRANSACTION request 2131954070 [ HASH
CPRQ(X_USER X_PWD) ]
Mar 26 20:10:33 13[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 26 20:10:33 14[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (84 bytes)
Mar 26 20:10:33 14[ENC] parsed INFORMATIONAL_V1 request 3099837383 [ HASH
N(INITIAL_CONTACT) ]
Mar 26 20:10:33 14[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (84 bytes)
Mar 26 20:10:33 14[ENC] parsed TRANSACTION response 2131954070 [ HASH
CPRP(X_TYPE X_USER X_PWD) ]
Mar 26 20:10:33 14[IKE] XAuth authentication of 'jordan' successful
Mar 26 20:10:33 14[ENC] generating TRANSACTION request 3742891146 [ HASH
CPS(X_STATUS) ]
Mar 26 20:10:33 14[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (68 bytes)
Mar 26 20:10:33 16[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (60 bytes)
Mar 26 20:10:33 16[ENC] parsed TRANSACTION response 3742891146 [ HASH CP ]
*Mar 26 20:10:33 16[IKE] IKE_SA mypolicy[1] established between
172.16.50.2[172.16.50.2]...172.16.50.10[172.16.50.10]*
Mar 26 20:10:33 16[IKE] scheduling rekeying in 3600s
Mar 26 20:10:33 16[IKE] maximum IKE_SA lifetime 3600s
Mar 26 20:10:33 16[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:10:33 16[ENC] parsed TRANSACTION request 1369079935 [ HASH
CPRQ(ADDR EXP MASK DNS NBNS U_DEFDOM U_SAVEPWD VER U_FWTYPE) ]
Mar 26 20:10:33 16[IKE] peer requested virtual IP %any
Mar 26 20:10:33 16[CFG] assigning new lease to 'jordan'
Mar 26 20:10:33 16[IKE] assigning virtual IP 172.16.80.1 to peer 'jordan'
Mar 26 20:10:33 16[ENC] generating TRANSACTION response 1369079935 [ HASH
CPRP(ADDR) ]
Mar 26 20:10:33 16[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 26 20:10:40 13[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:10:40 13[ENC] parsed QUICK_MODE request 4000330551 [ HASH SA No
ID ID ]
Mar 26 20:10:40 13[IKE] received 300s lifetime, configured 600s
Mar 26 20:10:40 13[ENC] generating QUICK_MODE response 4000330551 [ HASH SA
No ID ID ]
Mar 26 20:10:40 13[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (172 bytes)
Mar 26 20:10:40 14[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 26 20:10:40 14[ENC] parsed QUICK_MODE request 4000330551 [ HASH ]
*Mar 26 20:10:40 14[IKE] CHILD_SA mypolicy{1} established with SPIs
cfa38ed8_i c5c63403_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 26 20:14:40 12[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:14:40 12[ENC] parsed QUICK_MODE request 3560493529 [ HASH SA No
ID ID ]
Mar 26 20:14:40 12[IKE] received 300s lifetime, configured 600s
Mar 26 20:14:40 12[IKE] detected rekeying of CHILD_SA mypolicy{1}
Mar 26 20:14:40 12[ENC] generating QUICK_MODE response 3560493529 [ HASH SA
No ID ID ]
Mar 26 20:14:40 12[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (172 bytes)
Mar 26 20:14:41 14[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 26 20:14:41 14[ENC] parsed QUICK_MODE request 3560493529 [ HASH ]
*Mar 26 20:14:41 14[IKE] CHILD_SA mypolicy{1} established with SPIs
c7f534ac_i fac37624_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 26 20:18:41 11[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:18:41 11[ENC] parsed QUICK_MODE request 2579174717 [ HASH SA No
ID ID ]
Mar 26 20:18:41 11[IKE] received 300s lifetime, configured 600s
Mar 26 20:18:41 11[IKE] detected rekeying of CHILD_SA mypolicy{1}
Mar 26 20:18:41 11[ENC] generating QUICK_MODE response 2579174717 [ HASH SA
No ID ID ]
Mar 26 20:18:41 11[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (172 bytes)
Mar 26 20:18:41 12[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:18:41 12[ENC] parsed QUICK_MODE request 1607868552 [ HASH SA No
ID ID ]
*Mar 26 20:18:41 12[IKE] CHILD_SA mypolicy{1} established with SPIs
cbd0760a_i 98ef05d1_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 26 20:18:41 13[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 26 20:18:41 13[ENC] parsed QUICK_MODE request 2579174717 [ HASH ]
Mar 26 20:18:41 13[IKE] sa payload missing
Mar 26 20:18:41 13[ENC] generating INFORMATIONAL_V1 request 3969855327 [
HASH N(CRIT) ]
Mar 26 20:18:41 13[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 26 20:18:46 14[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:18:46 14[ENC] invalid HASH_V1 payload length, decryption failed?
Mar 26 20:18:46 14[ENC] could not decrypt payloads
Mar 26 20:18:46 14[IKE] message parsing failed
Mar 26 20:18:46 14[ENC] generating INFORMATIONAL_V1 request 2378489903 [
HASH N(PLD_MAL) ]
Mar 26 20:18:46 14[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (68 bytes)
Mar 26 20:18:46 14[IKE] QUICK_MODE request with message ID 1607868552
processing failed
Mar 26 20:18:51 08[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:18:51 08[ENC] invalid HASH_V1 payload length, decryption failed?
Mar 26 20:18:51 08[ENC] could not decrypt payloads
Mar 26 20:18:51 08[IKE] message parsing failed
Mar 26 20:18:51 08[ENC] generating INFORMATIONAL_V1 request 1459306840 [
HASH N(PLD_MAL) ]
Mar 26 20:18:51 08[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (68 bytes)
Mar 26 20:18:51 08[IKE] QUICK_MODE request with message ID 1607868552
processing failed
Mar 26 20:18:56 03[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:18:56 03[ENC] invalid HASH_V1 payload length, decryption failed?
Mar 26 20:18:56 03[ENC] could not decrypt payloads
Mar 26 20:18:56 03[IKE] message parsing failed
Mar 26 20:18:56 03[ENC] generating INFORMATIONAL_V1 request 1420736257 [
HASH N(PLD_MAL) ]
Mar 26 20:18:56 03[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (68 bytes)
Mar 26 20:18:56 03[IKE] QUICK_MODE request with message ID 1607868552
processing failed
Mar 26 20:20:40 15[KNL] creating delete job for ESP CHILD_SA with SPI
cfa38ed8 and reqid {1}
Mar 26 20:20:40 15[IKE] closing expired CHILD_SA mypolicy{1} with SPIs
cfa38ed8_i c5c63403_o and TS 172.16.40.0/24 === 172.16.80.1/32
Mar 26 20:20:40 15[IKE] sending DELETE for ESP CHILD_SA with SPI cfa38ed8
Mar 26 20:20:40 15[ENC] generating INFORMATIONAL_V1 request 2555004867 [
HASH D ]
Mar 26 20:20:40 15[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 26 20:22:41 15[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:22:41 15[ENC] parsed QUICK_MODE request 1483883341 [ HASH SA No
ID ID ]
Mar 26 20:22:41 15[IKE] received 300s lifetime, configured 600s
Mar 26 20:22:41 15[IKE] detected rekeying of CHILD_SA mypolicy{1}
Mar 26 20:22:41 15[ENC] generating QUICK_MODE response 1483883341 [ HASH SA
No ID ID ]
Mar 26 20:22:41 15[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (172 bytes)
Mar 26 20:22:41 09[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (52 bytes)
Mar 26 20:22:41 09[ENC] parsed QUICK_MODE request 1483883341 [ HASH ]
*Mar 26 20:22:41 09[IKE] CHILD_SA mypolicy{1} established with SPIs
c420eddf_i 79833585_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 26 20:24:41 16[KNL] creating delete job for ESP CHILD_SA with SPI
c7f534ac and reqid {1}
Mar 26 20:24:41 16[IKE] closing expired CHILD_SA mypolicy{1} with SPIs
c7f534ac_i fac37624_o and TS 172.16.40.0/24 === 172.16.80.1/32
Mar 26 20:24:41 16[IKE] sending DELETE for ESP CHILD_SA with SPI c7f534ac
Mar 26 20:24:41 16[ENC] generating INFORMATIONAL_V1 request 1963175476 [
HASH D ]
Mar 26 20:24:41 16[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 26 20:24:41 12[KNL] creating delete job for ESP CHILD_SA with SPI
fac37624 and reqid {1}
Mar 26 20:26:33 12[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (312 bytes)
Mar 26 20:26:33 12[ENC] parsed ID_PROT request 0 [ SA V V V V V V ]
Mar 26 20:26:33 12[IKE] received XAuth vendor ID
Mar 26 20:26:33 12[IKE] received FRAGMENTATION vendor ID
Mar 26 20:26:33 12[ENC] received unknown vendor ID:
f1:4b:94:b7:bf:f1:fe:f0:27:73:b8:c4:9f:ed:ed:26
Mar 26 20:26:33 12[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 26 20:26:33 12[ENC] received unknown vendor ID:
84:04:ad:f9:cd:a0:57:60:b2:ca:29:2e:4b:ff:53:7b
Mar 26 20:26:33 12[IKE] received Cisco Unity vendor ID
Mar 26 20:26:33 12[IKE] 172.16.50.10 is initiating a Main Mode IKE_SA
Mar 26 20:26:33 12[ENC] generating ID_PROT response 0 [ SA V V V ]
Mar 26 20:26:33 12[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (132 bytes)
Mar 26 20:26:33 01[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (184 bytes)
Mar 26 20:26:33 01[ENC] parsed ID_PROT request 0 [ KE No ]
Mar 26 20:26:33 01[ENC] generating ID_PROT response 0 [ KE No ]
Mar 26 20:26:33 01[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (196 bytes)
Mar 26 20:26:33 09[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (68 bytes)
Mar 26 20:26:33 09[ENC] parsed ID_PROT request 0 [ ID HASH ]
Mar 26 20:26:33 09[CFG] looking for XAuthInitPSK peer configs matching
172.16.50.2...172.16.50.10[172.16.50.10]
Mar 26 20:26:33 09[CFG] selected peer config "mypolicy"
Mar 26 20:26:33 09[ENC] generating ID_PROT response 0 [ ID HASH ]
Mar 26 20:26:33 09[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (68 bytes)
Mar 26 20:26:33 09[ENC] generating TRANSACTION request 3640581815 [ HASH
CPRQ(X_USER X_PWD) ]
Mar 26 20:26:33 09[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 26 20:26:33 08[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (84 bytes)
Mar 26 20:26:33 08[ENC] parsed TRANSACTION response 3640581815 [ HASH
CPRP(X_TYPE X_USER X_PWD) ]
Mar 26 20:26:33 08[IKE] XAuth authentication of 'jordan' successful
Mar 26 20:26:33 08[ENC] generating TRANSACTION request 2336290606 [ HASH
CPS(X_STATUS) ]
Mar 26 20:26:33 08[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (68 bytes)
Mar 26 20:26:33 10[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (60 bytes)
Mar 26 20:26:33 10[ENC] parsed TRANSACTION response 2336290606 [ HASH CP ]
*Mar 26 20:26:33 10[IKE] IKE_SA mypolicy[2] established between
172.16.50.2[172.16.50.2]...172.16.50.10[172.16.50.10]*




*Mar 26 20:26:33 10[IKE] scheduling rekeying in 3600sMar 26 20:26:33
10[IKE] maximum IKE_SA lifetime 3600sMar 26 20:26:33 10[CFG] detected
duplicate IKE_SA for '172.16.50.10', triggering delete for old IKE_SAMar 26
20:26:33 10[CFG] delete for duplicate IKE_SA '172.16.50.10' timed out,
keeping new IKE_SAMar 26 20:26:33 10[CFG] lease 172.16.80.1 by 'jordan'
went offline*
Mar 26 20:28:41 16[KNL] creating delete job for ESP CHILD_SA with SPI
cbd0760a and reqid {1}
Mar 26 20:28:41 16[IKE] closing expired CHILD_SA mypolicy{1} with SPIs
cbd0760a_i 98ef05d1_o and TS 172.16.40.0/24 === 172.16.80.1/32
Mar 26 20:28:41 16[IKE] sending DELETE for ESP CHILD_SA with SPI cbd0760a
Mar 26 20:28:41 16[ENC] generating INFORMATIONAL_V1 request 448306121 [
HASH D ]
Mar 26 20:28:41 16[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 26 20:30:47 10[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:30:47 10[ENC] parsed QUICK_MODE request 2177791340 [ HASH SA No
ID ID ]
Mar 26 20:30:47 10[IKE] no matching CHILD_SA config found
Mar 26 20:30:47 10[ENC] generating INFORMATIONAL_V1 request 2229198666 [
HASH N(INVAL_ID) ]
Mar 26 20:30:47 10[NET] sending packet: from 172.16.50.2[500] to
172.16.50.10[500] (76 bytes)
Mar 26 20:30:52 01[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:30:52 01[IKE] received retransmit of request with ID 2177791340,
but no response to retransmit
Mar 26 20:30:57 03[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:30:57 03[IKE] received retransmit of request with ID 2177791340,
but no response to retransmit
Mar 26 20:31:02 09[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:31:02 09[IKE] received retransmit of request with ID 2177791340,
but no response to retransmit
Mar 26 20:31:07 15[NET] received packet: from 172.16.50.10[500] to
172.16.50.2[500] (156 bytes)
Mar 26 20:31:07 15[ENC] parsed QUICK_MODE request 1370031388 [ HASH SA No
ID ID ]
Mar 26 20:31:07 15[IKE] no matching CHILD_SA config found

....


On Wed, Mar 26, 2014 at 1:53 AM, yordanos beyene <yordanosb at gmail.com>wrote:

> 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 300s.
> 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/20140327/519e24fb/attachment-0001.html>


More information about the Users mailing list