PfSense 2.3.2 : L2TP - no matching CHILD_SA config found



  • Hello,
    I have little problem with L2TP setting :-/. Actual situation is :

    PublicIP -> port forwarde udp500,udp4500 -> pfsense WAN:500,4500
    pfsense wan : 172.17.0.20/24 + GW 172.17.0.101
    pfsense lan : 192.168.1.88/24
    pfsense IP pool for L2TP : 192.168.81.0/24

    IPSEC and L2TP settings see screenshots in attachment. I think settings is right.
    pfSense config file see attachment too. Password in attachment and in screenshots is for test, so no problem with posting on web.

    I try connect from Windows 10 and from Android 5.0.2 (Galaxy Tab 4)

    Full ipsec log see :

    
    Sep 5 12:58:50	charon: 15[JOB] <con1|3>DPD check timed out, enforcing DPD action
    Sep 5 12:58:40	charon: 13[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (92 bytes)
    Sep 5 12:58:40	charon: 13[ENC] <con1|3>generating INFORMATIONAL_V1 request 3862525073 [ HASH N(DPD) ]
    Sep 5 12:58:40	charon: 13[IKE] <con1|3>sending DPD request
    Sep 5 12:58:30	charon: 15[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (92 bytes)
    Sep 5 12:58:30	charon: 15[ENC] <con1|3>generating INFORMATIONAL_V1 request 3539655449 [ HASH N(DPD) ]
    Sep 5 12:58:30	charon: 15[IKE] <con1|3>sending DPD request
    Sep 5 12:58:20	charon: 13[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (92 bytes)
    Sep 5 12:58:20	charon: 13[ENC] <con1|3>generating INFORMATIONAL_V1 request 3711181188 [ HASH N(DPD) ]
    Sep 5 12:58:20	charon: 13[IKE] <con1|3>sending DPD request
    Sep 5 12:58:10	charon: 11[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (92 bytes)
    Sep 5 12:58:10	charon: 11[ENC] <con1|3>generating INFORMATIONAL_V1 request 587122208 [ HASH N(DPD) ]
    Sep 5 12:58:10	charon: 11[IKE] <con1|3>sending DPD request
    Sep 5 12:58:00	charon: 13[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (92 bytes)
    Sep 5 12:58:00	charon: 13[ENC] <con1|3>generating INFORMATIONAL_V1 request 3478984326 [ HASH N(DPD) ]
    Sep 5 12:58:00	charon: 13[IKE] <con1|3>sending DPD request
    Sep 5 12:57:50	charon: 14[ENC] <con1|3>parsed INFORMATIONAL_V1 request 3806937966 [ HASH N(DPD_ACK) ]
    Sep 5 12:57:50	charon: 14[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (100 bytes)
    Sep 5 12:57:50	charon: 11[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (92 bytes)
    Sep 5 12:57:50	charon: 11[ENC] <con1|3>generating INFORMATIONAL_V1 request 269892292 [ HASH N(DPD) ]
    Sep 5 12:57:50	charon: 11[IKE] <con1|3>sending DPD request
    Sep 5 12:57:49	charon: 07[IKE] <con1|3>received retransmit of request with ID 2727296463, but no response to retransmit
    Sep 5 12:57:49	charon: 07[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:46	charon: 11[IKE] <con1|3>received retransmit of request with ID 2727296463, but no response to retransmit
    Sep 5 12:57:46	charon: 11[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:43	charon: 07[IKE] <con1|3>received retransmit of request with ID 2727296463, but no response to retransmit
    Sep 5 12:57:43	charon: 07[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:40	charon: 15[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (76 bytes)
    Sep 5 12:57:40	charon: 15[ENC] <con1|3>generating INFORMATIONAL_V1 request 1602887348 [ HASH N(INVAL_ID) ]
    Sep 5 12:57:40	charon: 15[IKE] <con1|3>no matching CHILD_SA config found
    Sep 5 12:57:40	charon: 15[ENC] <con1|3>parsed QUICK_MODE request 2727296463 [ HASH SA No ID ID ]
    Sep 5 12:57:40	charon: 15[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:37	charon: 10[IKE] <con1|3>QUICK_MODE request with message ID 2727296463 processing failed
    Sep 5 12:57:37	charon: 10[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (68 bytes)
    Sep 5 12:57:37	charon: 10[ENC] <con1|3>generating INFORMATIONAL_V1 request 641992696 [ HASH N(INVAL_HASH) ]
    Sep 5 12:57:37	charon: 10[IKE] <con1|3>integrity check failed
    Sep 5 12:57:37	charon: 10[ENC] <con1|3>received HASH payload does not match
    Sep 5 12:57:37	charon: 10[ENC] <con1|3>parsed QUICK_MODE request 2727296463 [ HASH SA No ID ID ]
    Sep 5 12:57:37	charon: 10[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:34	charon: 09[IKE] <con1|3>QUICK_MODE request with message ID 2727296463 processing failed
    Sep 5 12:57:34	charon: 09[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (68 bytes)
    Sep 5 12:57:34	charon: 09[ENC] <con1|3>generating INFORMATIONAL_V1 request 4075124940 [ HASH N(INVAL_HASH) ]
    Sep 5 12:57:34	charon: 09[IKE] <con1|3>integrity check failed
    Sep 5 12:57:34	charon: 09[ENC] <con1|3>received HASH payload does not match
    Sep 5 12:57:34	charon: 09[ENC] <con1|3>parsed QUICK_MODE request 2727296463 [ HASH SA No ID ID ]
    Sep 5 12:57:34	charon: 09[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:32	charon: 09[ENC] <con1|3>parsed INFORMATIONAL_V1 request 3152393528 [ HASH N(DPD_ACK) ]
    Sep 5 12:57:32	charon: 09[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (100 bytes)
    Sep 5 12:57:32	charon: 15[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (92 bytes)
    Sep 5 12:57:32	charon: 15[ENC] <con1|3>generating INFORMATIONAL_V1 request 3100154220 [ HASH N(DPD) ]
    Sep 5 12:57:32	charon: 15[IKE] <con1|3>sending DPD request
    Sep 5 12:57:31	charon: 08[IKE] <con1|3>received retransmit of request with ID 2727296463, but no response to retransmit
    Sep 5 12:57:31	charon: 08[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:28	charon: 15[IKE] <con1|3>received retransmit of request with ID 2727296463, but no response to retransmit
    Sep 5 12:57:28	charon: 15[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:25	charon: 08[IKE] <con1|3>received retransmit of request with ID 2727296463, but no response to retransmit
    Sep 5 12:57:25	charon: 08[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:22	charon: 12[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (76 bytes)
    Sep 5 12:57:22	charon: 12[ENC] <con1|3>generating INFORMATIONAL_V1 request 1310038501 [ HASH N(INVAL_ID) ]
    Sep 5 12:57:22	charon: 12[IKE] <con1|3>no matching CHILD_SA config found
    Sep 5 12:57:22	charon: 12[ENC] <con1|3>parsed QUICK_MODE request 2727296463 [ HASH SA No ID ID ]
    Sep 5 12:57:22	charon: 12[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (340 bytes)
    Sep 5 12:57:22	charon: 12[ENC] <con1|3>parsed INFORMATIONAL_V1 request 2186817399 [ HASH N(INITIAL_CONTACT) ]
    Sep 5 12:57:22	charon: 12[NET] <con1|3>received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (92 bytes)
    Sep 5 12:57:22	charon: 08[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39883] (68 bytes)
    Sep 5 12:57:22	charon: 08[ENC] <con1|3>generating ID_PROT response 0 [ ID HASH ]
    Sep 5 12:57:22	charon: 08[IKE] <con1|3>maximum IKE_SA lifetime 28508s
    Sep 5 12:57:22	charon: 08[IKE] <con1|3>scheduling reauthentication in 27968s
    Sep 5 12:57:22	charon: 08[IKE] <con1|3>IKE_SA con1[3] established between 172.17.0.20[172.17.0.20]...37.48.4.217[100.80.121.223]
    Sep 5 12:57:22	charon: 08[CFG] <3> selected peer config "con1"
    Sep 5 12:57:22	charon: 08[CFG] <3> looking for pre-shared key peer configs matching 172.17.0.20...37.48.4.217[100.80.121.223]
    Sep 5 12:57:22	charon: 08[ENC] <3> parsed ID_PROT request 0 [ ID HASH ]
    Sep 5 12:57:22	charon: 08[NET] <3> received packet: from 37.48.4.217[39883] to 172.17.0.20[4500] (76 bytes)
    Sep 5 12:57:22	charon: 08[NET] <3> sending packet: from 172.17.0.20[500] to 37.48.4.217[39995] (244 bytes)
    Sep 5 12:57:22	charon: 08[ENC] <3> generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
    Sep 5 12:57:22	charon: 08[IKE] <3> remote host is behind NAT
    Sep 5 12:57:22	charon: 08[IKE] <3> local host is behind NAT, sending keep alives
    Sep 5 12:57:22	charon: 08[ENC] <3> parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
    Sep 5 12:57:22	charon: 08[NET] <3> received packet: from 37.48.4.217[39995] to 172.17.0.20[500] (228 bytes)
    Sep 5 12:57:21	charon: 10[NET] <3> sending packet: from 172.17.0.20[500] to 37.48.4.217[39995] (156 bytes)
    Sep 5 12:57:21	charon: 10[ENC] <3> generating ID_PROT response 0 [ SA V V V V ]
    Sep 5 12:57:21	charon: 10[IKE] <3> 37.48.4.217 is initiating a Main Mode IKE_SA
    Sep 5 12:57:21	charon: 10[IKE] <3> received DPD vendor ID
    Sep 5 12:57:21	charon: 10[IKE] <3> received FRAGMENTATION vendor ID
    Sep 5 12:57:21	charon: 10[IKE] <3> received draft-ietf-ipsec-nat-t-ike-00 vendor ID
    Sep 5 12:57:21	charon: 10[IKE] <3> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    Sep 5 12:57:21	charon: 10[IKE] <3> received draft-ietf-ipsec-nat-t-ike-02 vendor ID
    Sep 5 12:57:21	charon: 10[IKE] <3> received NAT-T (RFC 3947) vendor ID
    Sep 5 12:57:21	charon: 10[ENC] <3> parsed ID_PROT request 0 [ SA V V V V V V ]
    Sep 5 12:57:21	charon: 10[NET] <3> received packet: from 37.48.4.217[39995] to 172.17.0.20[500] (444 bytes)</con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3> 
    

    /var/etc/ipsec/ipsec.conf :

    
    # This file is automatically generated. Do not edit
    config setup
    	uniqueids = yes
    
    conn bypasslan
    	leftsubnet = 192.168.1.0/24
    	rightsubnet = 192.168.1.0/24
    	authby = never
    	type = passthrough
    	auto = route
    
    conn con1
    	fragmentation = yes
    	keyexchange = ikev1
    	reauth = yes
    	forceencaps = yes
    	mobike = no
    
    	rekey = yes
    	installpolicy = yes
    	type = transport
    	dpdaction = clear
    	dpddelay = 10s
    	dpdtimeout = 60s
    	auto = add
    	left = %any
    	right = %any
    	leftid = 172.17.0.20
    	ikelifetime = 28800s
    	lifetime = 3600s
    	rightsourceip = 192.168.81.0/24
    	ike = 3des-sha1-modp1024!
    	esp = aes256-md5,aes256-sha1,aes256-sha256,aes192-md5,aes192-sha1,aes192-sha256,aes128-md5,aes128-sha1,aes128-sha256,blowfish256-md5,blowfish256-sha1,blowfish256-sha256,blowfish192-md5,blowfish192-sha1,blowfish192-sha256,blowfish128-md5,blowfish128-sha1,blowfish128-sha256,3des-md5,3des-sha1,3des-sha256,cast128-md5,cast128-sha1,cast128-sha256!
    	leftauth = psk
    	rightauth = psk
    	aggressive = no
    
    

    /var/etc/ipsec/ipsec.secrets :

    
     %any : PSK 0sbG9wYXRhamVkZXBvbGVzZQ==
    
    

    /var/etc/ipsec/strongswan.conf:

    
    # Automatically generated config file - DO NOT MODIFY. Changes will be overwritten.
    starter {
    	load_warning = no
    	config_file = /var/etc/ipsec/ipsec.conf
    }
    
    charon {
    # number of worker threads in charon
    	threads = 16
    	ikesa_table_size = 32
    	ikesa_table_segments = 4
    	init_limit_half_open = 1000
    	install_routes = no
    	load_modular = yes
    	ignore_acquire_ts = yes
    
    	cisco_unity = no
    
    	make_before_break = yes
    
    	syslog {
    		identifier = charon
    		# log everything under daemon since it ends up in the same place regardless with our syslog.conf
    		daemon {
    			ike_name = yes
    			dmn = 1
    			mgr = 1
    			ike = 1
    			chd = 1
    			job = 1
    			cfg = 1
    			knl = 1
    			net = 1
    			asn = 1
    			enc = 1
    			imc = 1
    			imv = 1
    			pts = 1
    			tls = 1
    			esp = 1
    			lib = 1
    
    		}
    		# disable logging under auth so logs aren't duplicated
    		auth {
    			default = -1
    		}
    	}
    
    	plugins {
    		# Load defaults
    		include /var/etc/ipsec/strongswan.d/charon/*.conf
    
    		stroke {
    			secrets_file = /var/etc/ipsec/ipsec.secrets
    		}
    
    		unity {
    			load = no
    		}
    		attr {
    			dns = 192.168.1.202,192.168.1.203
    			subnet = /
    			split-include = /
    			# Search domain and default domain
    			28674 = "corp.company.cz"
    			28675 = "corp.company.cz"
    		}
    		xauth-generic {
    			script = /etc/inc/ipsec.auth-user.php
    			authcfg = Local Database
    		}
    
    	}
    }
    
    

    From pfSense web I know only that is "Network Mismatch" in Phase 2 :
    https://doc.pfsense.org/index.php/IPsec_Troubleshooting

    Last days I tried more settings, but no give me solution :-/.
    Can you anyone help me with this?

    Thank you very much

    Max

















    config.xml.txt



  • Maybe is problem with L2TP IP Range, because is not possible set begin IP higher than 0.
    So, I have set
    server address : 192.168.81.253
    start remote range : 192.168.81.0
    mask : 24
    number of L2TP users : 250

    If I set "start remote range : 192.168.81.1", then GUI rewrite settings to "192.168.81.0"

    and :
    /var/etc/l2tp-vpn/mpd.conf

    have this lines :

    
    ...
    l2tp0:
            new -i l2tp0 l2tp0 l2tp0
            set ipcp ranges 192.168.81.253/32 192.168.81.0/32
            load l2tp_standard
    
    l2tp1:
            new -i l2tp1 l2tp1 l2tp1
            set ipcp ranges 192.168.81.253/32 192.168.81.1/32
            load l2tp_standard
    
    l2tp2:
            new -i l2tp2 l2tp2 l2tp2
            set ipcp ranges 192.168.81.253/32 192.168.81.2/32
            load l2tp_standard
    
    l2tp3:
            new -i l2tp3 l2tp3 l2tp3
            set ipcp ranges 192.168.81.253/32 192.168.81.3/32
            load l2tp_standard
    ...
    
    

    This looks bad, or am I wrong?

    Thanks

    Max


  • Banned

    From the log, it looks like the Hash Algorithm in Phase 2 is not negotiated properly. Please verify the following settings:

    1. Did you set the Pre-Shared Key under VPN > IPSec > Pre-Shared Keys? If you have not, the identifier that worked for me is "allusers"

    2. "Server address" should not be in the same subnet as "Remote address range". In your case, you can set it for 192.168.82.1. I know it makes no sense, but it's not the default gateway for the remote clients; rather, it's the virtual L2TP interface IP in pfSense.

    3. In my case, I did not select the checkbox next to "Virtual Address Pool" (VPN > IPSec > Mobile Clients).

    4. For IPSec Phase 1, I was able to use these settings:
    Authentication Method: Mutual PSK
    Negotiation Mode: Main
    My Identifier: My IP Address
    Encryption Algorithm: AES 256 bits
    Hash Algorithm: SHA256
    DH Group: 14 (2048 bits)

    or

    Authentication Method: Mutual PSK
    Negotiation Mode: Main
    My Identifier: My IP Address
    Encryption Algorithm: AES 128 bits
    Hash Algorithm: SHA1
    DH Group: 2 (1024 bit)

    –-----
    For IKE Phase 2, I was able to use these settings:
    Protocol: ESP
    AES: 128 bits
    Hash Algorithm: SHA1
    PFS key group: off

    or

    Protocol: ESP
    AES: 256 bits (lower throughput than 128 bits)
    Hash Algorithm: SHA1 (SHA256 did NOT work for me here).
    PFS key group: off



  • Hi sirozha,

    thank you, I unchecked "Virtual Address Pool" and error with "CHILD_SA config found" is gone.
    Now is connection estabilished, but communication not working and tunnel go down. See log below (log with Android 5.0.2):

    
    Sep 6 13:32:53	charon: 14[JOB] <con1|3>DPD check timed out, enforcing DPD action
    Sep 6 13:32:43	charon: 05[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:32:43	charon: 05[ENC] <con1|3>generating INFORMATIONAL_V1 request 3535955023 [ HASH N(DPD) ]
    Sep 6 13:32:43	charon: 05[IKE] <con1|3>sending DPD request
    Sep 6 13:32:33	charon: 15[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:32:33	charon: 15[ENC] <con1|3>generating INFORMATIONAL_V1 request 1300470192 [ HASH N(DPD) ]
    Sep 6 13:32:33	charon: 15[IKE] <con1|3>sending DPD request
    Sep 6 13:32:23	charon: 05[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:32:23	charon: 05[ENC] <con1|3>generating INFORMATIONAL_V1 request 1319197639 [ HASH N(DPD) ]
    Sep 6 13:32:23	charon: 05[IKE] <con1|3>sending DPD request
    Sep 6 13:32:13	charon: 15[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:32:13	charon: 15[ENC] <con1|3>generating INFORMATIONAL_V1 request 3399189039 [ HASH N(DPD) ]
    Sep 6 13:32:13	charon: 15[IKE] <con1|3>sending DPD request
    Sep 6 13:32:03	charon: 11[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:32:03	charon: 11[ENC] <con1|3>generating INFORMATIONAL_V1 request 1931306227 [ HASH N(DPD) ]
    Sep 6 13:32:03	charon: 11[IKE] <con1|3>sending DPD request
    Sep 6 13:31:53	charon: 11[ENC] <con1|3>parsed INFORMATIONAL_V1 request 3564880432 [ HASH N(DPD_ACK) ]
    Sep 6 13:31:53	charon: 11[NET] <con1|3>received packet: from 37.48.4.217[39870] to 172.17.0.20[4500] (108 bytes)
    Sep 6 13:31:53	charon: 15[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:31:53	charon: 15[ENC] <con1|3>generating INFORMATIONAL_V1 request 1463941235 [ HASH N(DPD) ]
    Sep 6 13:31:53	charon: 15[IKE] <con1|3>sending DPD request
    Sep 6 13:31:43	charon: 15[ENC] <con1|3>parsed INFORMATIONAL_V1 request 4084024601 [ HASH N(DPD_ACK) ]
    Sep 6 13:31:43	charon: 15[NET] <con1|3>received packet: from 37.48.4.217[39870] to 172.17.0.20[4500] (108 bytes)
    Sep 6 13:31:43	charon: 12[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:31:43	charon: 12[ENC] <con1|3>generating INFORMATIONAL_V1 request 2667992091 [ HASH N(DPD) ]
    Sep 6 13:31:43	charon: 12[IKE] <con1|3>sending DPD request
    Sep 6 13:31:33	charon: 12[ENC] <con1|3>parsed INFORMATIONAL_V1 request 4055282546 [ HASH N(DPD_ACK) ]
    Sep 6 13:31:33	charon: 12[NET] <con1|3>received packet: from 37.48.4.217[39870] to 172.17.0.20[4500] (108 bytes)
    Sep 6 13:31:33	charon: 15[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:31:33	charon: 15[ENC] <con1|3>generating INFORMATIONAL_V1 request 4174064800 [ HASH N(DPD) ]
    Sep 6 13:31:33	charon: 15[IKE] <con1|3>sending DPD request
    Sep 6 13:31:23	charon: 15[ENC] <con1|3>parsed INFORMATIONAL_V1 request 2401102524 [ HASH N(DPD_ACK) ]
    Sep 6 13:31:23	charon: 15[NET] <con1|3>received packet: from 37.48.4.217[39870] to 172.17.0.20[4500] (108 bytes)
    Sep 6 13:31:22	charon: 06[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:31:22	charon: 06[ENC] <con1|3>generating INFORMATIONAL_V1 request 1889749403 [ HASH N(DPD) ]
    Sep 6 13:31:22	charon: 06[IKE] <con1|3>sending DPD request
    Sep 6 13:31:13	charon: 06[ENC] <con1|3>parsed INFORMATIONAL_V1 request 3236894850 [ HASH N(DPD_ACK) ]
    Sep 6 13:31:13	charon: 06[NET] <con1|3>received packet: from 37.48.4.217[39870] to 172.17.0.20[4500] (108 bytes)
    Sep 6 13:31:12	charon: 15[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (92 bytes)
    Sep 6 13:31:12	charon: 15[ENC] <con1|3>generating INFORMATIONAL_V1 request 2824003961 [ HASH N(DPD) ]
    Sep 6 13:31:12	charon: 15[IKE] <con1|3>sending DPD request
    Sep 6 13:31:02	charon: 15[IKE] <con1|3>CHILD_SA con1{2} established with SPIs c76df120_i 0145cc5c_o and TS 172.17.0.20/32|/0[udp/l2f] === 37.48.4.217/32|/0[udp]
    Sep 6 13:31:02	charon: 15[ENC] <con1|3>parsed QUICK_MODE request 3513204958 [ HASH ]
    Sep 6 13:31:02	charon: 15[NET] <con1|3>received packet: from 37.48.4.217[39870] to 172.17.0.20[4500] (76 bytes)
    Sep 6 13:31:02	charon: 12[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (204 bytes)
    Sep 6 13:31:02	charon: 12[ENC] <con1|3>generating QUICK_MODE response 3513204958 [ HASH SA No ID ID NAT-OA NAT-OA ]
    Sep 6 13:31:02	charon: 12[IKE] <con1|3>received 28800s lifetime, configured 3600s
    Sep 6 13:31:02	charon: 12[ENC] <con1|3>parsed QUICK_MODE request 3513204958 [ HASH SA No ID ID ]
    Sep 6 13:31:02	charon: 12[NET] <con1|3>received packet: from 37.48.4.217[39870] to 172.17.0.20[4500] (348 bytes)
    Sep 6 13:31:00	charon: 08[ENC] <con1|3>parsed INFORMATIONAL_V1 request 2518634056 [ HASH N(INITIAL_CONTACT) ]
    Sep 6 13:31:00	charon: 08[NET] <con1|3>received packet: from 37.48.4.217[39870] to 172.17.0.20[4500] (108 bytes)
    Sep 6 13:31:00	charon: 12[NET] <con1|3>sending packet: from 172.17.0.20[4500] to 37.48.4.217[39870] (76 bytes)
    Sep 6 13:31:00	charon: 12[ENC] <con1|3>generating ID_PROT response 0 [ ID HASH ]
    Sep 6 13:31:00	charon: 12[IKE] <con1|3>maximum IKE_SA lifetime 28287s
    Sep 6 13:31:00	charon: 12[IKE] <con1|3>scheduling reauthentication in 27747s
    Sep 6 13:31:00	charon: 12[IKE] <con1|3>IKE_SA con1[3] established between 172.17.0.20[172.17.0.20]...37.48.4.217[100.80.121.223]
    Sep 6 13:31:00	charon: 12[CFG] <3> selected peer config "con1"
    Sep 6 13:31:00	charon: 12[CFG] <3> looking for pre-shared key peer configs matching 172.17.0.20...37.48.4.217[100.80.121.223]
    Sep 6 13:31:00	charon: 12[ENC] <3> parsed ID_PROT request 0 [ ID HASH ]
    Sep 6 13:31:00	charon: 12[NET] <3> received packet: from 37.48.4.217[39870] to 172.17.0.20[4500] (92 bytes)
    Sep 6 13:31:00	charon: 12[NET] <3> sending packet: from 172.17.0.20[500] to 37.48.4.217[39906] (244 bytes)
    Sep 6 13:31:00	charon: 12[ENC] <3> generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
    Sep 6 13:31:00	charon: 12[IKE] <3> remote host is behind NAT
    Sep 6 13:31:00	charon: 12[IKE] <3> local host is behind NAT, sending keep alives
    Sep 6 13:31:00	charon: 12[ENC] <3> parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
    Sep 6 13:31:00	charon: 12[NET] <3> received packet: from 37.48.4.217[39906] to 172.17.0.20[500] (228 bytes)
    Sep 6 13:31:00	charon: 13[NET] <3> sending packet: from 172.17.0.20[500] to 37.48.4.217[39906] (136 bytes)
    Sep 6 13:31:00	charon: 13[ENC] <3> generating ID_PROT response 0 [ SA V V V ]
    Sep 6 13:31:00	charon: 13[IKE] <3> 37.48.4.217 is initiating a Main Mode IKE_SA
    Sep 6 13:31:00	charon: 13[IKE] <3> received DPD vendor ID
    Sep 6 13:31:00	charon: 13[IKE] <3> received FRAGMENTATION vendor ID
    Sep 6 13:31:00	charon: 13[IKE] <3> received draft-ietf-ipsec-nat-t-ike-00 vendor ID
    Sep 6 13:31:00	charon: 13[IKE] <3> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    Sep 6 13:31:00	charon: 13[IKE] <3> received draft-ietf-ipsec-nat-t-ike-02 vendor ID
    Sep 6 13:31:00	charon: 13[IKE] <3> received NAT-T (RFC 3947) vendor ID
    Sep 6 13:31:00	charon: 13[ENC] <3> parsed ID_PROT request 0 [ SA V V V V V V ]
    Sep 6 13:31:00	charon: 13[NET] <3> received packet: from 37.48.4.217[39906] to 172.17.0.20[500] (444 bytes)</con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3></con1|3> 
    

    Log with windows 10 :

    
    Sep 6 14:46:07	charon: 10[IKE] <con1|9>deleting IKE_SA con1[9] between 172.17.0.20[172.17.0.20]...195.47.113.189[10.0.0.81]
    Sep 6 14:46:07	charon: 10[IKE] <con1|9>received DELETE for IKE_SA con1[9]
    Sep 6 14:46:07	charon: 10[ENC] <con1|9>parsed INFORMATIONAL_V1 request 2274322088 [ HASH D ]
    Sep 6 14:46:07	charon: 10[NET] <con1|9>received packet: from 195.47.113.189[4500] to 172.17.0.20[4500] (92 bytes)
    Sep 6 14:46:07	charon: 14[IKE] <con1|9>closing CHILD_SA con1{12} with SPIs ccb85aa0_i (665 bytes) 98886d34_o (0 bytes) and TS 172.17.0.20/32|/0[udp/l2f] === 195.47.113.189/32|/0[udp/l2f]
    Sep 6 14:46:07	charon: 14[IKE] <con1|9>received DELETE for ESP CHILD_SA with SPI 98886d34
    Sep 6 14:46:07	charon: 14[ENC] <con1|9>parsed INFORMATIONAL_V1 request 88292091 [ HASH D ]
    Sep 6 14:46:07	charon: 14[NET] <con1|9>received packet: from 195.47.113.189[4500] to 172.17.0.20[4500] (76 bytes)
    Sep 6 14:45:55	charon: 07[IKE] <con1|9>sending keep alive to 195.47.113.189[4500]
    Sep 6 14:45:32	charon: 14[IKE] <con1|9>CHILD_SA con1{12} established with SPIs ccb85aa0_i 98886d34_o and TS 172.17.0.20/32|/0[udp/l2f] === 195.47.113.189/32|/0[udp/l2f]
    Sep 6 14:45:32	charon: 14[ENC] <con1|9>parsed QUICK_MODE request 1 [ HASH ]
    Sep 6 14:45:32	charon: 14[NET] <con1|9>received packet: from 195.47.113.189[4500] to 172.17.0.20[4500] (60 bytes)
    Sep 6 14:45:32	charon: 14[NET] <con1|9>sending packet: from 172.17.0.20[4500] to 195.47.113.189[4500] (204 bytes)
    Sep 6 14:45:32	charon: 14[ENC] <con1|9>generating QUICK_MODE response 1 [ HASH SA No ID ID NAT-OA NAT-OA ]
    Sep 6 14:45:32	charon: 14[IKE] <con1|9>received 250000000 lifebytes, configured 0
    Sep 6 14:45:32	charon: 14[ENC] <con1|9>parsed QUICK_MODE request 1 [ HASH SA No ID ID NAT-OA NAT-OA ]
    Sep 6 14:45:32	charon: 14[NET] <con1|9>received packet: from 195.47.113.189[4500] to 172.17.0.20[4500] (332 bytes)
    Sep 6 14:45:31	charon: 13[NET] <con1|9>sending packet: from 172.17.0.20[4500] to 195.47.113.189[4500] (76 bytes)
    Sep 6 14:45:31	charon: 13[ENC] <con1|9>generating ID_PROT response 0 [ ID HASH ]
    Sep 6 14:45:31	charon: 13[IKE] <con1|9>DPD not supported by peer, disabled
    Sep 6 14:45:31	charon: 13[IKE] <con1|9>maximum IKE_SA lifetime 28779s
    Sep 6 14:45:31	charon: 13[IKE] <con1|9>scheduling reauthentication in 28239s
    Sep 6 14:45:31	charon: 13[IKE] <con1|9>IKE_SA con1[9] established between 172.17.0.20[172.17.0.20]...195.47.113.189[10.0.0.81]
    Sep 6 14:45:31	charon: 13[CFG] <9> selected peer config "con1"
    Sep 6 14:45:31	charon: 13[CFG] <9> looking for pre-shared key peer configs matching 172.17.0.20...195.47.113.189[10.0.0.81]
    Sep 6 14:45:31	charon: 13[ENC] <9> parsed ID_PROT request 0 [ ID HASH ]
    Sep 6 14:45:31	charon: 13[NET] <9> received packet: from 195.47.113.189[4500] to 172.17.0.20[4500] (76 bytes)
    Sep 6 14:45:31	charon: 13[NET] <9> sending packet: from 172.17.0.20[500] to 195.47.113.189[500] (212 bytes)
    Sep 6 14:45:31	charon: 13[ENC] <9> generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
    Sep 6 14:45:31	charon: 13[IKE] <9> remote host is behind NAT
    Sep 6 14:45:31	charon: 13[IKE] <9> local host is behind NAT, sending keep alives
    Sep 6 14:45:31	charon: 13[ENC] <9> parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
    Sep 6 14:45:31	charon: 13[NET] <9> received packet: from 195.47.113.189[500] to 172.17.0.20[500] (228 bytes)
    Sep 6 14:45:31	charon: 06[NET] <9> sending packet: from 172.17.0.20[500] to 195.47.113.189[500] (136 bytes)
    Sep 6 14:45:31	charon: 06[ENC] <9> generating ID_PROT response 0 [ SA V V V ]
    Sep 6 14:45:31	charon: 06[IKE] <9> 195.47.113.189 is initiating a Main Mode IKE_SA
    Sep 6 14:45:31	charon: 06[ENC] <9> received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
    Sep 6 14:45:31	charon: 06[ENC] <9> received unknown vendor ID: 26:24:4d:38:ed:db:61:b3:17:2a:36:e3:d0:cf:b8:19
    Sep 6 14:45:31	charon: 06[ENC] <9> received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
    Sep 6 14:45:31	charon: 06[IKE] <9> received FRAGMENTATION vendor ID
    Sep 6 14:45:31	charon: 06[IKE] <9> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    Sep 6 14:45:31	charon: 06[IKE] <9> received NAT-T (RFC 3947) vendor ID
    Sep 6 14:45:31	charon: 06[IKE] <9> received MS NT5 ISAKMPOAKLEY vendor ID
    Sep 6 14:45:31	charon: 06[ENC] <9> received unknown vendor ID: 01:52:8b:bb:c0:06:96:12:18:49:ab:9a:1c:5b:2a:51:00:00:00:01
    Sep 6 14:45:31	charon: 06[ENC] <9> parsed ID_PROT request 0 [ SA V V V V V V V V ]
    Sep 6 14:45:31	charon: 06[NET] <9> received packet: from 195.47.113.189[500] to 172.17.0.20[500] (408 bytes)</con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9> 
    

    And windows 10 display Error code 809. I have applied this reg key in Win10 :
    https://vkelk.wordpress.com/2012/10/28/windows-72008-error-809-l2tp-vpn/

    This does not look like problem with encryption format. Do you have any tips?

    Thanks
    Max

    PS: server IP is now "192.168.82.1" and Remote address range is still 192.168.81.0/24



  • Maybe is problem with NAT, because for example Zyxel product (aka Zyxel USG 100) does not support L2TP server behind nat.
    I tried pfSense in Home with DMZ (full port forwarde : NAT 1:1) and does not work too.
    I log all firewall traffic and :
    PHASE 1 is ok
    PHASE 2 is ok
    L2TP Phase fail …

    
    	Sep 6 22:46:14	WAN	  192.168.81.1	  224.0.0.1	IGMP
    Sep 6 22:46:14	WAN	  192.168.200.1	  224.0.0.1	IGMP
    Sep 6 22:46:14	WAN	  192.168.200.1	  224.0.0.1	IGMP
    Sep 6 22:46:14	WAN	  192.168.200.1	  224.0.0.1	IGMP
    Sep 6 22:44:08	WAN	  192.168.81.1	  224.0.0.1	IGMP
    Sep 6 22:44:08	WAN	  192.168.81.1	  224.0.0.1	IGMP
    Sep 6 22:44:08	WAN	  192.168.81.1	  224.0.0.1	IGMP
    Sep 6 22:44:08	WAN	  192.168.200.1	  224.0.0.1	IGMP
    Sep 6 22:44:08	WAN	  192.168.200.1	  224.0.0.1	IGMP
    Sep 6 22:44:08	WAN	  192.168.200.1	  224.0.0.1	IGMP
    Sep 6 22:44:06	WAN	  42.49.107.170:37258	  192.168.200.220:23	TCP:S
    Sep 6 22:44:05	WAN	  192.168.200.21:138	  192.168.200.255:138	UDP
    Sep 6 22:44:02	WAN	  190.255.132.43:37680	  192.168.200.220:23	TCP:S
    Sep 6 22:43:54	WAN	  36.68.1.9:53230	  192.168.200.220:23	TCP:S
    Sep 6 22:43:10	WAN	  187.101.214.153:41452	  192.168.200.220:23	TCP:S
    Sep 6 22:43:05	IPsec	  37.188.147.173:1701	  192.168.200.220:1701	UDP
    Sep 6 22:43:05	WAN	  37.188.147.173:23684	  192.168.200.220:4500	UDP
    Sep 6 22:43:04	WAN	  37.188.147.173:23683	  192.168.200.220:500	UDP
    
    

    Thanks

    Max



  • So, it is true, last problem is with NAT.
    I have news from one man, he said, that first connection is via IPSEC (UDP500 and UDP4500) but L2TP communication is via protocol 115.
    So, for L2TP over IPSEC with NAT must be forwarded UDP500, UDP4500 and proto 115
    I will try it and let you know.

    Max


  • Banned

    It makes no sense because L2TP would not be visible to the NAT device. I do believe the issue is caused by the device doing NAT though. Try to disable VPN pass-through in that device so that NAT-T is used exclusively.



  • Yes, you are right, PROTO 115 should be encapsalated in to IPSEC tunnel.
    I dont have access to NAT router, because he is managed by GTS / T-Mobile.
    I know, that router is Linux and have this iptables rules :

    
    -A PREROUTING -d 193.xx.xx.xxx/32 -p udp -m multiport --dports 500,4500 -m comment --comment "IPSec forward TT18987" -j DNAT --to-destination 172.17.0.20
    -A POSTROUTING -s 172.17.0.20/32 -o eth2 -m conntrack --ctstate NEW -m comment --comment "IPSec forward TT18987" -j SNAT --to-source 193.xx.xx.xxx
    -A inetlan -d 172.17.0.20/32 -p udp -m multiport --dports 500,4500 -m comment --comment "IPSec forward TT18987" -j ACCEPT
    -A laninet -s 172.17.0.20/32 -p udp -m multiport --sports 500,4500 -m comment --comment "IPSec forward TT18987" -j ACCEPT
    
    

    Tonight I will try at home pfsense with same configuration but without nat.

    Max



  • I found solution :
    https://forums.freebsd.org/threads/26755/page-7

    So, in freebsd with standard kernel does not work L2TP server behind nat.
    So, freebsd kernel must be patched and kernel in pfsense is not patched, because :
    sysctl: unknown oid 'net.inet.esp.esp_ignore_natt_cksum'

    Second option is remove some checksum options in kernel source and compile own kernel (this is from FreeBSD 10.2):

    
    /usr/src/sys/netinet/udp_usrreq.c
    ...
    
            /*
             * We cannot yet update the cksums so clear any
             * h/w cksum flags as they are no longer valid.
             */
            // if (m->m_pkthdr.csum_flags & CSUM_DATA_VALID)
            //      m->m_pkthdr.csum_flags &= ~(CSUM_DATA_VALID|CSUM_PSEUDO_HDR);
    
    ...
    
    

    Max


  • Banned

    Seems that the problem is with FreeBSD encapsulating with IPSec behind the NAT, not with L2TP per se. I'm surprised this has not been an issue before since it would seem that there would be a certain percentage of pfSense devices installed behind another device doing NAT.

    Has a bug been filed with pfSense?



  • It is a bug? I dont think so. FreeBSD kernel just drop packet with bad checksum. This is problem with NAT.
    So, maybe will be ignoring checksum nice to have feature, but in this case you must manualy put registry key in to windows :
    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\PolicyAgent
    AssumeUDPEncapsulationContextOnSendRule dword:2

    And you cant be sure, that will working another devices (iOS, android with specific version, MacOSX etc.).

    So, I surrende and I will have public IP directly on pfSense.

    Max

    PS: I think, that many people use pfSense for IPSEC (IPSEC working very nice behind NAT) and many people know NAT problems, so I think that many users use public IP on pfSense