Community discussions

MikroTik App
 
User avatar
LinuxLarry
just joined
Topic Author
Posts: 20
Joined: Fri Aug 10, 2018 9:31 pm
Location: Earth

L2TP with private ip from DHCP Server Connection Problems

Wed Aug 25, 2021 12:36 am

Howdy,

The topic may be confusing and I apologize for that. Currently if I use a public static ip address or I pull a public ip address via a dhcp client I can connect to the site and everything works well. However, if my device is behind a modem or another router that is routing and handing out private addresses the L2TP system fails to establish a connection successfully. I am wondering If I need to adjust a setting somewhere to compensate for this type of connection.

A relatable example would be in an edge x router from ubiquity when setting up l2tp I would either define next hop or outside hop if using static ip in the router or if I was using the dhcp client I would configure a dhcp interface. I have tried searching around for different configurations but all examples I have run across do not address this type of connection.

Currently using RB3011 with 6.47.10 long term

A small example of log output, the 10.106.74.190 is a private address coming from a device in front of the RB3011. the 47.x.x.x address is the address the connection is coming from but the ip address that is being used to connect is completely different. ports are open upstream for l2tp including protocol 50 to the mikrotik device.

15:25:32 ipsec,info respond new phase 1 (Identity Protection): 10.106.74.190[500]<=>47.203.211.198[500]
15:25:32 ipsec,info ISAKMP-SA established 10.106.74.190[4500]-47.203.211.34[4500] spi:c2dfc93fb6b3970f:34f278b2eb2aeaa4
15:26:08 ipsec,info purging ISAKMP-SA 10.106.74.190[4500]<=>47.203.211.34[4500] spi=c2dfc93fb6b3970f:34f278b2eb2aeaa4.
15:26:08 ipsec,info ISAKMP-SA deleted 10.106.74.190[4500]-47.203.211.34[4500] spi:c2dfc93fb6b3970f:34f278b2eb2aeaa4 rekey:1

/ppp profile pr
0 * name="default" local-address=10.10.10.1 remote-address=pool-vpn use-mpls=default use-compression=default use-encryption=yes only-one=no change-tcp-mss=yes use-upnp=default address-list="" on-up="" on-down=""

/interface l2tp-server server pr
enabled: yes
max-mtu: 1450
max-mru: 1450
mrru: disabled
authentication: pap,chap,mschap1,mschap2
keepalive-timeout: 30
max-sessions: unlimited
default-profile: default
use-ipsec: required
ipsec-secret: *******
caller-id-type: ip-address
one-session-per-host: no
allow-fast-path: no


If there is something else about the config I need to post please let me know. I appreciate any and all advice and I hope I can find a solution.
 
User avatar
LinuxLarry
just joined
Topic Author
Posts: 20
Joined: Fri Aug 10, 2018 9:31 pm
Location: Earth

Re: L2TP with private ip from DHCP Server Connection Problems

Wed Aug 25, 2021 1:58 am

I updated to 6.48.4 stable as I saw ipsec - fixed SA address parameter exporting; in the change log. Still same results. I read through viewtopic.php?f=2&t=132823 which is a lot and it sounds similar to my problem but in this it indicates they are getting at least 1 connection through and the problem is with other connections.

At this point I would be happy to have 1 working L2TP connection. IKEv2 is not an option for my environments and pptp is no go either. Altho I will add that pptp does work successfully.
 
sindy
Forum Guru
Forum Guru
Posts: 10206
Joined: Mon Dec 04, 2017 9:19 pm

Re: L2TP with private ip from DHCP Server Connection Problems  [SOLVED]

Wed Aug 25, 2021 9:50 am

You've written a lot in your OP but you've also left out a lot.

So do I guess properly that the 3011 getting a private WAN address from a NATing router is the L2TP/IPsec server and the L2TP/IPsec client that fails to connect is the Windows embedded VPN client?

If so, see this topic.
 
User avatar
LinuxLarry
just joined
Topic Author
Posts: 20
Joined: Fri Aug 10, 2018 9:31 pm
Location: Earth

Re: L2TP with private ip from DHCP Server Connection Problems

Wed Aug 25, 2021 4:56 pm

You've written a lot in your OP but you've also left out a lot.

So do I guess properly that the 3011 getting a private WAN address from a NATing router is the L2TP/IPsec server and the L2TP/IPsec client that fails to connect is the Windows embedded VPN client?

If so, see this topic.

Hi,

Yes the RB3011 is the l2tp server and the client is any client not just windows. The RB3011 is behind two devices Modem > Router > RB3011 both the modem and the additional router is passing 50 4500 500 1701 to the RB3011.

I did adjust the register on the windows machine I am testing connection from with the above in and same results in the log from the mikrotik when attempting to connect.
 
sindy
Forum Guru
Forum Guru
Posts: 10206
Joined: Mon Dec 04, 2017 9:19 pm

Re: L2TP with private ip from DHCP Server Connection Problems

Wed Aug 25, 2021 5:11 pm

You actually only need UDP ports 500 and 4500 to be forwarded all the way from the public IP to the 3011's WAN IP. UDP port 1701 is invisible to the firewall as it is the port of the payload encrypted and encapsulated inside the IPsec transport packets. If a cleartext packet to UDP port 1701 ever arrives, it means that the IPsec layer failed (or has not been requested in the client configuration) and whatever prevents such a connection attempt from being accepted is good because the whole connection would run without encryption.

50 is not a port number but an IP protocol number, aliased to ipsec-esp in Mikrotik firewall. And you only need to forward ESP all the way from the public IP to the 3011's WAN IP if some of the clients have public IPs directly on themselves. If all of them are behind a NAT on their side, bare ESP will never be used.

The log shows that an IPsec session has been successfully established but then terminated, which typically indicates that the L2TP negotiation, encrypted using that IPsec session, has failed. To see more details in the log, do the following:
/system logging add topics=ipsec,!packet
/system logging add topics=l2tp
 
User avatar
LinuxLarry
just joined
Topic Author
Posts: 20
Joined: Fri Aug 10, 2018 9:31 pm
Location: Earth

Re: L2TP with private ip from DHCP Server Connection Problems

Fri Aug 27, 2021 8:08 pm

I added the logging you had mentioned. I gave the router a fresh reboot and when I logged in and looked I noticed the following things right out the gate one with an error on 500

10:56:35 ipsec,debug 0.0.0.0[500] used as isakmp port (fd=25) 
10:56:35 ipsec,debug 0.0.0.0[4500] used as isakmp port with NAT-T (fd=27) 
 
10:56:38 ipsec,debug failed to bind to ::[500] Bad file descriptor


I am not using ipv6 so that should not be an issue or a concern correct? I will be getting some fresh log details to post up shortly.

Kind Regards
 
sindy
Forum Guru
Forum Guru
Posts: 10206
Joined: Mon Dec 04, 2017 9:19 pm

