Bug 11688 - IPsec N2N connections flapping after upgrade to Core 119
Summary: IPsec N2N connections flapping after upgrade to Core 119
Status: CLOSED FIXED
Alias: None
Product: IPFire
Classification: Unclassified
Component: --- (show other bugs)
Version: 2
Hardware: unspecified Unspecified
: Will affect most users Major Usability
Assignee: Michael Tremer
QA Contact:
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-03-25 17:01 UTC by Peter Müller
Modified: 2018-05-01 07:44 UTC (History)
5 users (show)

See Also:


Attachments
redacted ipsec logs (145.53 KB, text/plain)
2018-04-10 07:15 UTC, Oliver Fuhrer
Details
ipsec.conf (14.90 KB, text/plain)
2018-04-17 21:09 UTC, Oliver Fuhrer
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Peter Müller 2018-03-25 17:01:48 UTC
Since upgrade to Core Update 119, my machines (x86_64) are reacting a massive amount of log entries regarded to strongswan every ~ 10 seconds. They look like this:

Mar 25 16:54:11 [Firewall 1] charon: 11[IKE] deleting IKE_SA XXXX1GREEN[4341] between 88.130.xxx.xxx[[REDACTED]]...87.173.xxx.xxx[[REDACTED]] 
Mar 25 16:54:11 [Firewall 1] charon: 11[IKE] deleting IKE_SA XXXX1GREEN[4341] between 88.130.xxx.xxx[[REDACTED]]...87.173.xxx.xxx[[REDACTED]] 
Mar 25 16:54:11 [Firewall 1] charon: 11[IKE] sending DELETE for IKE_SA XXXX1GREEN[4341] 
Mar 25 16:54:11 [Firewall 1] charon: 11[ENC] generating INFORMATIONAL request 0 [ D ] 
Mar 25 16:54:11 [Firewall 1] charon: 11[NET] sending packet: from 88.130.xxx.xxx[4500] to 87.173.xxx.xxx[4500] (65 bytes) 
Mar 25 16:54:11 [Firewall 2] charon: 14[NET] received packet: from 88.130.xxx.xxx[4500] to 87.173.xxx.xxx[4500] (65 bytes) 
Mar 25 16:54:11 [Firewall 2] charon: 14[ENC] parsed INFORMATIONAL request 0 [ D ] 
Mar 25 16:54:11 [Firewall 2] charon: 14[IKE] received DELETE for IKE_SA XXXX2GREEN[4341] 
Mar 25 16:54:11 [Firewall 2] charon: 14[IKE] deleting IKE_SA XXXX2GREEN[4341] between 87.173.xxx.xxx[[REDACTED]]...88.130.xxx.xxx[[REDACTED]] 
Mar 25 16:54:11 [Firewall 2] charon: 14[IKE] deleting IKE_SA XXXX2GREEN[4341] between 87.173.xxx.xxx[[REDACTED]]...88.130.xxx.xxx[[REDACTED]] 
Mar 25 16:54:11 [Firewall 2] charon: 14[IKE] restarting CHILD_SA XXXX2GREEN 
Mar 25 16:54:11 [Firewall 2] charon: 14[IKE] initiating IKE_SA XXXX2GREEN[4343] to 88.130.xxx.xxx 
Mar 25 16:54:11 [Firewall 2] charon: 14[IKE] initiating IKE_SA XXXX2GREEN[4343] to 88.130.xxx.xxx 
Mar 25 16:54:11 [Firewall 2] charon: 14[ENC] generating 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) ] 
Mar 25 16:54:11 [Firewall 2] charon: 14[NET] sending packet: from 87.173.xxx.xxx[500] to 88.130.xxx.xxx[500] (304 bytes) 
Mar 25 16:54:11 [Firewall 2] charon: 14[IKE] IKE_SA deleted 
Mar 25 16:54:11 [Firewall 1] charon: 13[NET] received packet: from 87.173.xxx.xxx[500] to 88.130.xxx.xxx[500] (304 bytes) 
Mar 25 16:54:11 [Firewall 1] charon: 13[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) ] 
Mar 25 16:54:11 [Firewall 2] charon: 14[IKE] restarting CHILD_SA XXXX2ORANGE 
Mar 25 16:54:11 [Firewall 1] charon: 13[IKE] 87.173.xxx.xxx is initiating an IKE_SA 
Mar 25 16:54:11 [Firewall 1] charon: 13[IKE] 87.173.xxx.xxx is initiating an IKE_SA 
Mar 25 16:54:11 [Firewall 1] charon: 13[IKE] sending cert request for "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:11 [Firewall 1] charon: 13[IKE] sending cert request for "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:11 [Firewall 1] charon: 13[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(FRAG_SUP) N(HASH_ALG) N(MULT_AUTH) ] 
Mar 25 16:54:11 [Firewall 1] charon: 13[NET] sending packet: from 88.130.xxx.xxx[500] to 87.173.xxx.xxx[500] (277 bytes) 
Mar 25 16:54:11 [Firewall 2] charon: 14[IKE] IKE_SA deleted 
Mar 25 16:54:11 [Firewall 2] charon: 16[NET] received packet: from 88.130.xxx.xxx[500] to 87.173.xxx.xxx[500] (277 bytes) 
Mar 25 16:54:11 [Firewall 2] vpn: client- [REDACTED] [Firewall 1 GREEN net] == 88.130.xxx.xxx -- 87.173.xxx.xxx == [Firewall 2 GREEN net]
Mar 25 16:54:12 [Firewall 2] vpn: tunnel- 88.130.xxx.xxx -- 87.173.xxx.xxx
Mar 25 16:54:12 [Firewall 2] vpn: snat- ppp0-87.173.xxx.xxx : [Firewall 1 GREEN net] - [Firewall 2]
Mar 25 16:54:12 [Firewall 2] vpn: client- [REDACTED] [Firewall 1 ORANGE net] == 88.130.xxx.xxx -- 87.173.xxx.xxx == [Firewall 2 ORANGE net]
Mar 25 16:54:12 [Firewall 2] vpn: tunnel- 88.130.xxx.xxx -- 87.173.xxx.xxx
Mar 25 16:54:12 [Firewall 2] vpn: snat- ppp0-87.173.xxx.xxx : [Firewall 1 ORANGE net] - 10.51.163.1
Mar 25 16:54:12 [Firewall 2] vpn: client- [REDACTED] [Firewall 1 ORANGE net] == 88.130.xxx.xxx -- 87.173.xxx.xxx == [Firewall 2 GREEN net]
Mar 25 16:54:12 [Firewall 2] vpn: tunnel- 88.130.xxx.xxx -- 87.173.xxx.xxx
Mar 25 16:54:12 [Firewall 2] vpn: snat- ppp0-87.173.xxx.xxx : [Firewall 1 ORANGE net] - [Firewall 2]
Mar 25 16:54:12 [Firewall 2] charon: 14[ENC] generating INFORMATIONAL response 0 [ ] 
Mar 25 16:54:12 [Firewall 2] charon: 16[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(FRAG_SUP) N(HASH_ALG) N(MULT_AUTH) ] 
Mar 25 16:54:12 [Firewall 2] charon: 16[IKE] received cert request for "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:12 [Firewall 2] charon: 16[IKE] received cert request for "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:12 [Firewall 2] charon: 16[IKE] sending cert request for "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:12 [Firewall 1] charon: 08[NET] received packet: from 87.173.xxx.xxx[4500] to 88.130.xxx.xxx[4500] (57 bytes) 
Mar 25 16:54:12 [Firewall 1] charon: 08[ENC] parsed INFORMATIONAL response 0 [ ] 
Mar 25 16:54:12 [Firewall 1] charon: 08[IKE] IKE_SA deleted 
Mar 25 16:54:12 [Firewall 2] charon: 14[NET] sending packet: from 87.173.xxx.xxx[4500] to 88.130.xxx.xxx[4500] (57 bytes) 
Mar 25 16:54:12 [Firewall 2] charon: 16[IKE] sending cert request for "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:12 [Firewall 2] charon: 16[IKE] authentication of '[REDACTED]' (myself) with RSA_EMSA_PKCS1_SHA2_256 successful 
Mar 25 16:54:12 [Firewall 2] charon: 16[IKE] sending end entity cert "C=DE, O=[REDACTED], CN=[REDACTED]" 
Mar 25 16:54:12 [Firewall 2] charon: 16[ENC] generating IKE_AUTH request 1 [ EF(2/2) ] 
Mar 25 16:54:12 [Firewall 2] charon: 16[IKE] establishing CHILD_SA XXXX2GREEN{8685} reqid 1 
Mar 25 16:54:12 [Firewall 2] charon: 16[IKE] establishing CHILD_SA XXXX2GREEN{8685} reqid 1 
Mar 25 16:54:12 [Firewall 2] charon: 16[ENC] generating IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(MULT_AUTH) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ] 
Mar 25 16:54:12 [Firewall 2] charon: 16[ENC] splitting IKE message with length of 2000 bytes into 2 fragments 
Mar 25 16:54:12 [Firewall 2] charon: 16[ENC] generating IKE_AUTH request 1 [ EF(1/2) ] 
Mar 25 16:54:12 [Firewall 2] charon: 16[NET] sending packet: from 87.173.xxx.xxx[4500] to 88.130.xxx.xxx[4500] (817 bytes) 
Mar 25 16:54:12 [Firewall 2] charon: 16[NET] sending packet: from 87.173.xxx.xxx[4500] to 88.130.xxx.xxx[4500] (1248 bytes) 
Mar 25 16:54:12 [Firewall 1] charon: 08[IKE] IKE_SA deleted 
Mar 25 16:54:12 [Firewall 1] charon: 05[NET] received packet: from 87.173.xxx.xxx[4500] to 88.130.xxx.xxx[4500] (1248 bytes) 
Mar 25 16:54:12 [Firewall 1] vpn: client- [REDACTED] [Firewall 2 GREEN net] == 87.173.xxx.xxx -- 88.130.xxx.xxx == [Firewall 1 GREEN net]
Mar 25 16:54:12 [Firewall 1] vpn: tunnel- 87.173.xxx.xxx -- 88.130.xxx.xxx
Mar 25 16:54:12 [Firewall 1] vpn: snat- ppp0-88.130.xxx.xxx : [Firewall 2 GREEN net] - [Firewall 1]
Mar 25 16:54:12 [Firewall 1] vpn: client- [REDACTED] [Firewall 2 ORANGE net] == 87.173.xxx.xxx -- 88.130.xxx.xxx == [Firewall 1 ORANGE net]
Mar 25 16:54:12 [Firewall 1] vpn: tunnel- 87.173.xxx.xxx -- 88.130.xxx.xxx
Mar 25 16:54:12 [Firewall 1] vpn: snat- ppp0-88.130.xxx.xxx : [Firewall 2 ORANGE net] - [Firewall 1 ORANGE interface]
Mar 25 16:54:12 [Firewall 1] vpn: client- [REDACTED] [Firewall 2 GREEN net] == 87.173.xxx.xxx -- 88.130.xxx.xxx == [Firewall 1 ORANGE net]
Mar 25 16:54:12 [Firewall 1] vpn: tunnel- 87.173.xxx.xxx -- 88.130.xxx.xxx
Mar 25 16:54:12 [Firewall 1] vpn: snat- ppp0-88.130.xxx.xxx : [Firewall 2 GREEN net] - [Firewall 1 ORANGE interface]
Mar 25 16:54:12 [Firewall 1] charon: 05[ENC] parsed IKE_AUTH request 1 [ EF(1/2) ] 
Mar 25 16:54:12 [Firewall 1] charon: 05[ENC] received fragment #1 of 2, waiting for complete IKE message 
Mar 25 16:54:12 [Firewall 1] charon: 14[NET] received packet: from 87.173.xxx.xxx[4500] to 88.130.xxx.xxx[4500] (817 bytes) 
Mar 25 16:54:12 [Firewall 1] charon: 14[ENC] parsed IKE_AUTH request 1 [ EF(2/2) ] 
Mar 25 16:54:12 [Firewall 1] charon: 14[ENC] received fragment #2 of 2, reassembling fragmented IKE message 
Mar 25 16:54:12 [Firewall 1] charon: 14[ENC] parsed IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(MULT_AUTH) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ] 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] received cert request for "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] received cert request for "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] received end entity cert "C=DE, O=[REDACTED], CN=[REDACTED]" 
Mar 25 16:54:12 [Firewall 1] charon: 14[CFG] looking for peer configs matching 88.130.xxx.xxx[[REDACTED]]...87.173.xxx.xxx[[REDACTED]] 
Mar 25 16:54:12 [Firewall 1] charon: 14[CFG] selected peer config 'XXXX1GREEN' 
Mar 25 16:54:12 [Firewall 1] charon: 14[CFG]   using trusted ca certificate "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:12 [Firewall 1] charon: 14[CFG] checking certificate status of "C=DE, O=[REDACTED], CN=[REDACTED]" 
Mar 25 16:54:12 [Firewall 1] charon: 14[CFG] certificate status is not available 
Mar 25 16:54:12 [Firewall 1] charon: 14[CFG]   reached self-signed root ca with a path length of 0 
Mar 25 16:54:12 [Firewall 1] charon: 14[CFG]   using trusted certificate "C=DE, O=[REDACTED], CN=[REDACTED]" 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] authentication of '[REDACTED]' with RSA_EMSA_PKCS1_SHA2_256 successful 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] peer supports MOBIKE 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] authentication of '[REDACTED]' (myself) with RSA_EMSA_PKCS1_SHA2_256 successful 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] IKE_SA XXXX1GREEN[4343] established between 88.130.xxx.xxx[[REDACTED]]...87.173.xxx.xxx[[REDACTED]] 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] IKE_SA XXXX1GREEN[4343] established between 88.130.xxx.xxx[[REDACTED]]...87.173.xxx.xxx[[REDACTED]] 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] scheduling reauthentication in 10087s 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] maximum IKE_SA lifetime 10627s 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] sending end entity cert "C=DE, O=[REDACTED], CN=[REDACTED]" 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] CHILD_SA XXXX1GREEN{8685} established with SPIs c88b0b22_i c802cc80_o and TS [Firewall 1 GREEN net] === [Firewall 2 GREEN net] 
Mar 25 16:54:12 [Firewall 1] charon: 14[IKE] CHILD_SA XXXX1GREEN{8685} established with SPIs c88b0b22_i c802cc80_o and TS [Firewall 1 GREEN net] === [Firewall 2 GREEN net] 
Mar 25 16:54:12 [Firewall 1] vpn: client+ [REDACTED] [Firewall 2 GREEN net] == 87.173.xxx.xxx -- 88.130.xxx.xxx == [Firewall 1 GREEN net]
Mar 25 16:54:12 [Firewall 1] vpn: tunnel+ 87.173.xxx.xxx -- 88.130.xxx.xxx
Mar 25 16:54:12 [Firewall 1] vpn: snat+ ppp0-88.130.xxx.xxx : [Firewall 2 GREEN net] - [Firewall 1]
Mar 25 16:54:12 [Firewall 1] charon: 14[ENC] generating IKE_AUTH response 1 [ IDr CERT AUTH SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) ] 
Mar 25 16:54:12 [Firewall 1] charon: 14[ENC] splitting IKE message with length of 1846 bytes into 2 fragments 
Mar 25 16:54:12 [Firewall 1] charon: 14[ENC] generating IKE_AUTH response 1 [ EF(1/2) ] 
Mar 25 16:54:12 [Firewall 1] charon: 14[ENC] generating IKE_AUTH response 1 [ EF(2/2) ] 
Mar 25 16:54:12 [Firewall 1] charon: 14[NET] sending packet: from 88.130.xxx.xxx[4500] to 87.173.xxx.xxx[4500] (1248 bytes) 
Mar 25 16:54:12 [Firewall 1] charon: 14[NET] sending packet: from 88.130.xxx.xxx[4500] to 87.173.xxx.xxx[4500] (663 bytes) 
Mar 25 16:54:13 [Firewall 2] charon: 15[NET] received packet: from 88.130.xxx.xxx[4500] to 87.173.xxx.xxx[4500] (1248 bytes) 
Mar 25 16:54:13 [Firewall 2] charon: 15[ENC] parsed IKE_AUTH response 1 [ EF(1/2) ] 
Mar 25 16:54:13 [Firewall 2] charon: 15[ENC] received fragment #1 of 2, waiting for complete IKE message 
Mar 25 16:54:13 [Firewall 2] charon: 10[NET] received packet: from 88.130.xxx.xxx[4500] to 87.173.xxx.xxx[4500] (663 bytes) 
Mar 25 16:54:13 [Firewall 2] charon: 10[ENC] parsed IKE_AUTH response 1 [ EF(2/2) ] 
Mar 25 16:54:13 [Firewall 2] charon: 10[ENC] received fragment #2 of 2, reassembling fragmented IKE message 
Mar 25 16:54:13 [Firewall 2] charon: 10[ENC] parsed IKE_AUTH response 1 [ IDr CERT AUTH SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) ] 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] received end entity cert "C=DE, O=[REDACTED], CN=[REDACTED]" 
Mar 25 16:54:13 [Firewall 2] charon: 10[CFG]   using trusted ca certificate "C=DE, O=[REDACTED], CN=[REDACTED] CA" 
Mar 25 16:54:13 [Firewall 2] charon: 10[CFG] checking certificate status of "C=DE, O=[REDACTED], CN=[REDACTED]" 
Mar 25 16:54:13 [Firewall 2] charon: 10[CFG] certificate status is not available 
Mar 25 16:54:13 [Firewall 2] charon: 10[CFG]   reached self-signed root ca with a path length of 0 
Mar 25 16:54:13 [Firewall 2] charon: 10[CFG]   using trusted certificate "C=DE, O=[REDACTED], CN=[REDACTED]" 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] authentication of '[REDACTED]' with RSA_EMSA_PKCS1_SHA2_256 successful 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] IKE_SA XXXX2GREEN[4343] established between 87.173.xxx.xxx[[REDACTED]]...88.130.xxx.xxx[[REDACTED]] 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] IKE_SA XXXX2GREEN[4343] established between 87.173.xxx.xxx[[REDACTED]]...88.130.xxx.xxx[[REDACTED]] 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] scheduling reauthentication in 10253s 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] maximum IKE_SA lifetime 10793s 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] CHILD_SA XXXX2GREEN{8685} established with SPIs c802cc80_i c88b0b22_o and TS [Firewall 2 GREEN net] === [Firewall 1 GREEN net] 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] CHILD_SA XXXX2GREEN{8685} established with SPIs c802cc80_i c88b0b22_o and TS [Firewall 2 GREEN net] === [Firewall 1 GREEN net] 
Mar 25 16:54:13 [Firewall 2] vpn: client+ [REDACTED] [Firewall 1 GREEN net] == 88.130.xxx.xxx -- 87.173.xxx.xxx == [Firewall 2 GREEN net]
Mar 25 16:54:13 [Firewall 2] vpn: tunnel+ 88.130.xxx.xxx -- 87.173.xxx.xxx
Mar 25 16:54:13 [Firewall 2] vpn: snat+ ppp0-87.173.xxx.xxx : [Firewall 1 GREEN net] - [Firewall 2]
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] received AUTH_LIFETIME of 10086s, scheduling reauthentication in 9546s 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] peer supports MOBIKE 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] establishing CHILD_SA XXXX2ORANGE{8686} reqid 2 
Mar 25 16:54:13 [Firewall 2] charon: 10[IKE] establishing CHILD_SA XXXX2ORANGE{8686} reqid 2 
Mar 25 16:54:13 [Firewall 2] charon: 10[ENC] generating CREATE_CHILD_SA request 2 [ SA No KE TSi TSr ] 
Mar 25 16:54:13 [Firewall 2] charon: 10[NET] sending packet: from 87.173.xxx.xxx[4500] to 88.130.xxx.xxx[4500] (321 bytes) 
Mar 25 16:54:13 [Firewall 1] charon: 03[NET] received packet: from 87.173.xxx.xxx[4500] to 88.130.xxx.xxx[4500] (321 bytes) 
Mar 25 16:54:13 [Firewall 1] charon: 03[ENC] parsed CREATE_CHILD_SA request 2 [ SA No KE TSi TSr ] 
Mar 25 16:54:13 [Firewall 1] charon: 03[IKE] CHILD_SA XXXX1ORANGE{8686} established with SPIs c24f6a67_i c2d8782a_o and TS [Firewall 1 ORANGE net] === [Firewall 2 ORANGE net] [Firewall 2 GREEN net] 
Mar 25 16:54:13 [Firewall 1] charon: 03[IKE] CHILD_SA XXXX1ORANGE{8686} established with SPIs c24f6a67_i c2d8782a_o and TS [Firewall 1 ORANGE net] === [Firewall 2 ORANGE net] [Firewall 2 GREEN net] 
Mar 25 16:54:13 [Firewall 1] vpn: client+ [REDACTED] [Firewall 2 ORANGE net] == 87.173.xxx.xxx -- 88.130.xxx.xxx == [Firewall 1 ORANGE net]
Mar 25 16:54:13 [Firewall 1] vpn: tunnel+ 87.173.xxx.xxx -- 88.130.xxx.xxx
Mar 25 16:54:13 [Firewall 1] vpn: snat+ ppp0-88.130.xxx.xxx : [Firewall 2 ORANGE net] - [Firewall 1 ORANGE interface]
Mar 25 16:54:13 [Firewall 1] vpn: client+ [REDACTED] [Firewall 2 GREEN net] == 87.173.xxx.xxx -- 88.130.xxx.xxx == [Firewall 1 ORANGE net]
Mar 25 16:54:13 [Firewall 1] vpn: tunnel+ 87.173.xxx.xxx -- 88.130.xxx.xxx
Mar 25 16:54:13 [Firewall 1] vpn: snat+ ppp0-88.130.xxx.xxx : [Firewall 2 GREEN net] - [Firewall 1 ORANGE interface]
Mar 25 16:54:13 [Firewall 1] charon: 03[ENC] generating CREATE_CHILD_SA response 2 [ SA No KE TSi TSr ] 
Mar 25 16:54:13 [Firewall 1] charon: 03[NET] sending packet: from 88.130.xxx.xxx[4500] to 87.173.xxx.xxx[4500] (241 bytes) 
Mar 25 16:54:13 [Firewall 2] charon: 05[NET] received packet: from 88.130.xxx.xxx[4500] to 87.173.xxx.xxx[4500] (241 bytes) 
Mar 25 16:54:13 [Firewall 2] charon: 05[ENC] parsed CREATE_CHILD_SA response 2 [ SA No KE TSi TSr ] 
Mar 25 16:54:13 [Firewall 2] charon: 05[IKE] CHILD_SA XXXX2ORANGE{8686} established with SPIs c2d8782a_i c24f6a67_o and TS [Firewall 2 ORANGE net] [Firewall 2 GREEN net] === [Firewall 1 ORANGE net] 
Mar 25 16:54:13 [Firewall 2] charon: 05[IKE] CHILD_SA XXXX2ORANGE{8686} established with SPIs c2d8782a_i c24f6a67_o and TS [Firewall 2 ORANGE net] [Firewall 2 GREEN net] === [Firewall 1 ORANGE net] 
Mar 25 16:54:13 [Firewall 2] vpn: client+ [REDACTED] [Firewall 1 ORANGE net] == 88.130.xxx.xxx -- 87.173.xxx.xxx == [Firewall 2 ORANGE net]
Mar 25 16:54:13 [Firewall 2] vpn: tunnel+ 88.130.xxx.xxx -- 87.173.xxx.xxx
Mar 25 16:54:13 [Firewall 2] vpn: snat+ ppp0-87.173.xxx.xxx : [Firewall 1 ORANGE net] - 10.51.163.1
Mar 25 16:54:13 [Firewall 2] vpn: client+ [REDACTED] [Firewall 1 ORANGE net] == 88.130.xxx.xxx -- 87.173.xxx.xxx == [Firewall 2 GREEN net]
Mar 25 16:54:13 [Firewall 2] vpn: tunnel+ 88.130.xxx.xxx -- 87.173.xxx.xxx
Mar 25 16:54:14 [Firewall 2] vpn: snat+ ppp0-87.173.xxx.xxx : [Firewall 1 ORANGE net] - [Firewall 2]

