[strongSwan] Tunnel going down after 40+ hours

Fri Oct 11 23:40:06 CEST 2019

Hello Makarand,

1) The other peer does not respond to any requests for rekeying so naturally any expired tunnels don't magically persist.
2) The other peer doesn't respond to IKE messages so it's either dead or the network made it unreachable ... or your firewall rules don't allow the necessary messages to pass through (PEBKAC)
3) Please provide the configuration. And your cipher suites are suboptimal.

Kind regards

Noel

Am 11.10.19 um 21:39 schrieb Makarand Pradhan:
> Hello everyone,
> 
> We are running Strongswan 5.8 on Linux:
> Linux t1024rdb 4.1.35-rt41 #1 SMP PREEMPT Wed Sep 4 14:39:22 EDT 2019 ppc64 GNU/Linux
> 
> The tunnel is set up and works great for nearly 41 hours and then it is destroyed. We have experienced the same failure 2 consecutive times. So we increased the log level and dumped NET, ENC, IKE, CFG and KNL log levels.
> 
> We notice that when we fail we get an XFRM_MSG_EXPIRE. After that we do not receive a response from the other side and then we give up after 5 attempts. In previous XFRM_MSG_EXPIRE instances we notice that replies were received from the other side.
> 
> The IP connectivity between both the machines is up. Also the next time we "ipsec start" the tunnels are set up correctly and start working again.
> 
> We were wondering if someone can comment/speculate on possible reasons for the failure? 
> 
> Any way we can instruct charon to retry after giving up?
> 
> Your thoughts/suggestions would be highly appreciated.
> 
> Logs below:
> 
> 
> ct  6 05:33:59 t1024rdb charon: 16[NET] received packet: from 80.0.0.1[500] to 80.0.0.2[500] (392 bytes)
> Oct  6 05:33:59 t1024rdb charon: 16[ENC] parsed IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(REDIR_SUP) ]
> Oct  6 05:33:59 t1024rdb charon: 16[IKE] 80.0.0.1 is initiating an IKE_SA
> Oct  6 05:33:59 t1024rdb charon: 16[CFG] selected proposal: IKE:AES_CBC_128/HMAC_SHA2_256_128/PRF_AES128_XCBC/CURVE_25519
> Oct  6 05:33:59 t1024rdb charon: 16[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(CHDLESS_SUP) N(MULT_AUTH) ]
> Oct  6 05:33:59 t1024rdb charon: 16[NET] sending packet: from 80.0.0.2[500] to 80.0.0.1[500] (248 bytes)
> Oct  6 05:34:00 t1024rdb charon: 09[NET] received packet: from 80.0.0.1[4500] to 80.0.0.2[4500] (368 bytes)
> Oct  6 05:34:00 t1024rdb charon: 09[ENC] parsed IKE_AUTH request 1 [ IDi N(INIT_CONTACT) IDr AUTH SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(MULT_AUTH) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]
> Oct  6 05:34:00 t1024rdb charon: 09[CFG] looking for peer configs matching 80.0.0.2[80.0.0.2]...80.0.0.1[80.0.0.1]
> Oct  6 05:34:00 t1024rdb charon: 09[CFG] selected peer config 'pi_to_pi'
> Oct  6 05:34:00 t1024rdb charon: 09[IKE] authentication of '80.0.0.1' with pre-shared key successful
> Oct  6 05:34:00 t1024rdb charon: 09[IKE] peer supports MOBIKE
> Oct  6 05:34:00 t1024rdb charon: 09[IKE] authentication of '80.0.0.2' (myself) with pre-shared key
> Oct  6 05:34:00 t1024rdb charon: 09[IKE] IKE_SA pi_to_pi[15] established between 80.0.0.2[80.0.0.2]...80.0.0.1[80.0.0.1]
> Oct  6 05:34:00 t1024rdb charon: 09[IKE] scheduling reauthentication in 9851s
> Oct  6 05:34:00 t1024rdb charon: 09[IKE] maximum IKE_SA lifetime 10391s
> Oct  6 05:34:00 t1024rdb charon: 09[CFG] selected proposal: ESP:AES_CBC_128/HMAC_SHA2_256_128/NO_EXT_SEQ
> Oct  6 05:34:00 t1024rdb charon: 09[IKE] CHILD_SA pi_to_pi{56} established with SPIs cea7040d_i c0677e95_o and TS 192.168.2.0/24 192.168.55.0/24 === 192.168.1.0/24
> Oct  6 05:34:00 t1024rdb charon: 09[ENC] generating IKE_AUTH response 1 [ IDr AUTH SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) ]
> 
> 
> ....
> 
> 
> Oct  7 22:55:35 t1024rdb charon: 14[KNL] received a XFRM_MSG_EXPIRE
> Oct  7 22:55:35 t1024rdb charon: 14[KNL] creating rekey job for CHILD_SA ESP/0xc540db84/80.0.0.2
> Oct  7 22:55:35 t1024rdb charon: 14[IKE] queueing CHILD_REKEY task
> Oct  7 22:55:35 t1024rdb charon: 14[IKE] activating new tasks
> Oct  7 22:55:35 t1024rdb charon: 14[IKE]   activating CHILD_REKEY task
> Oct  7 22:55:35 t1024rdb charon: 14[IKE] establishing CHILD_SA pi_to_pi{119} reqid 28
> Oct  7 22:55:35 t1024rdb charon: 14[KNL] got SPI c9169901
> Oct  7 22:55:35 t1024rdb charon: 14[CHD] CHILD_SA pi_to_pi{118} state change: INSTALLED => REKEYING
> Oct  7 22:55:35 t1024rdb charon: 14[ENC] generating CREATE_CHILD_SA request 2 [ N(REKEY_SA) SA No TSi TSr ]
> Oct  7 22:55:35 t1024rdb charon: 14[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500] (288 bytes)
> Oct  7 22:55:35 t1024rdb charon: 03[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500]
> Oct  7 22:55:39 t1024rdb charon: 04[IKE] retransmit 1 of request with message ID 2
> Oct  7 22:55:39 t1024rdb charon: 04[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500] (288 bytes)
> Oct  7 22:55:39 t1024rdb charon: 03[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500]
> Oct  7 22:55:46 t1024rdb charon: 09[IKE] retransmit 2 of request with message ID 2
> Oct  7 22:55:46 t1024rdb charon: 09[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500] (288 bytes)
> Oct  7 22:55:46 t1024rdb charon: 03[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500]
> Oct  7 22:55:59 t1024rdb charon: 07[IKE] retransmit 3 of request with message ID 2
> Oct  7 22:55:59 t1024rdb charon: 07[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500] (288 bytes)
> Oct  7 22:55:59 t1024rdb charon: 03[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500]
> Oct  7 22:56:22 t1024rdb charon: 08[IKE] retransmit 4 of request with message ID 2
> Oct  7 22:56:22 t1024rdb charon: 08[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500] (288 bytes)
> Oct  7 22:56:22 t1024rdb charon: 03[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500]
> Oct  7 22:57:04 t1024rdb charon: 11[IKE] retransmit 5 of request with message ID 2
> Oct  7 22:57:04 t1024rdb charon: 11[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500] (288 bytes)
> Oct  7 22:57:04 t1024rdb charon: 03[NET] sending packet: from 80.0.0.2[4500] to 80.0.0.1[4500]
> Oct  7 22:57:35 t1024rdb charon: 16[KNL] received a XFRM_MSG_EXPIRE
> Oct  7 22:57:35 t1024rdb charon: 16[KNL] creating rekey job for CHILD_SA ESP/0xce9c4468/80.0.0.1
> Oct  7 22:57:35 t1024rdb charon: 16[IKE] queueing CHILD_REKEY task
> Oct  7 22:57:35 t1024rdb charon: 16[IKE] delaying task initiation, CREATE_CHILD_SA exchange in progress
> Oct  7 22:58:20 t1024rdb charon: 10[KNL] received a XFRM_MSG_EXPIRE
> Oct  7 22:58:20 t1024rdb charon: 10[KNL] creating delete job for CHILD_SA ESP/0xc9169901/80.0.0.2
> Oct  7 22:58:20 t1024rdb charon: 10[JOB] CHILD_SA ESP/0xc9169901/80.0.0.2 not found for delete
> Oct  7 22:58:20 t1024rdb charon: 13[IKE] giving up after 5 retransmits
> Oct  7 22:58:20 t1024rdb charon: 13[IKE] IKE_SA pi_to_pi[30] state change: ESTABLISHED => DESTROYING
> Oct  7 22:58:20 t1024rdb charon: 13[CHD] CHILD_SA pi_to_pi{119} state change: CREATED => DESTROYING
> Oct  7 22:58:20 t1024rdb charon: 13[KNL] deleting SAD entry with SPI c9169901
> Oct  7 22:58:20 t1024rdb charon: 13[CHD] CHILD_SA pi_to_pi{118} state change: REKEYING => DESTROYING
> Oct  7 22:58:20 t1024rdb charon: 13[KNL] deleting policy 192.168.2.0/24 === 192.168.1.0/24 out
> Oct  7 22:58:20 t1024rdb charon: 13[KNL] getting iface index for fm1-mac1.0555
> Oct  7 22:58:20 t1024rdb charon: 13[KNL] deleting policy 192.168.1.0/24 === 192.168.2.0/24 in
> Oct  7 22:58:20 t1024rdb charon: 13[KNL] deleting policy 192.168.1.0/24 === 192.168.2.0/24 fwd
> Oct  7 22:58:20 t1024rdb charon: 13[KNL] deleting policy 192.168.55.0/24 === 192.168.1.0/24 out
> 
> 
> Makarand Pradhan
> Senior Software Engineer.
> iS5 Communications Inc.
> #1-1815 Meyerside Drive
> Mississauga, Ontario
> L5T 1G3
> Main Line: +1-844-520-0588 Ext. 129
> Direct Line: +1-289-724-2296
> Cell: +1-226-501-5666
> Fax:+1-289-401-5206
> Email: makarandpradhan at is5com.com
> Website: www.iS5Com.com
> 
>  
> Confidentiality Notice: 
> This message is intended only for the named recipients. This message may contain information that is confidential and/or exempt from disclosure under applicable law. Any dissemination or copying of this message by anyone other than a named recipient is strictly prohibited. If you are not a named recipient or an employee or agent responsible for delivering this message to a named recipient, please notify us immediately, and permanently destroy this message and any copies you may have. Warning: Email may not be secure unless properly encrypted.
> 

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: OpenPGP digital signature
URL: <http://lists.strongswan.org/pipermail/users/attachments/20191011/530f0d97/attachment-0001.sig>