Re: L2TP with private ip from DHCP Server Connection Problems

Fri Aug 27, 2021 8:11 pm

Yes, you can ignore the failure to bind ::[500].
 
User avatar
LinuxLarry
just joined
Topic Author
Posts: 20
Joined: Fri Aug 10, 2018 9:31 pm
Location: Earth

Re: L2TP with private ip from DHCP Server Connection Problems

Fri Aug 27, 2021 8:17 pm

Fresh log output.
11:13:57 ipsec,debug ===== received 444 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:13:57 ipsec,debug hash(sha1) 
11:13:57 ipsec,debug === 
11:13:57 ipsec respond new phase 2 negotiation: 10.106.74.190[4500]<=>my.pubip.1[4500] 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=8(hash) len=24 
11:13:57 ipsec,debug seen nptype=1(sa) len=280 
11:13:57 ipsec,debug seen nptype=10(nonce) len=52 
11:13:57 ipsec,debug seen nptype=5(id) len=12 
11:13:57 ipsec,debug seen nptype=5(id) len=12 
11:13:57 ipsec,debug seen nptype=21(nat-oa) len=12 
11:13:57 ipsec,debug seen nptype=21(nat-oa) len=12 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug received IDci2: 
11:13:57 ipsec,debug 011106a5 0a0101dc 
11:13:57 ipsec,debug received IDcr2: 
11:13:57 ipsec,debug 011106a5 891a6c9a 
11:13:57 ipsec,debug HASH(1) validate: 
11:13:57 ipsec,debug 63564630 91532b8d a5191fa3 3be6054a 50ab39d3 
11:13:57 ipsec,debug total SA len=276 
11:13:57 ipsec,debug 00000001 00000001 02000038 01030401 bd067f70 0000002c 010c0000 80040004 
11:13:57 ipsec,debug 80060100 80050002 80010001 00020004 00000e10 80010002 00020004 0003d090 
11:13:57 ipsec,debug 02000038 02030401 bd067f70 0000002c 010c0000 80040004 80060080 80050002 
11:13:57 ipsec,debug 80010001 00020004 00000e10 80010002 00020004 0003d090 02000034 03030401 
11:13:57 ipsec,debug bd067f70 00000028 01030000 80040004 80050002 80010001 00020004 00000e10 
11:13:57 ipsec,debug 80010002 00020004 0003d090 02000034 04030401 bd067f70 00000028 01020000 
11:13:57 ipsec,debug 80040004 80050002 80010001 00020004 00000e10 80010002 00020004 0003d090 
11:13:57 ipsec,debug 00000034 05030401 bd067f70 00000028 010b0000 80040004 80050002 80010001 
11:13:57 ipsec,debug 00020004 00000e10 80010002 00020004 0003d090 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=2(prop) len=56 
11:13:57 ipsec,debug seen nptype=2(prop) len=56 
11:13:57 ipsec,debug seen nptype=2(prop) len=52 
11:13:57 ipsec,debug seen nptype=2(prop) len=52 
11:13:57 ipsec,debug seen nptype=2(prop) len=52 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug proposal #1 len=56 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=3(trns) len=44 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug transform #1 len=44 
11:13:57 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:13:57 ipsec,debug UDP encapsulation requested 
11:13:57 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
11:13:57 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug proposal #2 len=56 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=3(trns) len=44 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug transform #1 len=44 
11:13:57 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:13:57 ipsec,debug UDP encapsulation requested 
11:13:57 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
11:13:57 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug proposal #3 len=52 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=3(trns) len=40 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug transform #1 len=40 
11:13:57 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:13:57 ipsec,debug UDP encapsulation requested 
11:13:57 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug proposal #4 len=52 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=3(trns) len=40 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug transform #1 len=40 
11:13:57 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:13:57 ipsec,debug UDP encapsulation requested 
11:13:57 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug proposal #5 len=52 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=3(trns) len=40 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug transform #1 len=40 
11:13:57 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:13:57 ipsec,debug UDP encapsulation requested 
11:13:57 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug pair 1: 
11:13:57 ipsec,debug  0x9d840: next=(nil) tnext=(nil) 
11:13:57 ipsec,debug proposal #1: 1 transform 
11:13:57 ipsec,debug pair 2: 
11:13:57 ipsec,debug  0x9d858: next=(nil) tnext=(nil) 
11:13:57 ipsec,debug proposal #2: 1 transform 
11:13:57 ipsec,debug pair 3: 
11:13:57 ipsec,debug  0x9d870: next=(nil) tnext=(nil) 
11:13:57 ipsec,debug proposal #3: 1 transform 
11:13:57 ipsec,debug pair 4: 
11:13:57 ipsec,debug  0x9d888: next=(nil) tnext=(nil) 
11:13:57 ipsec,debug proposal #4: 1 transform 
11:13:57 ipsec,debug pair 5: 
11:13:57 ipsec,debug  0x9d8a0: next=(nil) tnext=(nil) 
11:13:57 ipsec,debug proposal #5: 1 transform 
11:13:57 ipsec,debug got the local address from ID payload puiblic.ip.1[1701] prefixlen=32 ul_proto=17 
11:13:57 ipsec,debug got the peer address from ID payload 10.1.1.220[1701] prefixlen=32 ul_proto=17 
11:13:57 ipsec,debug updating policy address because of NAT in transport mode 
11:13:57 ipsec,debug new local address 10.106.74.190[1701] 
11:13:57 ipsec,debug new peer address my.pubip.1[1701] 
11:13:57 ipsec searching for policy for selector: 10.106.74.190:1701 ip-proto:17 <=> my.pubip.1:1701 ip-proto:17 
11:13:57 ipsec using strict match: 10.106.74.190:1701 <=> my.pubip.1:1701 ip-proto:17 
11:13:57 ipsec,debug  (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=UDP-Transport reqid=2:2) 
11:13:57 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
11:13:57 ipsec,debug   (trns_id=AES-CBC encklen=192 authtype=hmac-sha1) 
11:13:57 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-sha1) 
11:13:57 ipsec,debug begin compare proposals. 
11:13:57 ipsec,debug pair[1]: 0x9d840 
11:13:57 ipsec,debug  0x9d840: next=(nil) tnext=(nil) 
11:13:57 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=1 trns#=1 trns-id=AES-CBC 
11:13:57 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:13:57 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
11:13:57 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug peer's single bundle: 
11:13:57 ipsec,debug  (proto_id=ESP spisize=4 spi=bd067f70 spi_p=00000000 encmode=UDP-Transport reqid=0:0) 
11:13:57 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
11:13:57 ipsec,debug my single bundle: 
11:13:57 ipsec,debug  (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=UDP-Transport reqid=2:2) 
11:13:57 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
11:13:57 ipsec,debug   (trns_id=AES-CBC encklen=192 authtype=hmac-sha1) 
11:13:57 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-sha1) 
11:13:57 ipsec Adjusting my encmode UDP-Transport->Transport 
11:13:57 ipsec Adjusting peer's encmode UDP-Transport(4)->Transport(2) 
11:13:57 ipsec,debug matched 
11:13:57 ipsec,debug === 
11:13:57 ipsec,debug call pfkey_send_getspi d 
11:13:57 ipsec,debug pfkey GETSPI sent: ESP/Transport my.pubip.1[4500]->10.106.74.190[4500]  
11:13:57 ipsec,debug pfkey getspi sent. 
11:13:57 ipsec,debug total SA len=64 
11:13:57 ipsec,debug 00000001 00000001 00000038 01030401 00000000 0000002c 010c0000 80040004 
11:13:57 ipsec,debug 80060100 80050002 80010001 00020004 00000e10 80010002 00020004 0003d090 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=2(prop) len=56 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug proposal #1 len=56 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=3(trns) len=44 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug transform #1 len=44 
11:13:57 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:13:57 ipsec,debug UDP encapsulation requested 
11:13:57 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
11:13:57 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:13:57 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:13:57 ipsec,debug pair 1: 
11:13:57 ipsec,debug  0x9bcb0: next=(nil) tnext=(nil) 
11:13:57 ipsec,debug proposal #1: 1 transform 
11:13:57 ipsec,debug NAT-OAi: 
11:13:57 ipsec,debug 01000000 2fcbd3c6 
11:13:57 ipsec,debug NAT-OAr: 
11:13:57 ipsec,debug 01000000 0a6a4abe 
11:13:57 ipsec,debug add payload of len 64, next type 10 
11:13:57 ipsec,debug add payload of len 24, next type 5 
11:13:57 ipsec,debug add payload of len 8, next type 5 
11:13:57 ipsec,debug add payload of len 8, next type 21 
11:13:57 ipsec,debug add payload of len 8, next type 21 
11:13:57 ipsec,debug add payload of len 8, next type 0 
11:13:57 ipsec,debug add payload of len 20, next type 1 
11:13:57 ipsec,debug 204 bytes from 10.106.74.190[4500] to my.pubip.1[4500] 
11:13:57 ipsec,debug 1 times of 208 bytes message will be sent to my.pubip.1[4500] 
11:13:57 ipsec sent phase2 packet 10.106.74.190[4500]<=>my.pubip.1[4500] c665fcbaa0443214:c73cd15ef6ef5f66:00000000 
11:13:57 ipsec,debug ===== received 60 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=8(hash) len=24 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug HASH(3) validate: 
11:13:57 ipsec,debug adcef992 4e213dd4 26328807 0354e3dc adba2619 
11:13:57 ipsec,debug === 
11:13:57 ipsec,debug encryption(aes-cbc) 
11:13:57 ipsec,debug hmac(sha1) 
11:13:57 ipsec,debug encklen=256 authklen=160 
11:13:57 ipsec,debug generating 640 bits of key (dupkeymat=4) 
11:13:57 ipsec,debug generating K1...K4 for KEYMAT. 
11:13:57 ipsec,debug 5602b92b b69152c7 b2f2eeee fe360dc7 c1004b14 e89daf81 7b7e35e6 14d0416f 
11:13:57 ipsec,debug 758ee426 da6b1cc6 a79c53ae b3cbcf07 26048c1c d926233b 50200547 c317bc2d 
11:13:57 ipsec,debug 66fed9fa b00d9b0b 88397c7b b16aae1f 
11:13:57 ipsec,debug encryption(aes-cbc) 
11:13:57 ipsec,debug hmac(sha1) 
11:13:57 ipsec,debug encklen=256 authklen=160 
11:13:57 ipsec,debug generating 640 bits of key (dupkeymat=4) 
11:13:57 ipsec,debug generating K1...K4 for KEYMAT. 
11:13:57 ipsec,debug b000cc2e 00540909 190f9eaa 7db29751 4cc19799 dc614c3a ed7870c5 153e0562 
11:13:57 ipsec,debug ff63aadd e2519f01 b978ca87 f7dce4f5 9f857e55 b9029f02 ea55b0cd 223dc8c1 
11:13:57 ipsec,debug 4c2654a4 72fca614 14d4dff0 c9b99e46 
11:13:57 ipsec,debug KEYMAT computed. 
11:13:57 ipsec,debug call pk_sendupdate 
11:13:57 ipsec,debug encryption(aes-cbc) 
11:13:57 ipsec,debug hmac(sha1) 
11:13:57 ipsec,debug call pfkey_send_update_nat 
11:13:57 ipsec IPsec-SA established: ESP/Transport my.pubip.1[4500]->10.106.74.190[4500] spi=0x412b050 
11:13:57 ipsec,debug pfkey update sent. 
11:13:57 ipsec,debug encryption(aes-cbc) 
11:13:57 ipsec,debug hmac(sha1) 
11:13:57 ipsec,debug call pfkey_send_add_nat 
11:13:57 ipsec IPsec-SA established: ESP/Transport 10.106.74.190[4500]->my.pubip.1[4500] spi=0xbd067f70 
11:13:57 ipsec,debug pfkey add sent. 
11:13:57 ipsec,debug ===== received 76 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:13:57 ipsec,debug receive Information. 
11:13:57 ipsec,debug hash(sha1) 
11:13:57 ipsec,debug hash validated. 
11:13:57 ipsec,debug begin. 
11:13:57 ipsec,debug seen nptype=8(hash) len=24 
11:13:57 ipsec,debug seen nptype=12(delete) len=16 
11:13:57 ipsec,debug succeed. 
11:13:57 ipsec,debug my.pubip.1 delete payload for protocol ESP 
11:13:57 ipsec purged IPsec-SA proto_id=ESP spi=0x7bf9418c 
11:13:57 ipsec purged IPsec-SA proto_id=ESP spi=0xd9205e0 
11:13:57 ipsec,debug purged SAs. 
11:13:58 ipsec,debug KA: 10.106.74.190[4500]->my.pubip.1[4500] 
11:13:58 ipsec,debug 1 times of 1 bytes message will be sent to my.pubip.1[4500] 
11:14:05 ipsec,debug ===== received 444 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:14:05 ipsec,debug hash(sha1) 
11:14:05 ipsec,debug === 
11:14:05 ipsec respond new phase 2 negotiation: 10.106.74.190[4500]<=>my.pubip.1[4500] 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=8(hash) len=24 
11:14:05 ipsec,debug seen nptype=1(sa) len=280 
11:14:05 ipsec,debug seen nptype=10(nonce) len=52 
11:14:05 ipsec,debug seen nptype=5(id) len=12 
11:14:05 ipsec,debug seen nptype=5(id) len=12 
11:14:05 ipsec,debug seen nptype=21(nat-oa) len=12 
11:14:05 ipsec,debug seen nptype=21(nat-oa) len=12 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug received IDci2: 
11:14:05 ipsec,debug 011106a5 0a0101dc 
11:14:05 ipsec,debug received IDcr2: 
11:14:05 ipsec,debug 011106a5 891a6c9a 
11:14:05 ipsec,debug HASH(1) validate: 
11:14:05 ipsec,debug 17452fef 2bf3b505 2892a701 22b66955 b6f3c8e0 
11:14:05 ipsec,debug total SA len=276 
11:14:05 ipsec,debug 00000001 00000001 02000038 01030401 8114ef96 0000002c 010c0000 80040004 
11:14:05 ipsec,debug 80060100 80050002 80010001 00020004 00000e10 80010002 00020004 0003d090 
11:14:05 ipsec,debug 02000038 02030401 8114ef96 0000002c 010c0000 80040004 80060080 80050002 
11:14:05 ipsec,debug 80010001 00020004 00000e10 80010002 00020004 0003d090 02000034 03030401 
11:14:05 ipsec,debug 8114ef96 00000028 01030000 80040004 80050002 80010001 00020004 00000e10 
11:14:05 ipsec,debug 80010002 00020004 0003d090 02000034 04030401 8114ef96 00000028 01020000 
11:14:05 ipsec,debug 80040004 80050002 80010001 00020004 00000e10 80010002 00020004 0003d090 
11:14:05 ipsec,debug 00000034 05030401 8114ef96 00000028 010b0000 80040004 80050002 80010001 
11:14:05 ipsec,debug 00020004 00000e10 80010002 00020004 0003d090 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=2(prop) len=56 
11:14:05 ipsec,debug seen nptype=2(prop) len=56 
11:14:05 ipsec,debug seen nptype=2(prop) len=52 
11:14:05 ipsec,debug seen nptype=2(prop) len=52 
11:14:05 ipsec,debug seen nptype=2(prop) len=52 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug proposal #1 len=56 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=3(trns) len=44 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug transform #1 len=44 
11:14:05 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:05 ipsec,debug UDP encapsulation requested 
11:14:05 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
11:14:05 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug proposal #2 len=56 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=3(trns) len=44 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug transform #1 len=44 
11:14:05 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:05 ipsec,debug UDP encapsulation requested 
11:14:05 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
11:14:05 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug proposal #3 len=52 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=3(trns) len=40 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug transform #1 len=40 
11:14:05 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:05 ipsec,debug UDP encapsulation requested 
11:14:05 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug proposal #4 len=52 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=3(trns) len=40 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug transform #1 len=40 
11:14:05 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:05 ipsec,debug UDP encapsulation requested 
11:14:05 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug proposal #5 len=52 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=3(trns) len=40 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug transform #1 len=40 
11:14:05 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:05 ipsec,debug UDP encapsulation requested 
11:14:05 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug pair 1: 
11:14:05 ipsec,debug  0x9bfd0: next=(nil) tnext=(nil) 
11:14:05 ipsec,debug proposal #1: 1 transform 
11:14:05 ipsec,debug pair 2: 
11:14:05 ipsec,debug  0x9cfd8: next=(nil) tnext=(nil) 
11:14:05 ipsec,debug proposal #2: 1 transform 
11:14:05 ipsec,debug pair 3: 
11:14:05 ipsec,debug  0x9aae0: next=(nil) tnext=(nil) 
11:14:05 ipsec,debug proposal #3: 1 transform 
11:14:05 ipsec,debug pair 4: 
11:14:05 ipsec,debug  0x9c000: next=(nil) tnext=(nil) 
11:14:05 ipsec,debug proposal #4: 1 transform 
11:14:05 ipsec,debug pair 5: 
11:14:05 ipsec,debug  0x95248: next=(nil) tnext=(nil) 
11:14:05 ipsec,debug proposal #5: 1 transform 
11:14:05 ipsec,debug got the local address from ID payload pub.ip.1[1701] prefixlen=32 ul_proto=17 
11:14:05 ipsec,debug got the peer address from ID payload 10.1.1.220[1701] prefixlen=32 ul_proto=17 
11:14:05 ipsec,debug updating policy address because of NAT in transport mode 
11:14:05 ipsec,debug new local address 10.106.74.190[1701] 
11:14:05 ipsec,debug new peer address my.pubip.1[1701] 
11:14:05 ipsec searching for policy for selector: 10.106.74.190:1701 ip-proto:17 <=> my.pubip.1:1701 ip-proto:17 
11:14:05 ipsec using strict match: 10.106.74.190:1701 <=> my.pubip.1:1701 ip-proto:17 
11:14:05 ipsec,debug  (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=UDP-Transport reqid=2:2) 
11:14:05 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
11:14:05 ipsec,debug   (trns_id=AES-CBC encklen=192 authtype=hmac-sha1) 
11:14:05 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-sha1) 
11:14:05 ipsec,debug begin compare proposals. 
11:14:05 ipsec,debug pair[1]: 0x9bfd0 
11:14:05 ipsec,debug  0x9bfd0: next=(nil) tnext=(nil) 
11:14:05 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=1 trns#=1 trns-id=AES-CBC 
11:14:05 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:05 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
11:14:05 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug peer's single bundle: 
11:14:05 ipsec,debug  (proto_id=ESP spisize=4 spi=8114ef96 spi_p=00000000 encmode=UDP-Transport reqid=0:0) 
11:14:05 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
11:14:05 ipsec,debug my single bundle: 
11:14:05 ipsec,debug  (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=UDP-Transport reqid=2:2) 
11:14:05 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
11:14:05 ipsec,debug   (trns_id=AES-CBC encklen=192 authtype=hmac-sha1) 
11:14:05 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-sha1) 
11:14:05 ipsec Adjusting my encmode UDP-Transport->Transport 
11:14:05 ipsec Adjusting peer's encmode UDP-Transport(4)->Transport(2) 
11:14:05 ipsec,debug matched 
11:14:05 ipsec,debug === 
11:14:05 ipsec,debug call pfkey_send_getspi e 
11:14:05 ipsec,debug pfkey GETSPI sent: ESP/Transport my.pubip.1[4500]->10.106.74.190[4500]  
11:14:05 ipsec,debug pfkey getspi sent. 
11:14:05 ipsec,debug total SA len=64 
11:14:05 ipsec,debug 00000001 00000001 00000038 01030401 00000000 0000002c 010c0000 80040004 
11:14:05 ipsec,debug 80060100 80050002 80010001 00020004 00000e10 80010002 00020004 0003d090 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=2(prop) len=56 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug proposal #1 len=56 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=3(trns) len=44 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug transform #1 len=44 
11:14:05 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:05 ipsec,debug UDP encapsulation requested 
11:14:05 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
11:14:05 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:05 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:05 ipsec,debug pair 1: 
11:14:05 ipsec,debug  0x9cfd8: next=(nil) tnext=(nil) 
11:14:05 ipsec,debug proposal #1: 1 transform 
11:14:05 ipsec,debug NAT-OAi: 
11:14:05 ipsec,debug 01000000 2fcbd3c6 
11:14:05 ipsec,debug NAT-OAr: 
11:14:05 ipsec,debug 01000000 0a6a4abe 
11:14:05 ipsec,debug add payload of len 64, next type 10 
11:14:05 ipsec,debug add payload of len 24, next type 5 
11:14:05 ipsec,debug add payload of len 8, next type 5 
11:14:05 ipsec,debug add payload of len 8, next type 21 
11:14:05 ipsec,debug add payload of len 8, next type 21 
11:14:05 ipsec,debug add payload of len 8, next type 0 
11:14:05 ipsec,debug add payload of len 20, next type 1 
11:14:05 ipsec,debug 204 bytes from 10.106.74.190[4500] to my.pubip.1[4500] 
11:14:05 ipsec,debug 1 times of 208 bytes message will be sent to my.pubip.1[4500] 
11:14:05 ipsec sent phase2 packet 10.106.74.190[4500]<=>my.pubip.1[4500] c665fcbaa0443214:c73cd15ef6ef5f66:00000000 
11:14:05 ipsec,debug ===== received 60 bytes from my.pubip.1[4500] to 10.106.74.190[4500]
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=8(hash) len=24 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug HASH(3) validate: 
11:14:05 ipsec,debug 82356c07 5da97c30 569e4c47 0c2e8698 27926c28 
11:14:05 ipsec,debug === 
11:14:05 ipsec,debug encryption(aes-cbc) 
11:14:05 ipsec,debug hmac(sha1) 
11:14:05 ipsec,debug encklen=256 authklen=160 
11:14:05 ipsec,debug generating 640 bits of key (dupkeymat=4) 
11:14:05 ipsec,debug generating K1...K4 for KEYMAT. 
11:14:05 ipsec,debug 60ce0751 beab8f1d 18251469 e928c28b af3c8508 79820dee 66eb5561 8e7b4637 
11:14:05 ipsec,debug c311b03b de9b1ece c61cfb26 62e834e9 4860be56 7f20cfaa c78defe3 007506a8 
11:14:05 ipsec,debug 4b1cd526 b0c310e9 f66713a3 35e5fa8a 
11:14:05 ipsec,debug encryption(aes-cbc) 
11:14:05 ipsec,debug hmac(sha1) 
11:14:05 ipsec,debug encklen=256 authklen=160 
11:14:05 ipsec,debug generating 640 bits of key (dupkeymat=4) 
11:14:05 ipsec,debug generating K1...K4 for KEYMAT. 
11:14:05 ipsec,debug 981b625c bf39653c 55bb7059 d3edf980 39f002b3 9293855a 49a0ce44 e75d4d89 
11:14:05 ipsec,debug 5b3c08a2 b0ac0755 d386ad61 163e1d34 8661b8c3 f83ad355 ac2be5f3 38bae301 
11:14:05 ipsec,debug a68b8e67 751d4c05 07925311 0d29b998 
11:14:05 ipsec,debug KEYMAT computed. 
11:14:05 ipsec,debug call pk_sendupdate 
11:14:05 ipsec,debug encryption(aes-cbc) 
11:14:05 ipsec,debug hmac(sha1) 
11:14:05 ipsec,debug call pfkey_send_update_nat 
11:14:05 ipsec IPsec-SA established: ESP/Transport my.pubip.1[4500]->10.106.74.190[4500] spi=0x979a457 
11:14:05 ipsec,debug pfkey update sent. 
11:14:05 ipsec,debug encryption(aes-cbc) 
11:14:05 ipsec,debug hmac(sha1) 
11:14:05 ipsec,debug call pfkey_send_add_nat 
11:14:05 ipsec IPsec-SA established: ESP/Transport 10.106.74.190[4500]->my.pubip.1[4500] spi=0x8114ef96 
11:14:05 ipsec,debug pfkey add sent. 
11:14:05 ipsec,debug ===== received 76 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:14:05 ipsec,debug receive Information. 
11:14:05 ipsec,debug hash(sha1) 
11:14:05 ipsec,debug hash validated. 
11:14:05 ipsec,debug begin. 
11:14:05 ipsec,debug seen nptype=8(hash) len=24 
11:14:05 ipsec,debug seen nptype=12(delete) len=16 
11:14:05 ipsec,debug succeed. 
11:14:05 ipsec,debug my.pubip.1 delete payload for protocol ESP 
11:14:05 ipsec purged IPsec-SA proto_id=ESP spi=0xbd067f70 
11:14:05 ipsec purged IPsec-SA proto_id=ESP spi=0x412b050 
11:14:05 ipsec,debug purged SAs.
11:14:15 ipsec,debug ===== received 444 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:14:15 ipsec,debug hash(sha1) 
11:14:15 ipsec,debug === 
11:14:15 ipsec respond new phase 2 negotiation: 10.106.74.190[4500]<=>my.pubip.1[4500] 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=8(hash) len=24 
11:14:15 ipsec,debug seen nptype=1(sa) len=280 
11:14:15 ipsec,debug seen nptype=10(nonce) len=52 
11:14:15 ipsec,debug seen nptype=5(id) len=12 
11:14:15 ipsec,debug seen nptype=5(id) len=12 
11:14:15 ipsec,debug seen nptype=21(nat-oa) len=12 
11:14:15 ipsec,debug seen nptype=21(nat-oa) len=12 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug received IDci2: 
11:14:15 ipsec,debug 011106a5 0a0101dc 
11:14:15 ipsec,debug received IDcr2: 
11:14:15 ipsec,debug 011106a5 891a6c9a 
11:14:15 ipsec,debug HASH(1) validate: 
11:14:15 ipsec,debug a4e8f7d8 7ea37f14 297f56fe 84fce31e 9b3ee64c 
11:14:15 ipsec,debug total SA len=276 
11:14:15 ipsec,debug 00000001 00000001 02000038 01030401 bb532692 0000002c 010c0000 80040004 
11:14:15 ipsec,debug 80060100 80050002 80010001 00020004 00000e10 80010002 00020004 0003d090 
11:14:15 ipsec,debug 02000038 02030401 bb532692 0000002c 010c0000 80040004 80060080 80050002 
11:14:15 ipsec,debug 80010001 00020004 00000e10 80010002 00020004 0003d090 02000034 03030401 
11:14:15 ipsec,debug bb532692 00000028 01030000 80040004 80050002 80010001 00020004 00000e10 
11:14:15 ipsec,debug 80010002 00020004 0003d090 02000034 04030401 bb532692 00000028 01020000 
11:14:15 ipsec,debug 80040004 80050002 80010001 00020004 00000e10 80010002 00020004 0003d090 
11:14:15 ipsec,debug 00000034 05030401 bb532692 00000028 010b0000 80040004 80050002 80010001 
11:14:15 ipsec,debug 00020004 00000e10 80010002 00020004 0003d090 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=2(prop) len=56 
11:14:15 ipsec,debug seen nptype=2(prop) len=56 
11:14:15 ipsec,debug seen nptype=2(prop) len=52 
11:14:15 ipsec,debug seen nptype=2(prop) len=52 
11:14:15 ipsec,debug seen nptype=2(prop) len=52 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug proposal #1 len=56 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=3(trns) len=44 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug transform #1 len=44 
11:14:15 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:15 ipsec,debug UDP encapsulation requested 
11:14:15 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
11:14:15 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug proposal #2 len=56 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=3(trns) len=44 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug transform #1 len=44 
11:14:15 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:15 ipsec,debug UDP encapsulation requested 
11:14:15 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
11:14:15 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug proposal #3 len=52 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=3(trns) len=40 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug transform #1 len=40 
11:14:15 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:15 ipsec,debug UDP encapsulation requested 
11:14:15 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug proposal #4 len=52 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=3(trns) len=40 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug transform #1 len=40 
11:14:15 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:15 ipsec,debug UDP encapsulation requested 
11:14:15 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug proposal #5 len=52 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=3(trns) len=40 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug transform #1 len=40 
11:14:15 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:15 ipsec,debug UDP encapsulation requested 
11:14:15 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug pair 1: 
11:14:15 ipsec,debug  0x9d5c8: next=(nil) tnext=(nil) 
11:14:15 ipsec,debug proposal #1: 1 transform 
11:14:15 ipsec,debug pair 2: 
11:14:15 ipsec,debug  0x9b028: next=(nil) tnext=(nil) 
11:14:15 ipsec,debug proposal #2: 1 transform 
11:14:15 ipsec,debug pair 3: 
11:14:15 ipsec,debug  0x9a620: next=(nil) tnext=(nil) 
11:14:15 ipsec,debug proposal #3: 1 transform 
11:14:15 ipsec,debug pair 4: 
11:14:15 ipsec,debug  0x9ab58: next=(nil) tnext=(nil) 
11:14:15 ipsec,debug proposal #4: 1 transform 
11:14:15 ipsec,debug pair 5: 
11:14:15 ipsec,debug  0x9ca40: next=(nil) tnext=(nil) 
11:14:15 ipsec,debug proposal #5: 1 transform 
11:14:15 ipsec,debug got the local address from ID payload pub.ip.1[1701] prefixlen=32 ul_proto=17 
11:14:15 ipsec,debug got the peer address from ID payload 10.1.1.220[1701] prefixlen=32 ul_proto=17 
11:14:15 ipsec,debug updating policy address because of NAT in transport mode 
11:14:15 ipsec,debug new local address 10.106.74.190[1701] 
11:14:15 ipsec,debug new peer address my.pubip.1[1701] 
11:14:15 ipsec searching for policy for selector: 10.106.74.190:1701 ip-proto:17 <=> my.pubip.1:1701 ip-proto:17 
11:14:15 ipsec using strict match: 10.106.74.190:1701 <=> my.pubip.1:1701 ip-proto:17 
11:14:15 ipsec,debug  (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=UDP-Transport reqid=2:2) 
11:14:15 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
11:14:15 ipsec,debug   (trns_id=AES-CBC encklen=192 authtype=hmac-sha1) 
11:14:15 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-sha1) 
11:14:15 ipsec,debug begin compare proposals. 
11:14:15 ipsec,debug pair[1]: 0x9d5c8 
11:14:15 ipsec,debug  0x9d5c8: next=(nil) tnext=(nil) 
11:14:15 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=1 trns#=1 trns-id=AES-CBC 
11:14:15 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:15 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
11:14:15 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug peer's single bundle: 
11:14:15 ipsec,debug  (proto_id=ESP spisize=4 spi=bb532692 spi_p=00000000 encmode=UDP-Transport reqid=0:0) 
11:14:15 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
11:14:15 ipsec,debug my single bundle: 
11:14:15 ipsec,debug  (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=UDP-Transport reqid=2:2) 
11:14:15 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
11:14:15 ipsec,debug   (trns_id=AES-CBC encklen=192 authtype=hmac-sha1) 
11:14:15 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-sha1) 
11:14:15 ipsec Adjusting my encmode UDP-Transport->Transport 
11:14:15 ipsec Adjusting peer's encmode UDP-Transport(4)->Transport(2) 
11:14:15 ipsec,debug matched 
11:14:15 ipsec,debug === 
11:14:15 ipsec,debug call pfkey_send_getspi f 
11:14:15 ipsec,debug pfkey GETSPI sent: ESP/Transport my.pubip.1[4500]->10.106.74.190[4500]  
11:14:15 ipsec,debug pfkey getspi sent. 
11:14:15 ipsec,debug total SA len=64 
11:14:15 ipsec,debug 00000001 00000001 00000038 01030401 00000000 0000002c 010c0000 80040004 
11:14:15 ipsec,debug 80060100 80050002 80010001 00020004 00000e10 80010002 00020004 0003d090 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=2(prop) len=56 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug proposal #1 len=56 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=3(trns) len=44 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug transform #1 len=44 
11:14:15 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
11:14:15 ipsec,debug UDP encapsulation requested 
11:14:15 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
11:14:15 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug type=SA Life Type, flag=0x8000, lorv=kilobytes 
11:14:15 ipsec,debug type=SA Life Duration, flag=0x0000, lorv=4 
11:14:15 ipsec,debug pair 1: 
11:14:15 ipsec,debug  0x9c918: next=(nil) tnext=(nil) 
11:14:15 ipsec,debug proposal #1: 1 transform 
11:14:15 ipsec,debug NAT-OAi: 
11:14:15 ipsec,debug 01000000 2fcbd3c6 
11:14:15 ipsec,debug NAT-OAr: 
11:14:15 ipsec,debug 01000000 0a6a4abe 
11:14:15 ipsec,debug add payload of len 64, next type 10 
11:14:15 ipsec,debug add payload of len 24, next type 5 
11:14:15 ipsec,debug add payload of len 8, next type 5 
11:14:15 ipsec,debug add payload of len 8, next type 21 
11:14:15 ipsec,debug add payload of len 8, next type 21 
11:14:15 ipsec,debug add payload of len 8, next type 0 
11:14:15 ipsec,debug add payload of len 20, next type 1 
11:14:15 ipsec,debug 204 bytes from 10.106.74.190[4500] to my.pubip.1[4500] 
11:14:15 ipsec,debug 1 times of 208 bytes message will be sent to my.pubip.1[4500] 
11:14:15 ipsec sent phase2 packet 10.106.74.190[4500]<=>my.pubip.1[4500] c665fcbaa0443214:c73cd15ef6ef5f66:00000000 
11:14:15 ipsec,debug ===== received 60 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=8(hash) len=24 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug HASH(3) validate: 
11:14:15 ipsec,debug 2d4e583d dbf15aa9 bb306c68 e161b299 542931ce 
11:14:15 ipsec,debug === 
11:14:15 ipsec,debug encryption(aes-cbc) 
11:14:15 ipsec,debug hmac(sha1) 
11:14:15 ipsec,debug encklen=256 authklen=160 
11:14:15 ipsec,debug generating 640 bits of key (dupkeymat=4) 
11:14:15 ipsec,debug generating K1...K4 for KEYMAT. 
11:14:15 ipsec,debug fe8b72d2 0cc1d423 94cadb48 bdb5b591 c0ded494 84db0a91 aa5a1de6 fd8cd76a 
11:14:15 ipsec,debug cce9148b ee14776d 504a965b 044d2f28 4a1784cb f5bd0693 79fa2861 7f3c6d83 
11:14:15 ipsec,debug 690231be e72a4fc0 7211ff39 1c0921db 
11:14:15 ipsec,debug encryption(aes-cbc) 
11:14:15 ipsec,debug hmac(sha1) 
11:14:15 ipsec,debug encklen=256 authklen=160 
11:14:15 ipsec,debug generating 640 bits of key (dupkeymat=4) 
11:14:15 ipsec,debug generating K1...K4 for KEYMAT. 
11:14:15 ipsec,debug 8bd9a17b 5c1813cf 4f08799e cc1face4 21c36e20 7cfea2d5 5396dcc9 aa0b0ff2 
11:14:15 ipsec,debug b7c8ff66 4a28e6db 12c74962 ee8201e8 f2303131 122915fb 571629e5 8f045b28 
11:14:15 ipsec,debug b7d56c54 84bcd932 f73ce960 4e181b21 
11:14:15 ipsec,debug KEYMAT computed. 
11:14:15 ipsec,debug call pk_sendupdate 
11:14:15 ipsec,debug encryption(aes-cbc) 
11:14:15 ipsec,debug hmac(sha1) 
11:14:15 ipsec,debug call pfkey_send_update_nat 
11:14:15 ipsec IPsec-SA established: ESP/Transport my.pubip.1[4500]->10.106.74.190[4500] spi=0x26f0c47 
11:14:15 ipsec,debug pfkey update sent. 
11:14:15 ipsec,debug encryption(aes-cbc) 
11:14:15 ipsec,debug hmac(sha1) 
11:14:15 ipsec,debug call pfkey_send_add_nat 
11:14:15 ipsec IPsec-SA established: ESP/Transport 10.106.74.190[4500]->my.pubip.1[4500] spi=0xbb532692 
11:14:15 ipsec,debug pfkey add sent. 
11:14:15 ipsec,debug ===== received 76 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:14:15 ipsec,debug receive Information. 
11:14:15 ipsec,debug hash(sha1) 
11:14:15 ipsec,debug hash validated. 
11:14:15 ipsec,debug begin. 
11:14:15 ipsec,debug seen nptype=8(hash) len=24 
11:14:15 ipsec,debug seen nptype=12(delete) len=16 
11:14:15 ipsec,debug succeed. 
11:14:15 ipsec,debug my.pubip.1 delete payload for protocol ESP 
11:14:15 ipsec purged IPsec-SA proto_id=ESP spi=0x8114ef96 
11:14:15 ipsec purged IPsec-SA proto_id=ESP spi=0x979a457 
11:14:15 ipsec,debug purged SAs. 
11:14:18 ipsec,debug KA: 10.106.74.190[4500]->my.pubip.1[4500] 
11:14:18 ipsec,debug 1 times of 1 bytes message will be sent to my.pubip.1[4500] 
11:14:25 ipsec,debug ===== received 76 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:14:25 ipsec,debug receive Information. 
11:14:25 ipsec,debug hash(sha1) 
11:14:25 ipsec,debug hash validated. 
11:14:25 ipsec,debug begin. 
11:14:25 ipsec,debug seen nptype=8(hash) len=24 
11:14:25 ipsec,debug seen nptype=12(delete) len=16 
11:14:25 ipsec,debug succeed. 
11:14:25 ipsec,debug my.pubip.1 delete payload for protocol ESP 
11:14:25 ipsec purged IPsec-SA proto_id=ESP spi=0xbb532692 
11:14:25 ipsec purged IPsec-SA proto_id=ESP spi=0x26f0c47 
11:14:25 ipsec removing generated policy 
11:14:25 ipsec,debug purged SAs. 
11:14:25 ipsec,debug ===== received 92 bytes from my.pubip.1[4500] to 10.106.74.190[4500] 
11:14:25 ipsec,debug receive Information. 
11:14:25 ipsec,debug hash(sha1) 
11:14:25 ipsec,debug hash validated. 
11:14:25 ipsec,debug begin. 
11:14:25 ipsec,debug seen nptype=8(hash) len=24 
11:14:25 ipsec,debug seen nptype=12(delete) len=28 
11:14:25 ipsec,debug succeed. 
11:14:25 ipsec,debug my.pubip.1 delete payload for protocol ISAKMP 
11:14:25 ipsec,info purging ISAKMP-SA 10.106.74.190[4500]<=>my.pubip.1[4500] spi=c665fcbaa0443214:c73cd15ef6ef5f66. 
11:14:25 ipsec purged ISAKMP-SA 10.106.74.190[4500]<=>my.pubip.1[4500] spi=c665fcbaa0443214:c73cd15ef6ef5f66. 
11:14:25 ipsec,debug purged SAs. 
11:14:25 ipsec,info ISAKMP-SA deleted 10.106.74.190[4500]-my.pubip.1[4500] spi:c665fcbaa0443214:c73cd15ef6ef5f66 rekey:1 
11:14:25 ipsec KA remove: 10.106.74.190[4500]->my.pubip.1[4500] 
11:14:25 ipsec,debug KA tree dump: 10.106.74.190[4500]->my.pubip.1[4500] (in_use=1) 
11:14:25 ipsec,debug KA removing this one...
Last edited by LinuxLarry on Sat Aug 28, 2021 2:52 am, edited 1 time in total.
 