This seems like a VPN tunnel could not be established properly, however, the WebUI shows all connections as CONNECTED.

Any help is appreciated... :-)
Comment 1 Peter Müller 2018-03-25 17:19:56 UTC
This problem can be reproduced with just one GREEN-to-GREEN VPN.
The tunnel seems to be teared down and rebuilt every ~ 10 seconds.
Comment 2 Michael Tremer 2018-03-26 15:20:43 UTC
Are you using Curve25519? If so, could you use any of the other algrotihms for testing and then restart strongSwan on both sides?
Comment 3 Peter Müller 2018-03-26 20:56:24 UTC
(In reply to Michael Tremer from comment #2)
> Are you using Curve25519? If so, could you use any of the other algrotihms
> for testing and then restart strongSwan on both sides?
I am (it is the only algorithm used in that group, don't know if that makes any difference). I'll test and report.
Comment 4 Michael Tremer 2018-03-27 15:40:23 UTC
In my test scenario it wasn't the only one, but it was the one that was
negotiated to be used with the other peer. So there was no failover to a second
one.
Comment 5 Oliver Fuhrer 2018-04-09 17:02:30 UTC
Hi
I'm facing the same Issue between two x86_64 boxes and an arm Installation which is causing quite some additional load as some of the tunnels are re-initialized every 10 seconds.
Current configuration for all tunnels:
Encryption: 256bit AES-CBC (IKE+ESP)
Integrity:  SHA2 256bit    (IKE+ESP)
Gruptype:   ECP-386 (NIST) (IKE+ESP)
IKE Lifetime: 3Hrs, ESP 1Hr.
Use only proposed Settings for IKE+ESP and PFS enabled.

Let me know if you need any additional information.

Regards
Oliver
Comment 6 Peter Müller 2018-04-09 19:30:43 UTC
Looks like not only Curve25519 is causing the problem, then.

Have not tested it yet (things are currently quite busy), but will do at the weekend.
Comment 7 Michael Tremer 2018-04-10 00:23:02 UTC
Since you are using a different curve this could be a diffent issue.

Could you please send logs? Potentially redacted?
Comment 8 Oliver Fuhrer 2018-04-10 07:15:07 UTC
Created attachment 569 [details]
redacted ipsec logs

Please find ipsec related messages attached.
Comment 9 Michael Tremer 2018-04-11 20:32:48 UTC
The server is being asked to close the connection, and then it starts them
again.

That is kind of works as designed.

Do you have an idea why the other end is closing it?
Comment 10 Oliver Fuhrer 2018-04-11 22:05:31 UTC
I don't really have a clue why this is happening.

What I see, is that, I have multiple connections active at the same time on each site. Running 'ipsecctrl I' in a loop shows reconnects every 10 seconds. This is also currently causing around 80-100 MB of log entries on the site with 2 tunnels.


[root@firewall ~]# ipsecctrl I
Security Associations (2 up, 0 connecting):
remotebackup[9144]: ESTABLISHED 8 seconds ago, 83.219.xxx.xxx[sitea.domain.tld]...85.5.xxx.xxx[siteb.domain.tld]
remotebackup{22064}:  INSTALLED, TUNNEL, reqid 1, ESP in UDP SPIs: c99a0959_i cd1e46c5_o
remotebackup{22064}:   10.219.220.1/32 === 192.168.10.0/24 192.168.55.0/24 192.168.92.0/24
remotebackup{22065}:  INSTALLED, TUNNEL, reqid 1, ESP in UDP SPIs: c61903e6_i caa3aee5_o
remotebackup{22065}:   10.219.220.1/32 === 192.168.10.0/24 192.168.55.0/24 192.168.92.0/24
remotebackup{22066}:  INSTALLED, TUNNEL, reqid 1, ESP in UDP SPIs: ce1bfee6_i c8a4af15_o
remotebackup{22066}:   10.219.220.1/32 === 192.168.10.0/24 192.168.55.0/24 192.168.92.0/24
remotebackup[9143]: ESTABLISHED 23 seconds ago, 83.219.xxx.xxx[sitea.domain.tld]...85.5.xxx.xxx[siteb.domain.tld]
remotebackup{22061}:  INSTALLED, TUNNEL, reqid 1, ESP in UDP SPIs: cb9984cd_i c935d6bb_o
remotebackup{22061}:   10.219.220.1/32 === 192.168.10.0/24 192.168.55.0/24 192.168.92.0/24
remotebackup{22062}:  INSTALLED, TUNNEL, reqid 1, ESP in UDP SPIs: c38fbc97_i c054d563_o
remotebackup{22062}:   10.219.220.1/32 === 192.168.10.0/24 192.168.55.0/24 192.168.92.0/24
remotebackup{22063}:  INSTALLED, TUNNEL, reqid 1, ESP in UDP SPIs: c77669ff_i cc6c7b82_o
remotebackup{22063}:   10.219.220.1/32 === 192.168.10.0/24 192.168.55.0/24 192.168.92.0/24

Here's the config for this particular tunnel
ipfire 1
cat /var/ipfire/vpn/config
1,on,remotebackup,siteb.domain.tld,net,cert,,off,@sitea.domain.tld,10.219.220.1/32,@siteb.domain.tld,siteb.domain.tld,192.168.10.0/24|192.168.55.0/24|192.168.92.0/24,off,,,off,3,1,aes256,sha2_256,e384,aes256,sha2_256,e384,on,,,restart,on,ikev2,120,30,off,start,0

ipfire 2
cat /var/ipfire/vpn/config
1,on,remotebackup,sitea.domain.tld,net,cert,,off,@siteb.domain.tld,192.168.10.0/24|192.168.55.0/24|192.168.92.0/24,@sitea.domain.tld,sitea.domain.tld,10.219.220.1/32,off,,,off,3,1,aes256,sha2_256,e384,aes256,sha2_256,e384,on,,,restart,on,ikev2,120,30,off,start,0

One site is located behind a NAT Router, but I don't think this should be an Issue.

There also seems to be someone else facing a similar Issue in the Forum
https://forum.ipfire.org/viewtopic.php?f=16&t=20286

I can try to set up another tunnel between the two sites which are not natted and see what happens then or set up multiple tunnels, 1 for each subnet and see what happens.
Comment 11 Michael Tremer 2018-04-11 22:41:38 UTC
I have multiple tunnels running with similar settings and previously have seen
that sometimes strongSwan logs something funny and then restarts the tunnel when
Curve25519 was involved.

This looks different. The other side is an IPFire system, too? Do the settings
match exactly?
Comment 12 Oliver Fuhrer 2018-04-11 23:13:19 UTC
Yes, all involved endpoints are ipfire systems (site 2 has tunnels to ipfire 1 and ipfire 3). Tunnel Settings were identical, however I recreated all tunnels in the meantime using PSK instead of certificates and using ipfire's default values except for deselecting curve25519.

New config for all 3 involved systems:
site 3:
[root@firewall ~]# cat /var/ipfire/vpn/config
1,on,radmin,,net,psk,redacted=,off,@sitec.domain.tld,172.28.7.0/24|172.28.9.0/24|172.28.10.0/23,@siteb.domain.tld,siteb.domain.tld,192.168.10.0/24|192.168.55.0/24|192.168.92.0/24,off,,,off,3,1,aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gcm64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,4096|3072|2048,aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gcm64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,4096|3072|2048,on,,,restart,on,ikev2,120,30,off,start,900

site 2:
[root@firewall ~]# cat /var/ipfire/vpn/config
1,on,remotebackup,,net,psk,redacted=,off,@siteb.domain.tld,192.168.10.0/24|192.168.55.0/24|192.168.92.0/24,@sitea.domain.tld,sitea.domain.tld,10.219.220.1/32,off,,,off,3,1,aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gcm64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,4096|3072|2048,aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gcm64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,4096|3072|2048,on,,,restart,on,ikev2,120,30,off,start,900
2,on,radmin,,net,psk,redacted=,off,@siteb.domain.tld,192.168.10.0/24|192.168.55.0/24|192.168.92.0/24,@sitec.domain.tld,sitec.domain.tld,172.28.7.0/24|172.28.9.0/24|172.28.10.0/23,off,,,off,3,1,aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gcm64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,4096|3072|2048,aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gcm64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,4096|3072|2048,on,,,restart,on,ikev2,120,30,off,start,900

site 1:
[root@firewall ~]# cat /var/ipfire/vpn/config
1,on,remotebackup,,net,psk,redacted=,off,@sitea.domain.tld,10.219.220.1/24,@siteb.domain.tld,siteb.domain.tld,192.168.10.0/24|192.168.55.0/24|192.168.92.0/24,off,,,off,3,1,aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gcm64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,4096|3072|2048,aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gcm64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,4096|3072|2048,on,,,restart,on,ikev2,120,30,off,start,900

I'll keep an eye on the logs and see what happens until tomorrow morning.
Comment 13 Peter Müller 2018-04-13 17:03:28 UTC
This might be related to #11559 since it seems to occur only in case multiple IPsec connections are announcing the same source and/or destination networks.
Comment 14 Michael Tremer 2018-04-17 14:52:52 UTC
(In reply to Oliver Fuhrer from comment #12)
> Yes, all involved endpoints are ipfire systems (site 2 has tunnels to ipfire
> 1 and ipfire 3). Tunnel Settings were identical, however I recreated all
> tunnels in the meantime using PSK instead of certificates and using ipfire's
> default values except for deselecting curve25519.
> 
> New config for all 3 involved systems:
> site 3:
> [root@firewall ~]# cat /var/ipfire/vpn/config
> 1,on,radmin,,net,psk,redacted=,off,@sitec.domain.tld,172.28.7.0/24|172.28.9.
> 0/24|172.28.10.0/23,@siteb.domain.tld,siteb.domain.tld,192.168.10.0/24|192.
> 168.55.0/24|192.168.92.0/24,off,,,off,3,1,
> aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gc
> m64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,
> 4096|3072|2048,
> aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gc
> m64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,
> 4096|3072|2048,on,,,restart,on,ikev2,120,30,off,start,900
> 
> site 2:
> [root@firewall ~]# cat /var/ipfire/vpn/config
> 1,on,remotebackup,,net,psk,redacted=,off,@siteb.domain.tld,192.168.10.0/
> 24|192.168.55.0/24|192.168.92.0/24,@sitea.domain.tld,sitea.domain.tld,10.219.
> 220.1/32,off,,,off,3,1,
> aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gc
> m64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,
> 4096|3072|2048,
> aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gc
> m64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,
> 4096|3072|2048,on,,,restart,on,ikev2,120,30,off,start,900
> 2,on,radmin,,net,psk,redacted=,off,@siteb.domain.tld,192.168.10.0/24|192.168.
> 55.0/24|192.168.92.0/24,@sitec.domain.tld,sitec.domain.tld,172.28.7.0/24|172.
> 28.9.0/24|172.28.10.0/23,off,,,off,3,1,
> aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gc
> m64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,
> 4096|3072|2048,
> aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gc
> m64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,
> 4096|3072|2048,on,,,restart,on,ikev2,120,30,off,start,900
> 
> site 1:
> [root@firewall ~]# cat /var/ipfire/vpn/config
> 1,on,remotebackup,,net,psk,redacted=,off,@sitea.domain.tld,10.219.220.1/24,
> @siteb.domain.tld,siteb.domain.tld,192.168.10.0/24|192.168.55.0/24|192.168.
> 92.0/24,off,,,off,3,1,
> aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gc
> m64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,
> 4096|3072|2048,
> aes256gcm128|aes256gcm96|aes256gcm64|aes256|aes192gcm128|aes192gcm96|aes192gc
> m64|aes192|aes128gcm128|aes128gcm96|aes128gcm64|aes128,sha2_512|sha2_256,
> 4096|3072|2048,on,,,restart,on,ikev2,120,30,off,start,900
> 
> I'll keep an eye on the logs and see what happens until tomorrow morning.

Could you rather post /etc/ipsec.conf? That is easier to read.
Comment 15 Oliver Fuhrer 2018-04-17 21:09:39 UTC
Created attachment 572 [details]
ipsec.conf

Consolidated ipsec.conf Files of all 3 IPFire Systems.
Comment 16 Peter Müller 2018-04-18 06:31:56 UTC
Disabling Curve25519 did not solve the problem here - after a while, the connection becomes unstable and switches up and down every ~ 10 seconds. Not very surprisingly, quality of VoIP calls over VPN becomes poor.

I guess this problem is neither related to multiple connection announcing the same routes partial (as suggested somewhere) nor to Curve25519 - at least not on my systems. :-)

In case anybody needs further information here, I'm happy to provide them.
Comment 17 Michael Tremer 2018-04-19 15:24:52 UTC
@Oliver: Did you install an experimental Core Update?

@Peter: Can you post your ipsec.conf as well?
Comment 18 Oliver Fuhrer 2018-04-19 15:39:41 UTC
Yes, site 2 ist currently running on core 120, the other 2 are on core 119. However the upgrade was done after the ipsec problems occured. If necessary I can wipe it and reinstall with core 119.

Regards
Oliver
Comment 19 Michael Tremer 2018-04-19 15:41:59 UTC
Not necessary. But if you could download the latest version of
vpnmain.cgi from https://git.ipfire.org/?p=ipfire-2.x.git;a=blob;f=html
/cgi-bin/vpnmain.cgi;h=a52b4d64d9b48d84babe8ec8d1220e4b3d4ddd01;hb=HEAD
 and copy it to /srv/web/ipfire/cgi-bin/vpnmain.cgi, then edit the
connection and hit save so that configuration files are rewritten, that
would help.

Potentially run "ipsec restart" on the console to restart the entire
IPsec stack.
Comment 20 Oliver Fuhrer 2018-04-19 16:03:38 UTC
Hi Michael

I just downloaded the latest vpnmain.cgi to the Core 120 System and diff did not show any changes.

Regards
Oliver
Comment 21 Michael Tremer 2018-04-19 16:33:02 UTC
Hmm, it should. This commit should have been reverted:

https://git.ipfire.org/?p=ipfire-2.x.git;a=commitdiff;h=a261cb06c6cdd3ba14ad0163
c8c9e714ae94fc5b

That did not land in master nor next, which isn't good.

Could you manually remove that line?
Comment 22 Oliver Fuhrer 2018-04-19 17:29:34 UTC
Ok, I removed the following Lines from the core 120 System, edited and saved all tunnels and bounced ipsec via init Script. So far no change. I will restart ipsec on the remote sites as well in a couple of hours.

                       # Restart the connection immediately when it has gone down
                       # unexpectedly
                       if ($start_action eq 'start') {
                               print CONF "\tcloseaction=restart\n";
                       }

Oliver
Comment 23 Michael Tremer 2018-04-19 17:32:07 UTC
Yes, please do this on both sides and make sure that strongswan has actually
reloaded the configuration.
Comment 24 Michael Tremer 2018-04-19 17:32:32 UTC
Also changing to on-demand mode should stop the flapping instantly.
Comment 25 Oliver Fuhrer 2018-04-20 21:32:40 UTC
Hi Michael

Thanks a lot. So far, the Logs are quiet again and the tunnels seem to be much more stable. Removing closeaction=restart from ipsec.conf and changing the tunnes to on demand did the trick.

Regards
Oliver
Comment 26 Michael Tremer 2018-04-20 22:20:23 UTC
Great. Thanks for the feedback. That shouldn't have been there in the
first place.
Comment 27 Michael Tremer 2018-04-23 12:33:50 UTC
Is everything still okay? Peter, could you confirm the same problem?
Comment 28 Peter Müller 2018-04-23 16:21:02 UTC
Flapping VPN tunnels also appear using curves other than Curve25519 here. I am also able to exclude multiple tunnels announcing the same routes partial as a reason for this, as I suspected initially.

@Michael: I did not try to apply your patch, yet. Working on it and get back...
Comment 29 Oliver Fuhrer 2018-04-23 22:28:03 UTC
Om my side tunnels seem to be stable for some time now using On Demand connect. I also cannot see multiple active tunnels in ipsecctrl's output, which is fine for me.
Is there anything else I should test in my setups?

Regards
Oliver
Comment 30 Michael Tremer 2018-04-24 11:58:15 UTC
Thanks for the feedback.

Multiple ESP sessions may happen. There should not be too many.

If tunnels are stable for you now, I think we have found the culprit and can
consider this as being fixed.
Comment 31 Peter Müller 2018-04-24 16:50:48 UTC
(In reply to Michael Tremer from comment #30)
> Thanks for the feedback.
> 
> Multiple ESP sessions may happen. There should not be too many.
Yes, my constructions was more like a crutch, to work around #11559.
> 
> If tunnels are stable for you now, I think we have found the culprit and can
> consider this as being fixed.
Are they running stable without "on demand" mode as well?

Also changing the bug title so it actual reflects what the problem was.
Comment 32 Michael Tremer 2018-04-24 16:51:50 UTC
I ported the patch to the core120 branch since we need to build again and I
consider this a bug that is severe enough to be a higher priority.
Comment 33 Peter Müller 2018-04-30 19:27:18 UTC
Core Update 120 has been released. Will close this as soon as tests show problem gone. Good work!
Comment 34 Peter Müller 2018-05-01 07:44:18 UTC
Confirm problem is solved after upgrading to Core Update 120 and reboot.