L2TP IPSEC Drops straight after connecting [Resolved]

RouterOS General
1

Hi Everyone,
I have been attempting to configure the LT2P IPSEC tunnel and am getting it to connect. Unfortunately, it then immediately disconnects. Can someone have a look at the log file below and let me know which line indicates the reason for this behavior? From what I can see, the test user successfully logs in then the tunnel doesn’t complete the establishment so it logs the user out.

Thanks
AU_Squirrel

The log file:
20:26:58 ipsec,info ISAKMP-SA established 180.150.98.165[4500]-1.128.241.167[4500] spi:02dd22f3edef0105:182db4e54e3827e1
20:26:59 l2tp,debug,packet rcvd control message from 1.128.241.167:1701 to 180.150.98.165:1701
20:26:59 l2tp,debug,packet tunnel-id=0, session-id=0, ns=0, nr=0
20:26:59 l2tp,debug,packet (M) Message-Type=SCCRQ
20:26:59 l2tp,debug,packet (M) Protocol-Version=0x01:00
20:26:59 l2tp,debug,packet (M) Framing-Capabilities=0x1
20:26:59 l2tp,debug,packet (M) Bearer-Capabilities=0x0
20:26:59 l2tp,debug,packet Firmware-Revision=0xa00
20:26:59 l2tp,debug,packet (M) Host-Name=“SURFACE.squires.id.au”
20:26:59 l2tp,debug,packet Vendor-Name=“Microsoft”
20:26:59 l2tp,debug,packet (M) Assigned-Tunnel-ID=26
20:26:59 l2tp,debug,packet (M) Receive-Window-Size=8
20:26:59 l2tp,info first L2TP UDP packet received from 1.128.241.167
20:26:59 l2tp,debug tunnel 28 entering state: wait-ctl-conn
20:26:59 l2tp,debug,packet sent control message to 1.128.241.167:1701 from 180.150.98.165:1701
20:26:59 l2tp,debug,packet tunnel-id=26, session-id=0, ns=0, nr=1
20:26:59 l2tp,debug,packet (M) Message-Type=SCCRP
20:26:59 l2tp,debug,packet (M) Protocol-Version=0x01:00
20:26:59 l2tp,debug,packet (M) Framing-Capabilities=0x1
20:26:59 l2tp,debug,packet (M) Bearer-Capabilities=0x0
20:26:59 l2tp,debug,packet Firmware-Revision=0x1
20:26:59 l2tp,debug,packet (M) Host-Name=“router.squires.id.au”
20:26:59 l2tp,debug,packet Vendor-Name=“MikroTik”
20:26:59 l2tp,debug,packet (M) Assigned-Tunnel-ID=28
20:26:59 l2tp,debug,packet (M) Receive-Window-Size=4
20:26:59 l2tp,debug,packet rcvd control message from 1.128.241.167:1701 to 180.150.98.165:1701
20:26:59 l2tp,debug,packet tunnel-id=28, session-id=0, ns=1, nr=1
20:26:59 l2tp,debug,packet (M) Message-Type=SCCCN
20:26:59 l2tp,debug tunnel 28 entering state: estabilished
20:26:59 l2tp,debug,packet sent control message (ack) to 1.128.241.167:1701 from 180.150.98.165:1701
20:26:59 l2tp,debug,packet tunnel-id=26, session-id=0, ns=1, nr=2
20:26:59 l2tp,debug,packet rcvd control message from 1.128.241.167:1701 to 180.150.98.165:1701
20:26:59 l2tp,debug,packet tunnel-id=28, session-id=0, ns=2, nr=1
20:26:59 l2tp,debug,packet (M) Message-Type=ICRQ
20:26:59 l2tp,debug,packet (M) Assigned-Session-ID=1
20:26:59 l2tp,debug,packet (M) Call-Serial-Number=0
20:26:59 l2tp,debug,packet (M) Bearer-Type=0x2
20:26:59 l2tp,debug session 1 entering state: wait-connect
20:26:59 l2tp,debug,packet sent control message to 1.128.241.167:1701 from 180.150.98.165:1701
20:26:59 l2tp,debug,packet tunnel-id=26, session-id=1, ns=1, nr=3
20:26:59 l2tp,debug,packet (M) Message-Type=ICRP
20:26:59 l2tp,debug,packet (M) Assigned-Session-ID=1
20:26:59 l2tp,debug,packet rcvd control message from 1.128.241.167:1701 to 180.150.98.165:1701
20:26:59 l2tp,debug,packet tunnel-id=28, session-id=1, ns=3, nr=2
20:26:59 l2tp,debug,packet (M) Message-Type=ICCN
20:26:59 l2tp,debug,packet (M) Tx-Connect-Speed-BPS=144000000
20:26:59 l2tp,debug,packet (M) Framing-Type=0x1
20:26:59 l2tp,debug,packet Proxy-Authen-Type=4
20:26:59 l2tp,debug session 1 entering state: established
20:26:59 l2tp,debug,packet sent control message (ack) to 1.128.241.167:1701 from 180.150.98.165:1701
20:26:59 l2tp,debug,packet tunnel-id=26, session-id=0, ns=2, nr=4
20:26:59 l2tp,ppp,debug <1.128.241.167>: LCP lowerup
20:26:59 l2tp,ppp,debug <1.128.241.167>: LCP open
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: rcvd LCP ConfReq id=0x0
20:26:59 l2tp,ppp,debug,packet <mru 1400>
20:26:59 l2tp,ppp,debug,packet <magic 0x6ef51ef8>
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,debug,packet <callback 0x06>
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent LCP ConfReq id=0x1
20:26:59 l2tp,ppp,debug,packet <mru 1450>
20:26:59 l2tp,ppp,debug,packet <magic 0x6ccba35b>
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent LCP ConfRej id=0x0
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: rcvd LCP ConfAck id=0x1
20:26:59 l2tp,ppp,debug,packet <mru 1450>
20:26:59 l2tp,ppp,debug,packet <magic 0x6ccba35b>
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: rcvd LCP ConfReq id=0x1
20:26:59 l2tp,ppp,debug,packet <mru 1400>
20:26:59 l2tp,ppp,debug,packet <magic 0x6ef51ef8>
20:26:59 l2tp,ppp,debug,packet <callback 0x06>
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent LCP ConfAck id=0x1
20:26:59 l2tp,ppp,debug,packet <mru 1400>
20:26:59 l2tp,ppp,debug,packet <magic 0x6ef51ef8>
20:26:59 l2tp,ppp,debug,packet <callback 0x06>
20:26:59 l2tp,ppp,debug <1.128.241.167>: LCP opened
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent CHAP Challenge id=0x1
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: rcvd LCP Ident id=0x2
20:26:59 l2tp,ppp,debug,packet <magic 0x6ef51ef8>
20:26:59 l2tp,ppp,debug,packet MSRASV5.20
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: rcvd LCP Ident id=0x3
20:26:59 l2tp,ppp,debug,packet <magic 0x6ef51ef8>
20:26:59 l2tp,ppp,debug,packet MSRAS-0-SURFACE
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: rcvd LCP Ident id=0x4
20:26:59 l2tp,ppp,debug,packet <magic 0x6ef51ef8>
20:26:59 l2tp,ppp,debug,packet \0E\F9\F3<xZ\02\00\08v\F5<xZ\D6\01
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: rcvd CHAP Response id=0x1
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,debug,packet
20:26:59 l2tp,ppp,info,account test logged in, 192.168.11.202 from 1.128.241.167
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent CHAP Success id=0x1
20:26:59 l2tp,ppp,debug,packet S=5748D0AD9C9408515425AFB8E05CB8D8D6A02312
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent CBCP CallbackReq id=0x0
20:26:59 l2tp,ppp,debug,packet 01 02
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: rcvd CBCP CallbackResp id=0x0
20:26:59 l2tp,ppp,debug,packet 01 02
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent CBCP CallbackAck id=0x1
20:26:59 l2tp,ppp,debug,packet 01 02
20:26:59 l2tp,ppp,info : authenticated
20:26:59 l2tp,ppp,debug <1.128.241.167>: IPCP lowerup
20:26:59 l2tp,ppp,debug <1.128.241.167>: IPCP open
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent IPCP ConfReq id=0x1
20:26:59 l2tp,ppp,debug,packet <addr 192.168.11.1>
20:26:59 l2tp,ppp,debug <1.128.241.167>: IPV6CP lowerup
20:26:59 l2tp,ppp,debug <1.128.241.167>: IPV6CP open
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent IPV6CP ConfReq id=0x1
20:26:59 l2tp,ppp,debug,packet <interface-identifier 0:0:f0:4d>
20:26:59 l2tp,ppp,debug <1.128.241.167>: MPLSCP lowerup
20:26:59 l2tp,ppp,debug <1.128.241.167>: MPLSCP open
20:26:59 l2tp,ppp,debug,packet <1.128.241.167>: sent MPLSCP ConfReq id=0x1
20:26:59 l2tp,ppp,debug <1.128.241.167>: BCP open
20:26:59 l2tp,ppp,debug <1.128.241.167>: CCP lowerup
20:26:59 l2tp,ppp,debug <1.128.241.167>: CCP open
20:27:00 l2tp,ppp,debug,packet <1.128.241.167>: rcvd LCP TermReq id=0x5
20:27:00 l2tp,ppp,debug,packet n\F5\1E\F8\00<\CDt\00\00\02\D0
20:27:00 l2tp,ppp,debug <1.128.241.167>: LCP closed
20:27:00 l2tp,ppp,debug <1.128.241.167>: CCP lowerdown
20:27:00 l2tp,ppp,debug <1.128.241.167>: BCP lowerdown
20:27:00 l2tp,ppp,debug <1.128.241.167>: BCP down event in starting state
20:27:00 l2tp,ppp,debug <1.128.241.167>: IPCP lowerdown
20:27:00 l2tp,ppp,debug <1.128.241.167>: IPV6CP lowerdown
20:27:00 l2tp,ppp,debug <1.128.241.167>: MPLSCP lowerdown
20:27:00 l2tp,ppp,debug,packet <1.128.241.167>: sent LCP TermAck id=0x5
20:27:00 l2tp,ppp,debug <1.128.241.167>: LCP lowerdown
20:27:00 l2tp,ppp,debug <1.128.241.167>: CCP close
20:27:00 l2tp,ppp,debug <1.128.241.167>: BCP close
20:27:00 l2tp,ppp,debug <1.128.241.167>: IPCP close
20:27:00 l2tp,ppp,debug <1.128.241.167>: IPV6CP close
20:27:00 l2tp,ppp,debug <1.128.241.167>: MPLSCP close
20:27:00 l2tp,ppp,info : terminating…
20:27:00 l2tp,ppp,debug <1.128.241.167>: LCP lowerdown
20:27:00 l2tp,ppp,debug <1.128.241.167>: LCP down event in starting state
20:27:00 l2tp,ppp,info,account test logged out, 1 0 28 0 3 from 1.128.241.167
20:27:00 l2tp,ppp,info : disconnected
20:27:00 l2tp,debug,packet sent control message to 1.128.241.167:1701 from 180.150.98.165:1701
20:27:00 l2tp,debug,packet tunnel-id=26, session-id=1, ns=2, nr=4
20:27:00 l2tp,debug,packet (M) Message-Type=CDN
20:27:00 l2tp,debug,packet (M) Result-Code=1
20:27:00 l2tp,debug,packet (M) Assigned-Session-ID=1
20:27:00 l2tp,debug session 1 entering state: stopping
20:27:00 l2tp,debug,packet rcvd control message from 1.128.241.167:1701 to 180.150.98.165:1701
20:27:00 l2tp,debug,packet tunnel-id=28, session-id=0, ns=4, nr=3
20:27:00 l2tp,debug,packet (M) Message-Type=StopCCN
20:27:00 l2tp,debug,packet (M) Assigned-Tunnel-ID=26
20:27:00 l2tp,debug,packet (M) Result-Code=6
20:27:00 l2tp,debug,packet Error-Code=0
20:27:00 l2tp,debug,packet sent control message (ack) to 1.128.241.167:1701 from 180.150.98.165:1701
20:27:00 l2tp,debug,packet tunnel-id=26, session-id=0, ns=3, nr=5
20:27:00 l2tp,debug tunnel 28 entering state: dead
20:27:00 l2tp,debug session 1 entering state: dead

2

The other side disconnects. Check its debug log for more detail…

3

This recent topic may be dealing with the same issue.

4

Thanks pe1chl and sindy for your suggestions. I have read both articles and will try them out and let you know how I go.

5

I read the posts and then removed and recreated the connections and after checking all the passwords were the same, it worked.

Thanks for the help.