sindy
Forum Guru
Forum Guru
Posts: 10206
Joined: Mon Dec 04, 2017 9:19 pm

Re: L2TP with private ip from DHCP Server Connection Problems

Fri Aug 27, 2021 8:26 pm

No signs of L2TP connection attempt in the log whatsoever. Show me the configuration export (see my signature regarding anonymisation), it must be something about the firewall.
 
sindy
Forum Guru
Forum Guru
Posts: 10206
Joined: Mon Dec 04, 2017 9:19 pm

Re: L2TP with private ip from DHCP Server Connection Problems

Fri Aug 27, 2021 8:51 pm

Oops, I was actually too fast. The initiator asks to delete the IPsec SA immediately after it has been established:

11:13:57 ipsec IPsec-SA established: ESP/Transport 10.106.74.190[4500]->my.pubip.1[4500] spi=0xbd067f70
11:13:57 ipsec,debug pfkey add sent.
11:13:57 ipsec,debug ===== received 76 bytes from my.pubip.1[4500] to 10.106.74.190[4500]
11:13:57 ipsec,debug receive Information.
11:13:57 ipsec,debug hash(sha1)
11:13:57 ipsec,debug hash validated.
11:13:57 ipsec,debug begin.
11:13:57 ipsec,debug seen nptype=8(hash) len=24
11:13:57 ipsec,debug seen nptype=12(delete) len=16
11:13:57 ipsec,debug succeed.
11:13:57 ipsec,debug my.pubip.1 delete payload for protocol ESP
11:13:57 ipsec purged IPsec-SA proto_id=ESP spi=0x7bf9418c
11:13:57 ipsec purged IPsec-SA proto_id=ESP spi=0xd9205e0
11:13:57 ipsec,debug purged SAs.

