I’ve been working on this problem for many days and hours now and just can’t figure it out. Any pointers are very welcome.
Situation:
MikrotikGW[h.h.h.52/24]->[h.h.h.164/24]IntermediateGW[P.P.P.164]->Internet->[R.R.R.15]TerminalGW[192.168.1.0/24]
I need to establish a vpn from MikrotikGW to TerminalGW, which will presumably provision an IP-Address from the range 192.168.1.0/24, which I need to bridge to a separate port on the Mikrotik. The TerminalGW is not under my control and the only thing I know is to use l2tp over ipsec with psk (and they credential values).
Given is the IP-address of TerminalGW. Furthermore username and password for l2tp and the psk are known. Also known is that TerminaGW runs a dhcp-server, serving addresses from the range 192.168.1.0/24.
VPN works like a charm and right out of the box using any iOS-device or MacOS. But I have not figured out any solution at all using my MikroTik RB 750GL, running version 6.27, Firmware 3.22. From looking at the logs it seems phase 1 of ipsec succeeds, but phase2 never seems to kick in. Here is my configuration on the mikrotik:
[admin@mtgwsg] > /interface l2tp-client print
Flags: X - disabled, R - running
0 X name="remgw" max-mtu=1450 max-mru=1450 mrru=1600 connect-to=192.168.1.1 user="l2tpUser" password="l2tpPwd" profile=remgwProfile keepalive-timeout=60 add-default-route=no dial-on-demand=no
allow=pap,chap,mschap1,mschap2
[admin@mtgwsg] > /ppp profile print
Flags: * - default
0 * name="default" remote-ipv6-prefix-pool=none use-ipv6=yes use-mpls=default use-compression=default use-vj-compression=default use-encryption=default only-one=default change-tcp-mss=yes address-list=""
1 name="remgwProfile" remote-ipv6-prefix-pool=*0 use-ipv6=default use-mpls=no use-compression=default use-vj-compression=default use-encryption=required only-one=default change-tcp-mss=default
address-list=""
2 * name="default-encryption" remote-ipv6-prefix-pool=none use-ipv6=yes use-mpls=default use-compression=default use-vj-compression=default use-encryption=yes only-one=default change-tcp-mss=yes address-list=""
[admin@mtgwsg] > /ip ipsec policy print
Flags: T - template, X - disabled, D - dynamic, I - inactive, * - default
0 T * group=remgwGroup src-address=0.0.0.0/0 dst-address=0.0.0.0/0 protocol=udp proposal=remgwProposal template=yes
1 src-address=0.0.0.0/32 src-port=any dst-address=192.168.1.0/24 dst-port=1701 protocol=udp action=encrypt level=require ipsec-protocols=esp tunnel=yes sa-src-address=h.h.h.52 sa-dst-address=R.R.R.15 proposal=remgwProposal
priority=1
[admin@mtgwsg] > /ip ipsec peer print
Flags: X - disabled, D - dynamic
0 X address=R.R.R.15/32 local-address=0.0.0.0 passive=no port=500 auth-method=pre-shared-key secret="verySecret" generate-policy=port-override policy-template-group=remgwGroup exchange-mode=main-l2tp mode-config=remgwMode
send-initial-contact=yes nat-traversal=yes my-id=user-fqdn:P.P.P.164 hash-algorithm=sha1 enc-algorithm=aes-256 dh-group=modp1024 lifetime=1h dpd-interval=2m dpd-maximum-failures=5
[admin@mtgwsg] > /ip ipsec proposal print
Flags: X - disabled, * - default
0 * name="default" auth-algorithms=sha1 enc-algorithms=3des lifetime=30m pfs-group=modp1024
1 name="remgwProposal" auth-algorithms=sha1 enc-algorithms=aes-128-cbc,aes-256-cbc lifetime=1h pfs-group=none
[admin@mtgwsg] > /ip ipsec mode-config print
Flags: * - default
0 * name="request-only" send-dns=yes
1 name="remgwMode" send-dns=no
[admin@mtgwsg] >
First of all I wonder why a connection is immediately setup as soon as I activate the peer. As far as I understand this leads to a successful phase 1 connection. At this point it waits until I activate the l2tp client configuration.
What I see from the logs is:
— Start/Activation of ipsec peer configuration —
<13>1 2015-02-28T04:05:42.542734+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ===
<13>1 2015-02-28T04:05:42.542734+01:00 ipsec,debug IPSEC - - - IPSEC::: initiate new phase 1 negotiation: h.h.h.52[500]<=>R.R.R.15[500]
<13>1 2015-02-28T04:05:42.542836+01:00 ipsec,debug IPSEC - - - IPSEC::: begin Identity Protection mode.
— Deleted lines —
<13>1 2015-02-28T04:05:42.552711+01:00 ipsec,debug IPSEC - - - IPSEC::: sent phase1 packet h.h.h.52[500]<=>R.R.R.15[500] 1439b70d23fb9e40:0000000000000000
— Deleted lines —
<13>1 2015-02-28T04:05:42.617610+01:00 ipsec,debug IPSEC - - - IPSEC::: received Vendor ID: draft-ietf-ipsra-isakmp-xauth-06.txt
<13>1 2015-02-28T04:05:42.617895+01:00 ipsec,debug IPSEC - - - IPSEC::: received Vendor ID: DPD
<13>1 2015-02-28T04:05:42.618173+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: remote supports DPD
<13>1 2015-02-28T04:05:42.618461+01:00 ipsec,debug IPSEC - - - IPSEC::: received Vendor ID: RFC 3947
<13>1 2015-02-28T04:05:42.618691+01:00 ipsec,debug IPSEC - - - IPSEC::: Selected NAT-T version: RFC 3947
— Deleted lines —
<13>1 2015-02-28T04:05:42.730331+01:00 ipsec,debug IPSEC - - - IPSEC::: Hashing R.R.R.15[500] with algo #2
<13>1 2015-02-28T04:05:42.730602+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: hash(sha1)
<13>1 2015-02-28T04:05:42.730927+01:00 ipsec,debug IPSEC - - - IPSEC::: Hashing h.h.h.52[500] with algo #2
<13>1 2015-02-28T04:05:42.731163+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: hash(sha1)
<13>1 2015-02-28T04:05:42.731410+01:00 ipsec,debug IPSEC - - - IPSEC::: Adding remote and local NAT-D payloads.
— Deleted lines —
<13>1 2015-02-28T04:05:42.737127+01:00 ipsec,debug IPSEC - - - IPSEC::: sent phase1 packet h.h.h.52[500]<=>R.R.R.15[500] 1439b70d23fb9e40:fec2c31c4406d7f4
<13>1 2015-02-28T04:05:42.826198+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ==========
— Deleted lines —
<13>1 2015-02-28T04:05:42.839134+01:00 ipsec,debug IPSEC - - - IPSEC::: Hashing h.h.h.52[500] with algo #2
<13>1 2015-02-28T04:05:42.839386+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: hash(sha1)
<13>1 2015-02-28T04:05:42.839637+01:00 ipsec,debug IPSEC - - - IPSEC::: NAT-D payload #0 doesn’t match
<13>1 2015-02-28T04:05:42.839925+01:00 ipsec,debug IPSEC - - - IPSEC::: Hashing R.R.R.15[500] with algo #2
<13>1 2015-02-28T04:05:42.840219+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: hash(sha1)
<13>1 2015-02-28T04:05:42.840476+01:00 ipsec,debug IPSEC - - - IPSEC::: NAT-D payload #1 doesn’t match
<13>1 2015-02-28T04:05:42.840739+01:00 ipsec,debug IPSEC - - - IPSEC::: NAT detected: ME PEER
<13>1 2015-02-28T04:05:42.841021+01:00 ipsec,debug IPSEC - - - IPSEC::: KA list add: h.h.h.52[4500]->R.R.R.15[4500]
<13>1 2015-02-28T04:05:42.841321+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ===
<13>1 2015-02-28T04:05:42.932600+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: compute DH’s shared.
— Deleted lines —
<13>1 2015-02-28T04:05:42.975370+01:00 ipsec,debug IPSEC - - - IPSEC::: sent phase1 packet h.h.h.52[4500]<=>R.R.R.15[4500] 1439b70d23fb9e40:fec2c31c4406d7f4
<13>1 2015-02-28T04:05:42.985018+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ==========
— Deleted lines —
<13>1 2015-02-28T04:05:43.000007+01:00 ipsec,debug IPSEC - - - IPSEC::: No ID match.
— Deleted lines —
<13>1 2015-02-28T04:05:43.008232+01:00 ipsec,debug IPSEC - - - IPSEC::: ISAKMP-SA established h.h.h.52[4500]-R.R.R.15[4500] spi:1439b70d23fb9e40:fec2c31c4406d7f4
<13>1 2015-02-28T04:05:43.008495+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ===
<13>1 2015-02-28T04:05:44.272044+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: KA: h.h.h.52[4500]->R.R.R.15[4500]
<13>1 2015-02-28T04:05:44.272044+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: sockname h.h.h.52[4500]
<13>1 2015-02-28T04:05:44.272128+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet from h.h.h.52[4500]
<13>1 2015-02-28T04:05:44.272128+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet to R.R.R.15[4500]
<13>1 2015-02-28T04:05:44.272166+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: src4 h.h.h.52[4500]
<13>1 2015-02-28T04:05:44.272427+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: dst4 R.R.R.15[4500]
<13>1 2015-02-28T04:05:44.272736+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 1 times of 1 bytes message will be sent to R.R.R.15[4500]
<13>1 2015-02-28T04:05:44.273040+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ff
<13>1 2015-02-28T04:06:04.274761+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: KA: h.h.h.52[4500]->R.R.R.15[4500]
<13>1 2015-02-28T04:06:04.274761+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: sockname h.h.h.52[4500]
<13>1 2015-02-28T04:06:04.274875+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet from h.h.h.52[4500]
<13>1 2015-02-28T04:06:04.274875+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet to R.R.R.15[4500]
<13>1 2015-02-28T04:06:04.274926+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: src4 h.h.h.52[4500]
<13>1 2015-02-28T04:06:04.275204+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: dst4 R.R.R.15[4500]
<13>1 2015-02-28T04:06:04.275580+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 1 times of 1 bytes message will be sent to R.R.R.15[4500]
<13>1 2015-02-28T04:06:04.275580+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ff— start/activate l2tp client configuration —
<13>1 2015-02-28T04:06:09.911238+01:00 l2tp,ppp,info L2TP - - - L2TP::: stargate: initializing…
<13>1 2015-02-28T04:06:09.912044+01:00 l2tp,ppp,info L2TP - - - L2TP::: stargate: connecting…
<13>1 2015-02-28T04:06:09.914878+01:00 l2tp,debug L2TP - - - L2TP::: tunnel 1 entering state: wait-ctl-reply
<13>1 2015-02-28T04:06:09.915194+01:00 l2tp,debug,packet L2TP - - - L2TP::: sent control message to 192.168.1.1:1701
<13>1 2015-02-28T04:06:09.915527+01:00 l2tp,debug,packet L2TP - - - L2TP::: tunnel-id=0, session-id=0, ns=0, nr=0
<13>1 2015-02-28T04:06:09.915751+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Message-Type=SCCRQ
<13>1 2015-02-28T04:06:09.916036+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Protocol-Version=0x01:00
<13>1 2015-02-28T04:06:09.916293+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Framing-Capabilities=0x1
<13>1 2015-02-28T04:06:09.916576+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Bearer-Capabilities=0x0
<13>1 2015-02-28T04:06:09.916834+01:00 l2tp,debug,packet L2TP - - - L2TP::: Firmware-Revision=0x1
<13>1 2015-02-28T04:06:09.917116+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Host-Name=“mtgwsg”
<13>1 2015-02-28T04:06:09.917359+01:00 l2tp,debug,packet L2TP - - - L2TP::: Vendor-Name=“MikroTik”
<13>1 2015-02-28T04:06:09.917642+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Assigned-Tunnel-ID=1
<13>1 2015-02-28T04:06:09.917919+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Receive-Window-Size=4
<13>1 2015-02-28T04:06:10.918055+01:00 l2tp,debug,packet L2TP - - - L2TP::: sent control message to 192.168.1.1:1701
<13>1 2015-02-28T04:06:10.918055+01:00 l2tp,debug,packet L2TP - - - L2TP::: tunnel-id=0, session-id=0, ns=0, nr=0
<13>1 2015-02-28T04:06:10.918468+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Message-Type=SCCRQ
<13>1 2015-02-28T04:06:10.918468+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Protocol-Version=0x01:00
<13>1 2015-02-28T04:06:10.918919+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Framing-Capabilities=0x1
<13>1 2015-02-28T04:06:10.918919+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Bearer-Capabilities=0x0
<13>1 2015-02-28T04:06:10.919312+01:00 l2tp,debug,packet L2TP - - - L2TP::: Firmware-Revision=0x1
<13>1 2015-02-28T04:06:10.919312+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Host-Name=“mtgwsg”
<13>1 2015-02-28T04:06:10.919758+01:00 l2tp,debug,packet L2TP - - - L2TP::: Vendor-Name=“MikroTik”
<13>1 2015-02-28T04:06:10.919758+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Assigned-Tunnel-ID=1
<13>1 2015-02-28T04:06:10.920182+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Receive-Window-Size=4
— Deleted lines —
<13>1 2015-02-28T04:06:24.266153+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: KA: h.h.h.52[4500]->R.R.R.15[4500]
<13>1 2015-02-28T04:06:24.266153+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: sockname h.h.h.52[4500]
<13>1 2015-02-28T04:06:24.266241+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet from h.h.h.52[4500]
<13>1 2015-02-28T04:06:24.266241+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet to R.R.R.15[4500]
<13>1 2015-02-28T04:06:24.266389+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: src4 h.h.h.52[4500]
<13>1 2015-02-28T04:06:24.266600+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: dst4 R.R.R.15[4500]
<13>1 2015-02-28T04:06:24.266957+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 1 times of 1 bytes message will be sent to R.R.R.15[4500]
<13>1 2015-02-28T04:06:24.267193+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ff
<13>1 2015-02-28T04:06:25.935129+01:00 l2tp,debug,packet L2TP - - - L2TP::: sent control message to 192.168.1.1:1701
<13>1 2015-02-28T04:06:25.935129+01:00 l2tp,debug,packet L2TP - - - L2TP::: tunnel-id=0, session-id=0, ns=0, nr=0
<13>1 2015-02-28T04:06:25.935515+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Message-Type=SCCRQ
<13>1 2015-02-28T04:06:25.935515+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Protocol-Version=0x01:00
<13>1 2015-02-28T04:06:25.935963+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Framing-Capabilities=0x1
<13>1 2015-02-28T04:06:25.935963+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Bearer-Capabilities=0x0
<13>1 2015-02-28T04:06:25.936317+01:00 l2tp,debug,packet L2TP - - - L2TP::: Firmware-Revision=0x1
<13>1 2015-02-28T04:06:25.936317+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Host-Name=“mtgwsg”
<13>1 2015-02-28T04:06:25.936783+01:00 l2tp,debug,packet L2TP - - - L2TP::: Vendor-Name=“MikroTik”
<13>1 2015-02-28T04:06:25.936783+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Assigned-Tunnel-ID=1
<13>1 2015-02-28T04:06:25.937199+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Receive-Window-Size=4
<13>1 2015-02-28T04:06:33.944806+01:00 l2tp,debug L2TP - - - L2TP::: tunnel 1 received no replies, disconnecting
<13>1 2015-02-28T04:06:33.944806+01:00 l2tp,debug L2TP - - - L2TP::: tunnel 1 entering state: dead
<13>1 2015-02-28T04:06:33.944924+01:00 l2tp,debug L2TP - - - L2TP::: session 1 entering state: dead
<13>1 2015-02-28T04:06:33.944924+01:00 l2tp,ppp,info L2TP - - - L2TP::: stargate: terminating… - session closed
<13>1 2015-02-28T04:06:33.945040+01:00 l2tp,ppp,debug L2TP - - - L2TP::: stargate: LCP lowerdown
<13>1 2015-02-28T04:06:33.945292+01:00 l2tp,ppp,debug L2TP - - - L2TP::: stargate: LCP down event in initial state
<13>1 2015-02-28T04:06:33.945601+01:00 l2tp,ppp,info L2TP - - - L2TP::: stargate: disconnected
<13>1 2015-02-28T04:06:33.946051+01:00 l2tp,ppp,info L2TP - - - L2TP::: stargate: initializing…
<13>1 2015-02-28T04:06:33.946051+01:00 l2tp,ppp,info L2TP - - - L2TP::: stargate: connecting…
<13>1 2015-02-28T04:06:33.946546+01:00 l2tp,ppp,info L2TP - - - L2TP::: stargate: terminating… - old tunnel is not closed yet
<13>1 2015-02-28T04:06:33.946827+01:00 l2tp,ppp,debug L2TP - - - L2TP::: stargate: LCP lowerdown
<13>1 2015-02-28T04:06:33.947136+01:00 l2tp,ppp,debug L2TP - - - L2TP::: stargate: LCP down event in initial state
<13>1 2015-02-28T04:06:33.947428+01:00 l2tp,ppp,info L2TP - - - L2TP::: stargate: disconnected
— Deleted lines —
<13>1 2015-02-28T04:06:41.479377+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: Removing PH1…
<13>1 2015-02-28T04:06:41.479377+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: compute IV for phase2
<13>1 2015-02-28T04:06:41.479455+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: phase1 last IV:
<13>1 2015-02-28T04:06:41.479455+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 3c9dbaa1 6155209a ccb69371 30477fc9 ef488dae
<13>1 2015-02-28T04:06:41.479496+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: hash(sha1)
<13>1 2015-02-28T04:06:41.479768+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: encryption(aes)
<13>1 2015-02-28T04:06:41.480112+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: phase2 IV computed:
<13>1 2015-02-28T04:06:41.480309+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 169e0f39 c1a6e2d4 2110ba7b 8cd13b15
<13>1 2015-02-28T04:06:41.480589+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: HASH with:
<13>1 2015-02-28T04:06:41.480882+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ef488dae 0000001c 00000001 01100001 1439b70d 23fb9e40 fec2c31c 4406d7f4
<13>1 2015-02-28T04:06:41.481235+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: hmac(hmac_sha1)
<13>1 2015-02-28T04:06:41.481235+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: HASH computed:
<13>1 2015-02-28T04:06:41.481716+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 218d9a09 1898dcfd 22cb7e66 966b4dcf 562fe1ff
<13>1 2015-02-28T04:06:41.481974+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: begin encryption.
<13>1 2015-02-28T04:06:41.482279+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: encryption(aes)
<13>1 2015-02-28T04:06:41.482534+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: pad length = 12
<13>1 2015-02-28T04:06:41.482917+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 0c000018 218d9a09 1898dcfd 22cb7e66 966b4dcf 562fe1ff 0000001c 00000001
<13>1 2015-02-28T04:06:41.483195+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 01100001 1439b70d 23fb9e40 fec2c31c 4406d7f4 f9a2db29 b887bdb4 e194c50b
<13>1 2015-02-28T04:06:41.483511+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: encryption(aes)
<13>1 2015-02-28T04:06:41.483759+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: with key:
<13>1 2015-02-28T04:06:41.484031+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: a4eae9d6 f315bef4 49b67068 a8488a60
<13>1 2015-02-28T04:06:41.484290+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: encrypted payload by IV:
<13>1 2015-02-28T04:06:41.484609+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 169e0f39 c1a6e2d4 2110ba7b 8cd13b15
<13>1 2015-02-28T04:06:41.484875+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: save IV for next:
<13>1 2015-02-28T04:06:41.485138+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: a3b76ec5 d55d7c32 e639dbfe c2d4418f
<13>1 2015-02-28T04:06:41.485400+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: encrypted.
<13>1 2015-02-28T04:06:41.485708+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: Adding NON-ESP marker
<13>1 2015-02-28T04:06:41.485994+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 96 bytes from h.h.h.52[4500] to R.R.R.15[4500]
<13>1 2015-02-28T04:06:41.486297+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: sockname h.h.h.52[4500]
<13>1 2015-02-28T04:06:41.486537+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet from h.h.h.52[4500]
<13>1 2015-02-28T04:06:41.486875+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet to R.R.R.15[4500]
<13>1 2015-02-28T04:06:41.487104+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: src4 h.h.h.52[4500]
<13>1 2015-02-28T04:06:41.487428+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: dst4 R.R.R.15[4500]
<13>1 2015-02-28T04:06:41.487676+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 1 times of 96 bytes message will be sent to R.R.R.15[4500]
<13>1 2015-02-28T04:06:41.487978+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 00000000 1439b70d 23fb9e40 fec2c31c 4406d7f4 08100501 ef488dae 0000005c
<13>1 2015-02-28T04:06:41.488256+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: fd3398bf c13b9176 df4ffafe 46854386 c29faec8 c9b77009 f6dc18b4 39064cda
<13>1 2015-02-28T04:06:41.488550+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 679327d3 abfc3158 fe138d8e f04fd300 a3b76ec5 d55d7c32 e639dbfe c2d4418f
<13>1 2015-02-28T04:06:41.488824+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: sendto Information delete.
<13>1 2015-02-28T04:06:41.489124+01:00 ipsec,debug IPSEC - - - IPSEC::: ISAKMP-SA deleted h.h.h.52[4500]-R.R.R.15[4500] spi:1439b70d23fb9e40:fec2c31c4406d7f4
<13>1 2015-02-28T04:06:41.489390+01:00 ipsec,debug IPSEC - - - IPSEC::: KA remove: h.h.h.52[4500]->R.R.R.15[4500]
<13>1 2015-02-28T04:06:41.489708+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: KA tree dump: h.h.h.52[4500]->R.R.R.15[4500] (in_use=1)
<13>1 2015-02-28T04:06:41.489939+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: KA removing this one…
<13>1 2015-02-28T04:06:41.490245+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: an undead schedule has been deleted.
<13>1 2015-02-28T04:06:42.185278+01:00 l2tp,debug,packet L2TP - - - L2TP::: sent control message to 192.168.1.1:1701
<13>1 2015-02-28T04:06:42.185278+01:00 l2tp,debug,packet L2TP - - - L2TP::: tunnel-id=0, session-id=0, ns=0, nr=0
<13>1 2015-02-28T04:06:42.185632+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Message-Type=SCCRQ
<13>1 2015-02-28T04:06:42.185632+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Protocol-Version=0x01:00
<13>1 2015-02-28T04:06:42.186021+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Framing-Capabilities=0x1
<13>1 2015-02-28T04:06:42.186021+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Bearer-Capabilities=0x0
<13>1 2015-02-28T04:06:42.186339+01:00 l2tp,debug,packet L2TP - - - L2TP::: Firmware-Revision=0x1
<13>1 2015-02-28T04:06:42.186339+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Host-Name=“mtgwsg”
<13>1 2015-02-28T04:06:42.186637+01:00 l2tp,debug,packet L2TP - - - L2TP::: Vendor-Name=“MikroTik”
<13>1 2015-02-28T04:06:42.186637+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Assigned-Tunnel-ID=2
<13>1 2015-02-28T04:06:42.187015+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Receive-Window-Size=4
<13>1 2015-02-28T04:06:50.194297+01:00 l2tp,debug,packet L2TP - - - L2TP::: sent control message to 192.168.1.1:1701
<13>1 2015-02-28T04:06:50.194297+01:00 l2tp,debug,packet L2TP - - - L2TP::: tunnel-id=0, session-id=0, ns=0, nr=0
<13>1 2015-02-28T04:06:50.194389+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Message-Type=SCCRQ
<13>1 2015-02-28T04:06:50.194389+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Protocol-Version=0x01:00
<13>1 2015-02-28T04:06:50.194430+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Framing-Capabilities=0x1
<13>1 2015-02-28T04:06:50.194721+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Bearer-Capabilities=0x0
<13>1 2015-02-28T04:06:50.194976+01:00 l2tp,debug,packet L2TP - - - L2TP::: Firmware-Revision=0x1
<13>1 2015-02-28T04:06:50.195363+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Host-Name=“mtgwsg”
<13>1 2015-02-28T04:06:50.195363+01:00 l2tp,debug,packet L2TP - - - L2TP::: Vendor-Name=“MikroTik”
<13>1 2015-02-28T04:06:50.196595+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Assigned-Tunnel-ID=2
<13>1 2015-02-28T04:06:50.196595+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Receive-Window-Size=4
<13>1 2015-02-28T04:06:58.202081+01:00 l2tp,debug L2TP - - - L2TP::: tunnel 2 received no replies, disconnecting
<13>1 2015-02-28T04:06:58.203261+01:00 l2tp,debug L2TP - - - L2TP::: tunnel 2 entering state: dead
<13>1 2015-02-28T04:06:58.203542+01:00 l2tp,debug L2TP - - - L2TP::: session 1 entering state: dead
I wonder if the “No ID match” debug message from Ipsec above is a serious problem or not and if it was how to correct it.
One more configuration trial: I change the l2tp-client config and policy config as follows (changed connect-to=R.R.R.15 in l2tp-client and dst-address=R.R.R.15/32 in ipsec policy. Everything else remains the same:
[admin@mtgwsg] > /interface l2tp-client print
Flags: X - disabled, R - running
0 X name="remgw" max-mtu=1450 max-mru=1450 mrru=1600 [color=#408000]connect-to=R.R.R.15[/color] user="l2tpUser" password="l2tpPwd" profile=remgwProfile keepalive-timeout=60 add-default-route=no dial-on-demand=no
allow=pap,chap,mschap1,mschap2
[admin@mtgwsg] > /ip ipsec policy print
Flags: T - template, X - disabled, D - dynamic, I - inactive, * - default
0 T * group=remgwGroup src-address=0.0.0.0/0 dst-address=0.0.0.0/0 protocol=udp proposal=remgwProposal template=yes
1 src-address=0.0.0.0/0 src-port=any [color=#408000]dst-address=R.R.R.15/32[/color] dst-port=1701 protocol=udp action=encrypt level=require ipsec-protocols=esp tunnel=yes sa-src-address=h.h.h.52 sa-dst-address=R.R.R.15
proposal=remgwProposal priority=1
Obviously nothing changed in the first part (phase 1), because nothing changed in peer configuration. But after starting/activating l2tp-client config I get the following log:
<13>1 2015-02-28T11:04:31.493176+01:00 l2tp,ppp,info L2TP - - - L2TP::: remgw: initializing…
<13>1 2015-02-28T11:04:31.493176+01:00 l2tp,ppp,info L2TP - - - L2TP::: remgw: connecting…
<13>1 2015-02-28T11:04:31.493255+01:00 l2tp,debug L2TP - - - L2TP::: tunnel 1 entering state: wait-ctl-reply
<13>1 2015-02-28T11:04:31.493435+01:00 l2tp,debug,packet L2TP - - - L2TP::: sent control message to R.R.R.15:1701
<13>1 2015-02-28T11:04:31.493670+01:00 l2tp,debug,packet L2TP - - - L2TP::: tunnel-id=0, session-id=0, ns=0, nr=0
<13>1 2015-02-28T11:04:31.493979+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Message-Type=SCCRQ
<13>1 2015-02-28T11:04:31.494270+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Protocol-Version=0x01:00
<13>1 2015-02-28T11:04:31.494531+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Framing-Capabilities=0x1
<13>1 2015-02-28T11:04:31.494806+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Bearer-Capabilities=0x0
<13>1 2015-02-28T11:04:31.495083+01:00 l2tp,debug,packet L2TP - - - L2TP::: Firmware-Revision=0x1
<13>1 2015-02-28T11:04:31.495367+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Host-Name=“mtgwsg”
<13>1 2015-02-28T11:04:31.495631+01:00 l2tp,debug,packet L2TP - - - L2TP::: Vendor-Name=“MikroTik”
<13>1 2015-02-28T11:04:31.495911+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Assigned-Tunnel-ID=1
<13>1 2015-02-28T11:04:31.496188+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Receive-Window-Size=4
<13>1 2015-02-28T11:04:31.513272+01:00 ipsec,debug IPSEC - - - IPSEC::: new acquire h.h.h.52[0]<=>R.R.R.15[0]
<13>1 2015-02-28T11:04:31.513550+01:00 ipsec,debug IPSEC - - - IPSEC::: suitable outbound SP found: 0.0.0.0/0[0] R.R.R.15/32[1701] proto=udp dir=out
<13>1 2015-02-28T11:04:31.513875+01:00 ipsec,debug IPSEC - - - IPSEC::: suitable inbound SP found: R.R.R.15/32[1701] 0.0.0.0/0[0] proto=udp dir=in
<13>1 2015-02-28T11:04:31.514124+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Tunnel reqid=0:0)
<13>1 2015-02-28T11:04:31.514408+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: (trns_id=AES-CBC encklen=128 authtype=hmac-sha1)
<13>1 2015-02-28T11:04:31.514676+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: (trns_id=AES-CBC encklen=256 authtype=hmac-sha1)
<13>1 2015-02-28T11:04:31.514955+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: begin QUICK mode.
<13>1 2015-02-28T11:04:31.515229+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ===
<13>1 2015-02-28T11:04:31.515502+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: begin QUICK mode.
<13>1 2015-02-28T11:04:31.515791+01:00 ipsec,debug IPSEC - - - IPSEC::: initiate new phase 2 negotiation: h.h.h.52[0]<=>R.R.R.15[0]
— deleted —
<13>1 2015-02-28T11:04:31.518834+01:00 ipsec,debug IPSEC - - - IPSEC::: pfkey GETSPI succeeded: ESP/Tunnel R.R.R.15[0]->h.h.h.52[0] spi=151901850(0x90dd69a)
<13>1 2015-02-28T11:04:31.519109+01:00 ipsec,debug IPSEC - - - IPSEC::: NAT detected → UDP encapsulation (ENC_MODE 1->3).
<13>1 2015-02-28T11:04:31.519380+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: use local ID type IPv4_subnet
<13>1 2015-02-28T11:04:31.519668+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: use remote ID type IPv4_address
<13>1 2015-02-28T11:04:31.519943+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: IDci:
<13>1 2015-02-28T11:04:31.520220+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 04110000 00000000 00000000
<13>1 2015-02-28T11:04:31.520497+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: IDcr:
<13>1 2015-02-28T11:04:31.520780+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 011106a5 3ecbdb0f
— deleted —
<13>1 2015-02-28T11:04:31.552138+01:00 ipsec,debug IPSEC - - - IPSEC::: sent phase2 packet h.h.h.52[4500]<=>R.R.R.15[4500] 9ee94d145c43be54:d0485eeeb4fd86bb:b45461e3
— deleted —
<13>1 2015-02-28T11:04:31.615591+01:00 ipsec,debug IPSEC - - - IPSEC::: attribute has been modified.
— deleted —
<13>1 2015-02-28T11:04:31.629436+01:00 ipsec,debug IPSEC - - - IPSEC::: Adjusting my encmode UDP-Tunnel->Tunnel
<13>1 2015-02-28T11:04:31.629716+01:00 ipsec,debug IPSEC - - - IPSEC::: Adjusting peer’s encmode UDP-Tunnel(3)->Tunnel(1)
— deleted —
<13>1 2015-02-28T11:04:31.657207+01:00 ipsec IPSEC - - - IPSEC::: IPsec-SA established: ESP/Tunnel R.R.R.15[0]->h.h.h.52[0] spi=151901850(0x90dd69a)
— deleted —
<13>1 2015-02-28T11:04:31.658575+01:00 ipsec IPSEC - - - IPSEC::: IPsec-SA established: ESP/Tunnel h.h.h.52[0]->R.R.R.15[0] spi=3285094760(0xc3ce9168)
<13>1 2015-02-28T11:04:31.658875+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: pfkey add sent.
<13>1 2015-02-28T11:04:32.495057+01:00 l2tp,debug,packet L2TP - - - L2TP::: sent control message to R.R.R.15:1701
<13>1 2015-02-28T11:04:32.495057+01:00 l2tp,debug,packet L2TP - - - L2TP::: tunnel-id=0, session-id=0, ns=0, nr=0
<13>1 2015-02-28T11:04:32.495127+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Message-Type=SCCRQ
<13>1 2015-02-28T11:04:32.495127+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Protocol-Version=0x01:00
<13>1 2015-02-28T11:04:32.495402+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Framing-Capabilities=0x1
<13>1 2015-02-28T11:04:32.495660+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Bearer-Capabilities=0x0
<13>1 2015-02-28T11:04:32.495942+01:00 l2tp,debug,packet L2TP - - - L2TP::: Firmware-Revision=0x1
<13>1 2015-02-28T11:04:32.496220+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Host-Name=“mtgwsg”
<13>1 2015-02-28T11:04:32.496504+01:00 l2tp,debug,packet L2TP - - - L2TP::: Vendor-Name=“MikroTik”
<13>1 2015-02-28T11:04:32.496772+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Assigned-Tunnel-ID=1
<13>1 2015-02-28T11:04:32.497039+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Receive-Window-Size=4
<13>1 2015-02-28T11:04:33.497501+01:00 l2tp,debug,packet L2TP - - - L2TP::: sent control message to R.R.R.15:1701
<13>1 2015-02-28T11:04:33.497501+01:00 l2tp,debug,packet L2TP - - - L2TP::: tunnel-id=0, session-id=0, ns=0, nr=0
<13>1 2015-02-28T11:04:33.497589+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Message-Type=SCCRQ
<13>1 2015-02-28T11:04:33.497589+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Protocol-Version=0x01:00
<13>1 2015-02-28T11:04:33.497628+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Framing-Capabilities=0x1
<13>1 2015-02-28T11:04:33.497877+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Bearer-Capabilities=0x0
<13>1 2015-02-28T11:04:33.498108+01:00 l2tp,debug,packet L2TP - - - L2TP::: Firmware-Revision=0x1
<13>1 2015-02-28T11:04:33.498383+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Host-Name=“mtgwsg”
<13>1 2015-02-28T11:04:33.498667+01:00 l2tp,debug,packet L2TP - - - L2TP::: Vendor-Name=“MikroTik”
<13>1 2015-02-28T11:04:33.498923+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Assigned-Tunnel-ID=1
<13>1 2015-02-28T11:04:33.499192+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Receive-Window-Size=4
— deleted (repeats every 1-2 seconds)—
<13>1 2015-02-28T11:04:45.249778+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: KA: h.h.h.52[4500]->R.R.R.15[4500]
<13>1 2015-02-28T11:04:45.249952+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: sockname h.h.h.52[4500]
<13>1 2015-02-28T11:04:45.250374+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet from h.h.h.52[4500]
<13>1 2015-02-28T11:04:45.250374+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: send packet to R.R.R.15[4500]
<13>1 2015-02-28T11:04:45.250796+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: src4 h.h.h.52[4500]
<13>1 2015-02-28T11:04:45.251065+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: dst4 R.R.R.15[4500]
<13>1 2015-02-28T11:04:45.251375+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: 1 times of 1 bytes message will be sent to R.R.R.15[4500]
<13>1 2015-02-28T11:04:45.251630+01:00 ipsec,debug,packet IPSEC - - - IPSEC::: ff
<13>1 2015-02-28T11:04:47.513757+01:00 l2tp,debug,packet L2TP - - - L2TP::: sent control message to R.R.R.15:1701
<13>1 2015-02-28T11:04:47.513757+01:00 l2tp,debug,packet L2TP - - - L2TP::: tunnel-id=0, session-id=0, ns=0, nr=0
<13>1 2015-02-28T11:04:47.514505+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Message-Type=SCCRQ
<13>1 2015-02-28T11:04:47.514785+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Protocol-Version=0x01:00
<13>1 2015-02-28T11:04:47.515083+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Framing-Capabilities=0x1
<13>1 2015-02-28T11:04:47.515333+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Bearer-Capabilities=0x0
<13>1 2015-02-28T11:04:47.515614+01:00 l2tp,debug,packet L2TP - - - L2TP::: Firmware-Revision=0x1
<13>1 2015-02-28T11:04:47.515890+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Host-Name=“mtgwsg”
<13>1 2015-02-28T11:04:47.516150+01:00 l2tp,debug,packet L2TP - - - L2TP::: Vendor-Name=“MikroTik”
<13>1 2015-02-28T11:04:47.516419+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Assigned-Tunnel-ID=1
<13>1 2015-02-28T11:04:47.516698+01:00 l2tp,debug,packet L2TP - - - L2TP::: (M) Receive-Window-Size=4
— deleted (goes on forever) —
In this run it seems no phase 2 is even tried in Ipsec. I seem to be at a complete loss here. Any help would be greatly appreciated.