Hi Tobias, > Very strange. Due to the NAT this packet should actually be sent from > port 4500 to port 4500. The complete log of moon (and sun) would help > to see whether there is something wrong with the NAT detection etc. > Here are excerpts of the two log files. I tried to get similar time slot. I also added some further 'bits' where the behaviour seems a bit strange. Hope it helps.
-- sun ipsec.log -- Mar 19 16:15:48 sun charon: 03[CFG] received stroke: initiate 'sun-moon' Mar 19 16:15:48 sun charon: 14[AUD] initiating IKE_SA sun-moon[1140] to moon Mar 19 16:15:48 sun charon: 14[AUD] initiating IKE_SA sun-moon[1140] to moon Mar 19 16:15:48 sun charon: 14[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ] Mar 19 16:15:48 sun charon: 14[NET] sending packet: from sun[500] to moon[500] Mar 19 16:15:48 sun charon: 17[NET] received packet: from moon[500] to sun[500] Mar 19 16:15:48 sun charon: 17[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N((16404)) ] Mar 19 16:15:48 sun charon: 17[IKE] remote host is behind NAT Mar 19 16:15:48 sun charon: 17[IKE] received cert request for "C=... Mar 19 16:15:48 sun charon: 17[IKE] sending cert request for "C=... Mar 19 16:15:48 sun charon: 17[IKE] authentication of 'sun' (myself) with RSA signature successful Mar 19 16:15:48 sun charon: 17[IKE] sending end entity cert "C=... Mar 19 16:15:48 sun charon: 17[AUD] establishing CHILD_SA sun-moon Mar 19 16:15:48 sun charon: 17[AUD] establishing CHILD_SA sun-moon Mar 19 16:15:48 sun charon: 17[ENC] generating IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH SA TSi TSr ] Mar 19 16:15:48 sun charon: 17[NET] sending packet: from sun[4500] to moon[4500] Mar 19 16:15:49 sun charon: 13[NET] received packet: from moon[4500] to sun[4500] Mar 19 16:15:49 sun charon: 13[ENC] parsed IKE_AUTH response 1 [ IDr CERT AUTH SA TSi TSr N(AUTH_LFT) ] Mar 19 16:15:49 sun charon: 13[IKE] received end entity cert "C=... Mar 19 16:15:49 sun charon: 13[CFG] using certificate "C=... Mar 19 16:15:49 sun charon: 13[CFG] using trusted ca certificate Mar 19 16:15:49 sun charon: 13[CFG] checking certificate status of Mar 19 16:15:49 sun charon: 13[CFG] certificate status is not available Mar 19 16:15:49 sun charon: 13[IKE] authentication of 'C=...' with RSA signature successful Mar 19 16:15:49 sun charon: 13[IKE] scheduling reauthentication in 3285s Mar 19 16:15:49 sun charon: 13[IKE] maximum IKE_SA lifetime 3465s Mar 19 16:15:49 sun charon: 13[AUD] IKE_SA sun-moon[1140] established between sun...moon Mar 19 16:15:49 sun charon: 13[AUD] IKE_SA sun-moon[1140] established between sun...moon Mar 19 16:15:49 sun charon: 13[KNL] no local address found in traffic selector 172.18.0.0/16 Mar 19 16:15:49 sun charon: 13[KNL] no local address found in traffic selector 172.30.0.0/24 Mar 19 16:15:49 sun charon: 13[AUD] CHILD_SA sun-moon{916} established with SPIs cf938ad2_i c152593b_o and TS 172.16.0.0/16 172.18.0.0/16 172.30.0.0/24 === 172.17.0.0/16 172.17.0.0/16 172.17.0.0/16 Mar 19 16:15:49 sun charon: 13[AUD] CHILD_SA sun-moon{916} established with SPIs cf938ad2_i c152593b_o and TS 172.16.0.0/16 172.18.0.0/16 172.30.0.0/24 === 172.17.0.0/16 172.17.0.0/16 172.17.0.0/16 Mar 19 16:15:49 sun charon: 13[IKE] received AUTH_LIFETIME of 3259s, scheduling reauthentication in 3079s Mar 19 16:16:01 sun charon: 09[ENC] header verification failed Mar 19 16:16:01 sun charon: 09[NET] received invalid IKE header from moon - ignored ... Mar 19 16:29:59 sun charon: 04[KNL] creating rekey job for ESP CHILD_SA with SPI cf938ad2 and reqid {916} Mar 19 16:29:59 sun charon: 03[AUD] establishing CHILD_SA sun-moon{916} Mar 19 16:29:59 sun charon: 03[AUD] establishing CHILD_SA sun-moon{916} Mar 19 16:29:59 sun charon: 03[ENC] generating CREATE_CHILD_SA request 2 [ N(REKEY_SA) SA No TSi TSr ] Mar 19 16:29:59 sun charon: 03[NET] sending packet: from sun[4500] to moon[4500] Mar 19 16:29:59 sun charon: 13[NET] received packet: from moon[4500] to sun[4500] Mar 19 16:29:59 sun charon: 13[ENC] parsed CREATE_CHILD_SA response 2 [ SA No TSi TSr ] Mar 19 16:29:59 sun charon: 13[KNL] no local address found in traffic selector 172.18.0.0/16 Mar 19 16:29:59 sun charon: 13[KNL] no local address found in traffic selector 172.30.0.0/24 Mar 19 16:29:59 sun charon: 13[AUD] CHILD_SA sun-moon{916} established with SPIs ced57a15_i ca5c514b_o and TS 172.16.0.0/16 172.18.0.0/16 172.30.0.0/24 === 172.17.0.0/16 172.17.0.0/16 172.17.0.0/16 Mar 19 16:29:59 sun charon: 13[AUD] CHILD_SA sun-moon{916} established with SPIs ced57a15_i ca5c514b_o and TS 172.16.0.0/16 172.18.0.0/16 172.30.0.0/24 === 172.17.0.0/16 172.17.0.0/16 172.17.0.0/16 Mar 19 16:29:59 sun charon: 13[AUD] closing CHILD_SA sun-moon{916} with SPIs cf938ad2_i c152593b_o and TS 172.16.0.0/16 172.18.0.0/16 172.30.0.0/24 === 172.17.0.0/16 172.17.0.0/16 172.17.0.0/16 Mar 19 16:29:59 sun charon: 13[AUD] closing CHILD_SA sun-moon{916} with SPIs cf938ad2_i c152593b_o and TS 172.16.0.0/16 172.18.0.0/16 172.30.0.0/24 === 172.17.0.0/16 172.17.0.0/16 172.17.0.0/16 Mar 19 16:29:59 sun charon: 13[IKE] sending DELETE for ESP CHILD_SA with SPI cf938ad2 Mar 19 16:29:59 sun charon: 13[ENC] generating INFORMATIONAL request 3 [ D ] Mar 19 16:29:59 sun charon: 13[NET] sending packet: from sun[4500] to moon[4500] Mar 19 16:29:59 sun charon: 15[NET] received packet: from moon[4500] to sun[4500] Mar 19 16:29:59 sun charon: 15[ENC] parsed INFORMATIONAL response 3 [ D ] Mar 19 16:29:59 sun charon: 15[IKE] received DELETE for ESP CHILD_SA with SPI c152593b Mar 19 16:29:59 sun charon: 15[AUD] CHILD_SA closed Mar 19 16:29:59 sun charon: 15[AUD] CHILD_SA closed -- moon ipsec.log -- Mar 19 16:12:07 moon charon: 14[NET] sending packet: from 192.168.2.17[4500] to sun[500] Mar 19 16:12:11 moon charon: 01[KNL] NAT mappings of ESP CHILD_SA with SPI cadd18c0 and reqid {817} changed, queuing update job Mar 19 16:13:16 charon: last message repeated 104 times Mar 19 16:13:21 moon charon: 01[KNL] NAT mappings of ESP CHILD_SA with SPI cadd18c0 and reqid {817} changed, queuing update job Mar 19 16:13:23 moon charon: 01[KNL] creating delete job for ESP CHILD_SA with SPI c6ca2843 and reqid {817} Mar 19 16:13:23 moon charon: 09[IKE] giving up after 5 retransmits Mar 19 16:13:23 moon vpn: - sun 172.16.0.0/16 == sun -- 192.168.2.17 == 172.17.0.0/16 Mar 19 16:13:23 moon vpn: - sun 172.18.0.0/16 == sun -- 192.168.2.17 == 172.17.0.0/16 Mar 19 16:13:23 moon vpn: - sun 172.30.0.0/24 == sun -- 192.168.2.17 == 172.17.0.0/16 Mar 19 16:13:23 moon charon: 01[KNL] NAT mappings of ESP CHILD_SA with SPI cadd18c0 and reqid {817} changed, queuing update job Mar 19 16:13:23 moon charon: 09[KNL] received netlink error: No such process (3) Mar 19 16:13:23 moon charon: 09[KNL] unable to delete SAD entry with SPI c6ca2843 Mar 19 16:13:23 moon charon: 10[JOB] CHILD_SA with reqid 817 not found for update Mar 19 16:13:23 moon charon: 01[KNL] NAT mappings of ESP CHILD_SA with SPI cadd18c0 and reqid {817} changed, queuing update job Mar 19 16:13:23 moon charon: 09[JOB] CHILD_SA with reqid 817 not found for update Mar 19 16:13:29 moon charon: 01[KNL] creating acquire job for policy 172.17.0.1/32[tcp] === 172.16.0.24/32[tcp/ldap] with reqid {817} Mar 19 16:13:29 moon charon: 12[CFG] trap not found, unable to acquire reqid 817 Mar 19 16:15:47 moon charon: 09[NET] received packet: from sun[500] to 192.168.2.17[500] Mar 19 16:15:47 moon charon: 09[ENC] parsed IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ] Mar 19 16:15:47 moon charon: 09[IKE] sun is initiating an IKE_SA Mar 19 16:15:47 moon charon: 09[IKE] sun is initiating an IKE_SA Mar 19 16:15:47 moon charon: 09[IKE] local host is behind NAT, sending keep alives Mar 19 16:15:47 moon charon: 09[IKE] sending cert request for "C=... Mar 19 16:15:47 moon charon: 09[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ] Mar 19 16:15:47 moon charon: 09[NET] sending packet: from 192.168.2.17[500] to sun[500] Mar 19 16:15:47 moon charon: 12[NET] received packet: from sun[4500] to 192.168.2.17[4500] Mar 19 16:15:47 moon charon: 12[ENC] parsed IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH SA TSi TSr ] Mar 19 16:15:47 moon charon: 12[IKE] received cert request for "C=... Mar 19 16:15:47 moon charon: 12[IKE] received end entity cert "C=... Mar 19 16:15:47 moon charon: 12[CFG] looking for peer configs matching 192.168.2.17[moon]...sun[sun] Mar 19 16:15:47 moon charon: 12[CFG] selected peer config 'moon-sun' Mar 19 16:15:47 moon charon: 12[CFG] using certificate "C=... Mar 19 16:15:47 moon charon: 12[CFG] using trusted ca certificate Mar 19 16:15:47 moon charon: 12[CFG] checking certificate status of Mar 19 16:15:47 moon charon: 12[CFG] certificate status is not available Mar 19 16:15:47 moon charon: 12[CFG] reached self-signed root ca with a path length of 0 Mar 19 16:15:47 moon charon: 12[IKE] authentication of 'sun' with RSA signature successful Mar 19 16:15:48 moon charon: 12[IKE] authentication of 'C=... , CN=moon' (myself) with RSA signature successful Mar 19 16:15:48 moon charon: 12[IKE] IKE_SA moon-sun[809] established between 192.168.2.17[CN=moon]...sun[sun] Mar 19 16:15:48 moon charon: 12[IKE] IKE_SA moon-sun[809] established between 192.168.2.17[ CN=moon]...sun[sun] Mar 19 16:15:48 moon charon: 12[IKE] scheduling reauthentication in 3259s Mar 19 16:15:48 moon charon: 12[IKE] maximum IKE_SA lifetime 3439s Mar 19 16:15:48 moon charon: 12[IKE] sending end entity cert "C=... Mar 19 16:15:48 moon charon: 12[IKE] CHILD_SA moon-sun{818} established with SPIs c152593b_i cf938ad2_o and TS 172.17.0.0/16 === 172.16.0.0/16 172.18.0.0/16 172.30.0.0/24 Mar 19 16:15:48 moon vpn: + sun 172.16.0.0/16 == sun -- 192.168.2.17 == 172.17.0.0/16 Mar 19 16:15:48 moon vpn: + sun 172.18.0.0/16 == sun -- 192.168.2.17 == 172.17.0.0/16 Mar 19 16:15:48 moon vpn: + sun 172.30.0.0/24 == sun -- 192.168.2.17 == 172.17.0.0/16 Mar 19 16:15:48 moon charon: 12[IKE] CHILD_SA moon-sun{818} established with SPIs c152593b_i cf938ad2_o and TS 172.17.0.0/16 === 172.16.0.0/16 172.18.0.0/16 172.30.0.0/24 Mar 19 16:15:48 moon charon: 12[ENC] generating IKE_AUTH response 1 [ IDr CERT AUTH SA TSi TSr N(AUTH_LFT) ] Mar 19 16:15:48 moon charon: 12[NET] sending packet: from 192.168.2.17[4500] to sun[4500] Mar 19 16:15:49 moon charon: 01[KNL] NAT mappings of ESP CHILD_SA with SPI c152593b and reqid {818} changed, queuing update job > > Mar 19 11:02:46 moon charon: 01[KNL] NAT mappings of ESP CHILD_SA > > with SPI c2aa0995 and reqid {804} changed, queuing update job > > This seems strange too as this should not really happen for the host > *behind* the NAT (unless the other end is natted too, of course) - and > only if the actual endpoints have changed. A possible reason could be > that sun sends ESP packets from port 4500 while moon has port 500 > configured (if the port used above is any indication). sun is connected via a router directly to the internet and holds a public IP. moon is connected to the internet via a NAT ADSL-Router/Modem Combination with port forwarding on UDP 500 and UDP 4500 to moon. What I also noticed in this setup, that if both sides only call auto=route in the configuration I can see the configuration with ipsec statusall, but no SA is installed on receiving traffic to the other network. Cheers, Kim > > > _______________________________________________ > Users mailing list > Users@lists.strongswan.org > https://lists.strongswan.org/mailman/listinfo/users > _______________________________________________ Users mailing list Users@lists.strongswan.org https://lists.strongswan.org/mailman/listinfo/users