So what's the overall topology? Could it be that there is some routing shortcut between the client/initiator and the server/responder, or some unusual NAT, which causes the client to dislike the connection?
 
User avatar
LinuxLarry
just joined
Topic Author
Posts: 20
Joined: Fri Aug 10, 2018 9:31 pm
Location: Earth

Re: L2TP with private ip from DHCP Server Connection Problems

Fri Aug 27, 2021 10:53 pm

Hi,

I believe the problem is related to some natting somewhere or lack thereof but this is just a guess. I have verified that directly using a static or public ip address in the rb3011 the vpn works. I put the router behind a natted device and it fails pulling a private address and it fails.

modem > rb3011 it works as expected. The rb3011 has the static ip from the isp programmed into it then we had to change the configuration as follows

modem > pepwave > rb3011 the pepwave now holds the static ip that the rb3011 was using and the rb3011 is now using an dhcp client to get a private address from the pepwave.

In that later configuration l2tp no longer connect successfully. The vpn is used for customers to be able to access their stores to look at reports on the local machines. They range from MacOS and Windows users typically dialing in on the public ip to connect to the network.
 
sindy
Forum Guru
Forum Guru
Posts: 10206
Joined: Mon Dec 04, 2017 9:19 pm

Re: L2TP with private ip from DHCP Server Connection Problems

