[strongSwan] disappearing interface (ppp, tun) terminates connection
Axel Zöllich
a.zoellich at kirsch.zoellich.de
Sun Jul 12 20:58:43 CEST 2015
Hi,
strongswan 5.2.1 (5.2.1-6+deb8u1~bpo70+1 from debian backports for wheezy)
conn %default
rekeymargin=3m
keyingtries=%forever
authby=secret
reauth=no
dpdaction=restart
conn astelle
ikelifetime=86400
keylife=86400
esp=3des-sha1-modp1024
ike=3des-sha1-modp1024
keyexchange=ikev2
left=111.111.111.111
leftid=111.111.111.111
leftfirewall=no
lefthostaccess=no
leftsubnet=192.168.222.0/24,172.18.1.1/32,10.8.0.0/24
rightid=222.222.222.222
right=222.222.222.222
rightsubnet=192.168.223.0/24,192.168.3.0/24
auto=route
Due to a defective adsl modem I got several ppp reconnections.
And noticed further on that my ipsec tunel doesn't survive this transitions.
Timeout rekeying is working like expected:
working rekeying:
Jul 10 02:33:02 08[KNL] creating rekey job for ESP CHILD_SA with SPI ca926d62 and reqid {1}
Jul 10 02:33:02 08[IKE] <astelle|6> establishing CHILD_SA astelle{1}
Jul 10 02:33:02 08[ENC] <astelle|6> generating CREATE_CHILD_SA request 0 [ N(REKEY_SA) SA No KE TSi TSr ]
Jul 10 02:33:02 08[NET] <astelle|6> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (484 bytes)
Jul 10 02:33:02 04[NET] <astelle|6> received packet: from 222.222.222.222[4500] to 111.111.111.111[4500] (372 bytes)
Jul 10 02:33:02 04[ENC] <astelle|6> parsed CREATE_CHILD_SA response 0 [ SA No KE TSi TSr ]
Jul 10 02:33:02 04[IKE] <astelle|6> CHILD_SA astelle{1} established with SPIs c0dfff62_i cfef2b16_o and TS 192.168.222.0/24 172.18.1.1/32 10.8.0.0/24 === 192.168.223.0/24 192.168.3.0/24
Jul 10 02:33:02 04[IKE] <astelle|6> closing CHILD_SA astelle{1} with SPIs ca926d62_i (720983136 bytes) cca2e89e_o (2305346659 bytes) and TS 192.168.222.0/24 172.18.1.1/32 10.8.0.0/24 === 192.168.223.0/24 192.168.3.0/24
Jul 10 02:33:02 04[IKE] <astelle|6> sending DELETE for ESP CHILD_SA with SPI ca926d62
Jul 10 02:33:02 04[ENC] <astelle|6> generating INFORMATIONAL request 1 [ D ]
Jul 10 02:33:02 04[NET] <astelle|6> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (68 bytes)
Jul 10 02:33:02 11[NET] <astelle|6> received packet: from 222.222.222.222[4500] to 111.111.111.111[4500] (68 bytes)
Jul 10 02:33:02 11[ENC] <astelle|6> parsed INFORMATIONAL response 1 [ D ]
Jul 10 02:33:02 11[IKE] <astelle|6> received DELETE for ESP CHILD_SA with SPI cca2e89e
Jul 10 02:33:02 11[IKE] <astelle|6> CHILD_SA closed
Jul 10 02:33:13 07[IKE] <astelle|6> initiating IKE_SA astelle[7] to 222.222.222.222
Jul 10 02:33:13 07[ENC] <astelle|6> generating CREATE_CHILD_SA request 2 [ SA No KE ]
Jul 10 02:33:13 07[NET] <astelle|6> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (932 bytes)
Jul 10 02:33:13 13[NET] <astelle|6> received packet: from 222.222.222.222[4500] to 111.111.111.111[4500] (284 bytes)
Jul 10 02:33:13 13[ENC] <astelle|6> parsed CREATE_CHILD_SA response 2 [ SA No KE ]
Jul 10 02:33:13 13[IKE] <astelle|6> scheduling rekeying in 86045s
Jul 10 02:33:13 13[IKE] <astelle|6> maximum IKE_SA lifetime 86225s
Jul 10 02:33:13 13[IKE] <astelle|6> IKE_SA astelle[7] rekeyed between 111.111.111.111[111.111.111.111]...222.222.222.222[222.222.222.222]
Jul 10 02:33:13 13[IKE] <astelle|6> deleting IKE_SA astelle[6] between 111.111.111.111[111.111.111.111]...222.222.222.222[222.222.222.222]
Jul 10 02:33:13 13[IKE] <astelle|6> sending DELETE for IKE_SA astelle[6]
Jul 10 02:33:13 13[ENC] <astelle|6> generating INFORMATIONAL request 3 [ D ]
Jul 10 02:33:13 13[NET] <astelle|6> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (68 bytes)
Jul 10 02:33:13 09[NET] <astelle|6> received packet: from 222.222.222.222[4500] to 111.111.111.111[4500] (60 bytes)
Jul 10 02:33:13 09[ENC] <astelle|6> parsed INFORMATIONAL response 3 [ ]
Jul 10 02:33:13 09[IKE] <astelle|6> IKE_SA deleted
but with the ppp Interface (with fixed IP) fading away there is something going wrong.
vanishing ppp interface:
Jul 6 17:14:46 14[KNL] interface ppp0 deactivated
Jul 6 17:14:46 12[KNL] 333.333.333.333 disappeared from ppp0
Jul 6 17:14:46 03[IKE] <astelle|2> sending address list update using MOBIKE
Jul 6 17:14:46 03[ENC] <astelle|2> generating INFORMATIONAL request 6 [ N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) ]
Jul 6 17:14:46 03[NET] <astelle|2> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (156 bytes)
Jul 6 17:14:50 09[IKE] <astelle|2> retransmit 1 of request with message ID 6
Jul 6 17:14:50 09[NET] <astelle|2> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (156 bytes)
Jul 6 17:14:52 06[KNL] interface ppp0 deleted
Jul 6 17:14:52 10[IKE] <astelle|2> sending address list update using MOBIKE
Jul 6 17:14:58 05[IKE] <astelle|2> retransmit 2 of request with message ID 6
Jul 6 17:14:58 05[NET] <astelle|2> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (156 bytes)
Jul 6 17:15:11 14[IKE] <astelle|2> retransmit 3 of request with message ID 6
Jul 6 17:15:11 14[NET] <astelle|2> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (156 bytes)
Jul 6 17:15:34 14[IKE] <astelle|2> retransmit 4 of request with message ID 6
Jul 6 17:15:34 14[NET] <astelle|2> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (156 bytes)
Jul 6 17:16:16 14[IKE] <astelle|2> retransmit 5 of request with message ID 6
Jul 6 17:16:16 14[NET] <astelle|2> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (156 bytes)
Jul 6 17:16:47 11[KNL] 333.333.333.333 appeared on ppp0
Jul 6 17:16:47 08[KNL] 333.333.333.333 disappeared from ppp0
Jul 6 17:16:47 09[KNL] 333.333.333.333 appeared on ppp0
Jul 6 17:16:47 07[KNL] interface ppp0 activated
Jul 6 17:16:47 10[IKE] <astelle|2> sending address list update using MOBIKE
Jul 6 17:17:31 05[IKE] <astelle|2> giving up after 5 retransmits
Jul 6 17:17:31 05[IKE] <astelle|2> restarting CHILD_SA astelle
Jul 6 17:17:31 05[IKE] <astelle|2> initiating IKE_SA astelle[3] to 222.222.222.222
Jul 6 17:17:31 05[ENC] <astelle|2> generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
Jul 6 17:17:31 05[NET] <astelle|2> sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (936 bytes)
Jul 6 17:17:31 08[KNL] creating acquire job for policy 192.168.222.50/32[tcp/2483] === 192.168.223.71/32[tcp/11112] with reqid {1}
Jul 6 17:17:31 09[NET] <astelle|3> received packet: from 222.222.222.222[500] to 111.111.111.111[500] (308 bytes)
Jul 6 17:17:31 09[ENC] <astelle|3> parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(MULT_AUTH) ]
Jul 6 17:17:31 09[IKE] <astelle|3> authentication of '111.111.111.111' (myself) with pre-shared key
Jul 6 17:17:31 09[IKE] <astelle|3> establishing CHILD_SA astelle{1}
Jul 6 17:17:31 09[ENC] <astelle|3> generating 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(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
Jul 6 17:17:31 09[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 6 17:17:35 06[IKE] <astelle|3> retransmit 1 of request with message ID 1
Jul 6 17:17:35 06[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 6 17:17:43 11[IKE] <astelle|3> retransmit 2 of request with message ID 1
Jul 6 17:17:43 11[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 6 17:17:50 09[KNL] interface ppp0 deactivated
Jul 6 17:17:50 04[KNL] 333.333.333.333 disappeared from ppp0
Jul 6 17:17:56 05[IKE] <astelle|3> retransmit 3 of request with message ID 1
Jul 6 17:17:56 05[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 6 17:17:56 08[KNL] interface ppp0 deleted
Discovering this misbehaveior I tried terminating the openvpn connections on this router and got an equal reaction:
disappearing tun interface (openvpn):
Jul 7 02:40:23 14[KNL] 10.8.0.177 disappeared from tun_bot
Jul 7 02:40:23 04[KNL] interface tun_bot deactivated
Jul 7 02:40:23 06[KNL] interface tun_bot deleted
Jul 7 02:40:23 11[KNL] 10.8.0.137 disappeared from tun_hoe
Jul 7 02:40:23 08[KNL] interface tun_hoe deactivated
Jul 7 02:40:23 09[KNL] interface tun_hoe deleted
Jul 7 02:40:23 10[KNL] 10.8.0.169 disappeared from tun_jun
Jul 7 02:40:23 07[KNL] interface tun_jun deactivated
Jul 7 02:40:23 06[KNL] interface tun_jun deleted
Jul 7 02:40:23 11[KNL] 10.8.0.153 disappeared from tun_kel
Jul 7 02:40:23 08[KNL] interface tun_kel deactivated
Jul 7 02:40:23 09[KNL] interface tun_kel deleted
Jul 7 02:40:23 05[KNL] 10.8.0.113 disappeared from tun_pik
Jul 7 02:40:23 06[KNL] interface tun_pik deactivated
Jul 7 02:40:23 13[KNL] interface tun_pik deleted
Jul 7 02:40:23 12[KNL] 10.8.0.145 disappeared from tun_vol
Jul 7 02:40:23 14[KNL] interface tun_vol deactivated
Jul 7 02:40:23 10[KNL] interface tun_vol deleted
Jul 7 02:40:24 04[IKE] <astelle|3> sending address list update using MOBIKE
Jul 7 02:40:24 04[ENC] <astelle|3> generating INFORMATIONAL request 8 [ N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) ]
Jul 7 02:40:24 04[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (140 bytes)
Jul 7 02:40:25 03[KNL] 10.8.0.145 appeared on tun_vol
Jul 7 02:40:25 08[KNL] interface tun_vol activated
Jul 7 02:40:25 09[KNL] 10.8.0.145 disappeared from tun_vol
Jul 7 02:40:25 10[KNL] 10.8.0.145 appeared on tun_vol
Jul 7 02:40:25 13[IKE] <astelle|3> sending address list update using MOBIKE
Jul 7 02:40:28 09[IKE] <astelle|3> retransmit 1 of request with message ID 8
Jul 7 02:40:28 09[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (140 bytes)
Jul 7 02:40:35 13[IKE] <astelle|3> retransmit 2 of request with message ID 8
Jul 7 02:40:35 13[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (140 bytes)
Jul 7 02:40:48 09[IKE] <astelle|3> retransmit 3 of request with message ID 8
Jul 7 02:40:48 09[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (140 bytes)
Jul 7 02:41:11 13[IKE] <astelle|3> retransmit 4 of request with message ID 8
Jul 7 02:41:11 13[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (140 bytes)
Jul 7 02:41:53 08[IKE] <astelle|3> retransmit 5 of request with message ID 8
Jul 7 02:41:53 08[NET] <astelle|3> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (140 bytes)
Jul 7 02:43:09 11[IKE] <astelle|3> giving up after 5 retransmits
Jul 7 02:43:09 11[IKE] <astelle|3> restarting CHILD_SA astelle
Jul 7 02:43:09 11[IKE] <astelle|3> initiating IKE_SA astelle[4] to 222.222.222.222
Jul 7 02:43:09 11[ENC] <astelle|3> generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
Jul 7 02:43:09 11[NET] <astelle|3> sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (936 bytes)
Jul 7 02:43:09 13[NET] <astelle|4> received packet: from 222.222.222.222[500] to 111.111.111.111[500] (308 bytes)
Jul 7 02:43:09 13[ENC] <astelle|4> parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(MULT_AUTH) ]
Jul 7 02:43:09 13[IKE] <astelle|4> authentication of '111.111.111.111' (myself) with pre-shared key
Jul 7 02:43:09 13[IKE] <astelle|4> establishing CHILD_SA astelle{1}
Jul 7 02:43:09 13[ENC] <astelle|4> generating 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(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
Jul 7 02:43:09 13[NET] <astelle|4> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 7 02:43:09 12[KNL] creating acquire job for policy 192.168.222.241/32[icmp/3(1)] === 192.168.223.161/32[icmp/3(1)] with reqid {1}
Jul 7 02:43:13 05[IKE] <astelle|4> retransmit 1 of request with message ID 1
Jul 7 02:43:13 05[NET] <astelle|4> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 7 02:43:20 08[IKE] <astelle|4> retransmit 2 of request with message ID 1
Jul 7 02:43:20 08[NET] <astelle|4> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 7 02:43:33 14[IKE] <astelle|4> retransmit 3 of request with message ID 1
Jul 7 02:43:33 14[NET] <astelle|4> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 7 02:43:56 14[IKE] <astelle|4> retransmit 4 of request with message ID 1
Jul 7 02:43:56 14[NET] <astelle|4> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 7 02:44:38 05[IKE] <astelle|4> retransmit 5 of request with message ID 1
Jul 7 02:44:38 05[NET] <astelle|4> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 7 02:45:54 11[KNL] creating delete job for ESP CHILD_SA with SPI ce52ac9d and reqid {1}
Jul 7 02:45:54 11[JOB] CHILD_SA with reqid 1 not found for delete
Jul 7 02:45:54 12[IKE] <astelle|4> giving up after 5 retransmits
Jul 7 02:45:54 12[IKE] <astelle|4> peer not responding, trying again (2/0)
Jul 7 02:45:54 12[IKE] <astelle|4> initiating IKE_SA astelle[4] to 222.222.222.222
Jul 7 02:45:54 12[ENC] <astelle|4> generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
Jul 7 02:45:54 12[NET] <astelle|4> sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (936 bytes)
Jul 7 02:45:54 08[NET] <astelle|4> received packet: from 222.222.222.222[500] to 111.111.111.111[500] (308 bytes)
Jul 7 02:45:54 08[ENC] <astelle|4> parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(MULT_AUTH) ]
Jul 7 02:45:54 08[IKE] <astelle|4> authentication of '111.111.111.111' (myself) with pre-shared key
Jul 7 02:45:54 08[IKE] <astelle|4> establishing CHILD_SA astelle
Jul 7 02:45:54 08[ENC] <astelle|4> generating 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(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
Jul 7 02:45:54 08[NET] <astelle|4> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (476 bytes)
Jul 7 02:45:54 09[NET] <astelle|4> received packet: from 222.222.222.222[4500] to 111.111.111.111[4500] (324 bytes)
Jul 7 02:45:54 09[ENC] <astelle|4> parsed IKE_AUTH response 1 [ 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(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) ]
Jul 7 02:45:54 09[IKE] <astelle|4> authentication of '222.222.222.222' with pre-shared key successful
Jul 7 02:45:54 09[IKE] <astelle|4> IKE_SA astelle[4] established between 111.111.111.111[111.111.111.111]...222.222.222.222[222.222.222.222]
Jul 7 02:45:54 09[IKE] <astelle|4> scheduling rekeying in 86207s
Jul 7 02:45:54 09[IKE] <astelle|4> maximum IKE_SA lifetime 86387s
Jul 7 02:45:54 09[IKE] <astelle|4> CHILD_SA astelle{1} established with SPIs c8481ca9_i c7c8e51c_o and TS 192.168.222.0/24 172.18.1.1/32 10.8.0.0/24 === 192.168.223.0/24 192.168.3.0/24
Jul 7 02:45:54 09[IKE] <astelle|4> peer supports MOBIKE
Jul 7 02:45:54 09[IKE] <astelle|4> establishing CHILD_SA astelle
Jul 7 02:45:54 09[ENC] <astelle|4> generating CREATE_CHILD_SA request 2 [ SA No KE TSi TSr ]
Jul 7 02:45:54 09[NET] <astelle|4> sending packet: from 111.111.111.111[4500] to 222.222.222.222[4500] (508 bytes)
Jul 7 02:45:54 14[NET] <astelle|4> received packet: from 222.222.222.222[4500] to 111.111.111.111[4500] (68 bytes)
Jul 7 02:45:54 14[ENC] <astelle|4> parsed CREATE_CHILD_SA response 2 [ N(TS_UNACCEPT) ]
Jul 7 02:45:54 14[IKE] <astelle|4> received TS_UNACCEPTABLE notify, no CHILD_SA built
Jul 7 02:45:54 14[IKE] <astelle|4> failed to establish CHILD_SA, keeping IKE_SA
More information about the Users
mailing list