Sat Aug 28, 2021 12:00 am

I do understand that the issue started once you've moved the 3011 to a private address, however, you've taken a log from a connection attempt of just a single client that dislikes the IPsec connection as soon as it establishes. What made me cautious is that you've substituted the address of the client by my.public.ip.1, but you haven't substituted the public IP of the pepwave - this suggests that you use some unusual network arrangement for this test. But regardless that, if this test client was a Windows one, without the non-default setting in the registry making it tolerate the NAT at responder side, it is well possible that the Windows VPN client terminates the connection this nice way once it detects the NAT at the responder side, rather than just stopping to respond. I don't know how other clients than Windows and Mikrotik react on NAT at responder side.

So I'd really suggest you to implement the trick I've linked to in my first response - attach the public IP that is actually up on the pepwave (P.P.P.P) as a /32 one to a dedicated port-less bridge on the 3011, and use the following dst-nat rule:

chain=dstnat in-interface=the-wan-interface-name dst-address-type=local protocol=udp dst-port=500,4500 action=dst-nat to-addresses=P.P.P.P

Doing so will hide the NAT at the 3011 end from the clients. I can see that there is a NAT also on the client end so the NAT-T mode will be negotiated anyway, so no need to bother about forwarding ESP through the pepwave.
 
User avatar
LinuxLarry
just joined
Topic Author
Posts: 20
Joined: Fri Aug 10, 2018 9:31 pm
Location: Earth

Re: L2TP with private ip from DHCP Server Connection Problems

Sat Aug 28, 2021 3:03 am

I actually did not mean to leave their public address exposed. That was a mistake on my bad. There is no odd setup here its straight forward. a remote person using my.pubip.1 connects to a server pub.ip.1 and thats pretty much it. I am dumbfounded at the moment if mikrotik cant handle l2tp in this manner where the server is behind a natted router. Ill review that link again. i thought that was to resolve a problem with multi people trying to use the l2tp which in this case i dont have a need for that as it will be okay with just 1 person connected at time. maybe it is the windows setup and I need to use a 2 for the register setting instead of a 1.

I probably just dont understand the issue maybe. I am thankful for you looking through the logs and replying to my request for help.
 
sindy
Forum Guru
Forum Guru
Posts: 10206
Joined: Mon Dec 04, 2017 9:19 pm

Re: L2TP with private ip from DHCP Server Connection Problems

Sat Aug 28, 2021 8:26 am

There are two topics related to L2TP and NAT:
  • the one you have found on your own and linked in your OP, dealing with multiple clients at the same site, thus NATed to the same public IP as seen by the server
  • the one I've linked in my first response in this current thread, dealing with the server itself running on a private address.
The latter one requires much less extra configuration, and I have reworded those few configuration steps in brief in my previous post.

Of course those two setups can be merged if needed, but it doesn't seem to be necessary in your setup.
 
User avatar
LinuxLarry
just joined
Topic Author
Posts: 20
Joined: Fri Aug 10, 2018 9:31 pm
Location: Earth

Re: L2TP with private ip from DHCP Server Connection Problems

Sat Aug 28, 2021 7:12 pm

In my previous post I said maybe I should of used a 2 instead of a 1, this was the answer. I went back and adjusted the registry and I was able to connect successfully. This link was in the thread that you originally posted as well which im placing here in case anyone follows behind and reads this thread. Again thank you for the assistance.

http://woshub.com/l2tp-ipsec-vpn-server-behind/
 
sindy
Forum Guru
Forum Guru
Posts: 10206
Joined: Mon Dec 04, 2017 9:19 pm

Re: L2TP with private ip from DHCP Server Connection Problems

Sat Aug 28, 2021 7:45 pm

Glad that you've solved it. The reason why I keep recommending my solution with the dst-nat back to the public IP on the Mikrotik is that it is enough to implement this once on the Mikrotik, whereas the change of 1 to 2 in registry must be done on every single Windows client.

Who is online

Users browsing this forum: Bing [Bot], CryptoCurrencyDyday, K0NCTANT1N, triss and 75 guests