L2TP closes connection for unknown reason
-
We have noticed that during the last few days we had repeated L2TP disconnects from 2 Mikrotik routers that have been running for more than a year. No software update or changes have been made on the Mikrotik in a long time, and I'm not aware of any changes on pfSense either.
Here's the log when the disconnect occurs:
Aug 3 16:56:51 l2tps: [l2tp_l-2] LCP: no reply to 1 echo request(s) Aug 3 16:55:21 l2tps: [l2tp_l-2] LCP: no reply to 1 echo request(s) Aug 3 16:54:11 l2tps: [l2tp_l-2] LCP: no reply to 1 echo request(s) Aug 3 16:53:41 l2tps: [l2tp_l-2] LCP: no reply to 1 echo request(s) Aug 3 16:53:01 l2tps: [l2tp_l-2] LCP: no reply to 1 echo request(s) Aug 3 16:45:01 l2tps: [l2tp_l-2] LCP: no reply to 1 echo request(s) Aug 3 16:44:01 l2tps: [l2tp_l-2] LCP: no reply to 1 echo request(s) Aug 3 16:17:18 l2tps: L2TP: Control connection 0x803257910 destroyed Aug 3 16:17:07 l2tps: [l2tp_l-1] Link: Shutdown Aug 3 16:17:07 l2tps: [l2tp_l-1] Link: SHUTDOWN event Aug 3 16:17:07 l2tps: L2TP: Control connection 0x803257910 terminated: 0 () Aug 3 16:17:07 l2tps: [l2tp_l-1] LCP: state change Closing --> Initial Aug 3 16:17:07 l2tps: [l2tp_l-1] LCP: LayerFinish Aug 3 16:17:07 l2tps: [l2tp_l-1] LCP: Down event Aug 3 16:17:07 l2tps: [l2tp_l-1] LCP: LayerDown Aug 3 16:17:07 l2tps: [l2tp_l-1] LCP: SendTerminateReq #4 Aug 3 16:17:07 l2tps: [l2tp_b-1] Bundle: Shutdown Aug 3 16:17:07 l2tps: [l2tp_b-1] CCP: state change Closed --> Initial Aug 3 16:17:07 l2tps: [l2tp_b-1] CCP: Down event Aug 3 16:17:07 l2tps: [l2tp_b-1] IPCP: state change Closing --> Initial Aug 3 16:17:07 l2tps: [l2tp_b-1] Bundle: No NCPs left. Closing links... Aug 3 16:17:07 l2tps: [l2tp_b-1] IPCP: LayerFinish Aug 3 16:17:07 l2tps: [l2tp_b-1] IPCP: Down event Aug 3 16:17:07 l2tps: [l2tp_b-1] CCP: state change Stopped --> Closed Aug 3 16:17:07 l2tps: [l2tp_b-1] CCP: Close event Aug 3 16:17:07 l2tps: [l2tp_b-1] IFACE: Rename interface l2tp1 to l2tp1 Aug 3 16:17:07 l2tps: [l2tp_b-1] IFACE: Down event Aug 3 16:17:07 l2tps: [l2tp_b-1] IPCP: LayerDown Aug 3 16:17:07 l2tps: [l2tp_b-1] IPCP: SendTerminateReq #3 Aug 3 16:17:07 l2tps: [l2tp_b-1] IPCP: state change Opened --> Closing Aug 3 16:17:07 l2tps: [l2tp_b-1] IPCP: Close event Aug 3 16:17:07 l2tps: [l2tp_b-1] Bundle: Status update: up 0 links, total bandwidth 9600 bps Aug 3 16:17:07 l2tps: [l2tp_l-1] Link: Leave bundle "l2tp_b-1" Aug 3 16:17:07 l2tps: [l2tp_l-1] LCP: state change Opened --> Closing Aug 3 16:17:07 l2tps: [l2tp_l-1] LCP: Close event Aug 3 16:17:07 l2tps: [l2tp_l-1] Link: DOWN event Aug 3 16:17:07 l2tps: [l2tp_l-1] L2TP: call #14 terminated: result=2 error=6 errmsg="control connection closing" Aug 3 16:17:06 l2tps: [l2tp_l-1] LCP: no reply to 11 echo request(s) Aug 3 16:16:56 l2tps: [l2tp_l-1] LCP: no reply to 10 echo request(s) Aug 3 16:16:46 l2tps: [l2tp_l-1] LCP: no reply to 9 echo request(s) Aug 3 16:16:36 l2tps: [l2tp_l-1] LCP: no reply to 8 echo request(s) Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: LayerFinish Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: state change Stopping --> Stopped Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: rec'd Terminate Ack #2 (Stopping) Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: SendTerminateAck #3 Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: rec'd Terminate Request #18 (Stopping) Aug 3 16:16:28 l2tps: [l2tp_b-5] IFACE: Add group l2tp to ng4 Aug 3 16:16:28 l2tps: [l2tp_b-5] IFACE: Rename interface ng4 to l2tp5 Aug 3 16:16:28 l2tps: [l2tp_b-5] IFACE: Up event Aug 3 16:16:28 l2tps: [l2tp_b-5] 192.168.0.223 -> 192.168.0.220 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: LayerUp Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: state change Ack-Sent --> Opened Aug 3 16:16:28 l2tps: [l2tp_b-5] IPADDR 192.168.0.223 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: rec'd Configure Ack #2 (Ack-Sent) Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: LayerDown Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: SendTerminateReq #2 Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: state change Opened --> Stopping Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: parameter negotiation failed Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: No compression negotiated Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: LayerUp Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: state change Ack-Rcvd --> Opened Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: SendConfigAck #17 Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: rec'd Configure Request #17 (Ack-Rcvd) Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: state change Req-Sent --> Ack-Sent Aug 3 16:16:28 l2tps: [l2tp_b-5] IPADDR 192.168.0.220 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: SendConfigAck #12 Aug 3 16:16:28 l2tps: [l2tp_b-5] 192.168.0.220 is OK Aug 3 16:16:28 l2tps: [l2tp_b-5] IPADDR 192.168.0.220 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: rec'd Configure Request #12 (Req-Sent) Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: state change Req-Sent --> Ack-Rcvd Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: rec'd Configure Ack #1 (Req-Sent) Aug 3 16:16:28 l2tps: [l2tp_b-5] IPADDR 192.168.0.223 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: SendConfigReq #2 Aug 3 16:16:28 l2tps: [l2tp_b-5] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: rec'd Configure Reject #1 (Req-Sent) Aug 3 16:16:28 l2tps: [l2tp_b-5] 0x01000040:MPPE(128 bits), stateless Aug 3 16:16:28 l2tps: [l2tp_b-5] MPPC Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: SendConfigRej #16 Aug 3 16:16:28 l2tps: [l2tp_b-5] 0x01000040:MPPE(128 bits), stateless Aug 3 16:16:28 l2tps: [l2tp_b-5] MPPC Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: rec'd Configure Request #16 (Req-Sent) Aug 3 16:16:28 l2tps: [l2tp_l-5] rec'd unexpected protocol MPLS Control Protocol (RFC 3032), rejecting Aug 3 16:16:28 l2tps: [l2tp_b-5] IPADDR 192.168.0.220 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: SendConfigNak #11 Aug 3 16:16:28 l2tps: [l2tp_b-5] NAKing with 192.168.0.220 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPADDR 0.0.0.0 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: rec'd Configure Request #11 (Req-Sent) Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: SendConfigReq #1 Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: state change Starting --> Req-Sent Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: Protocol mppc disabled as useless for this setup Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: Up event Aug 3 16:16:28 l2tps: [l2tp_b-5] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Aug 3 16:16:28 l2tps: [l2tp_b-5] IPADDR 192.168.0.223 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: SendConfigReq #1 Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: state change Starting --> Req-Sent Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: Up event Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: LayerStart Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: state change Initial --> Starting Aug 3 16:16:28 l2tps: [l2tp_b-5] CCP: Open event Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: LayerStart Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: state change Initial --> Starting Aug 3 16:16:28 l2tps: [l2tp_b-5] IPCP: Open event Aug 3 16:16:28 l2tps: [l2tp_b-5] Bundle: Status update: up 1 link, total bandwidth 64000 bps Aug 3 16:16:28 l2tps: [l2tp_l-5] Link: Join bundle "l2tp_b-5" Aug 3 16:16:28 l2tps: [l2tp_b-5] Bundle: Interface ng4 created Aug 3 16:16:28 l2tps: [l2tp_l-5] Creating new bundle using template "l2tp_b". Aug 3 16:16:28 l2tps: [l2tp_l-5] Link: Matched action 'bundle "l2tp_b" ""' Aug 3 16:16:28 l2tps: [l2tp_l-5] LCP: authorization successful Aug 3 16:16:28 l2tps: [l2tp_l-5] CHAP: sending SUCCESS #1 len: 46 Aug 3 16:16:28 l2tps: [l2tp_l-5] CHAP: Reply message: S=B0EE82416C391333984215D6C915B640BAE3FFBF Aug 3 16:16:28 l2tps: [l2tp_l-5] CHAP: Response is valid Aug 3 16:16:28 l2tps: [l2tp_l-5] CHAP: Auth return status: undefined Aug 3 16:16:28 l2tps: [l2tp_l-5] AUTH: INTERNAL returned: undefined Aug 3 16:16:28 l2tps: [l2tp_l-5] AUTH: Trying INTERNAL Aug 3 16:16:28 l2tps: [l2tp_l-5] Name: "imb-router" Aug 3 16:16:28 l2tps: [l2tp_l-5] CHAP: rec'd RESPONSE #1 len: 64 Aug 3 16:16:28 l2tps: [l2tp_l-5] LCP: LayerUp Aug 3 16:16:28 l2tps: [l2tp_l-5] CHAP: sending CHALLENGE #1 len: 21 Aug 3 16:16:28 l2tps: [l2tp_l-5] LCP: auth: peer wants nothing, I want CHAP Aug 3 16:16:28 l2tps: [l2tp_l-5] LCP: state change Ack-Sent --> Opened Aug 3 16:16:28 l2tps: [l2tp_l-5] AUTHPROTO CHAP MSOFTv2 Aug 3 16:16:28 l2tps: [l2tp_l-5] MAGICNUM 0xcdeb1d4c Aug 3 16:16:28 l2tps: [l2tp_l-5] MRU 1500 Aug 3 16:16:28 l2tps: [l2tp_l-5] LCP: rec'd Configure Ack #3 (Ack-Sent) Aug 3 16:16:28 l2tps: [l2tp_l-5] AUTHPROTO CHAP MSOFTv2 Aug 3 16:16:28 l2tps: [l2tp_l-5] MAGICNUM 0xcdeb1d4c Aug 3 16:16:28 l2tps: [l2tp_l-5] MRU 1500 Aug 3 16:16:28 l2tps: [l2tp_l-5] LCP: SendConfigReq #3 Aug 3 16:16:28 l2tps: [l2tp_l-5] MP SHORTSEQ Aug 3 16:16:28 l2tps: [l2tp_l-5] ENDPOINTDISC [802.1] 00 1e 67 ce 84 59 Aug 3 16:16:28 l2tps: [l2tp_l-5] MP MRRU 2048 Aug 3 16:16:28 l2tps: [l2tp_l-5] PROTOCOMP Aug 3 16:16:28 l2tps: [l2tp_l-5] ACFCOMP Aug 3 16:16:28 l2tps: [l2tp_l-5] LCP: rec'd Configure Reject #2 (Ack-Sent) Aug 3 16:16:28 l2tps: [l2tp_l-5] ENDPOINTDISC [802.1] 00 1e 67 ce 84 59 Aug 3 16:16:28 l2tps: [l2tp_l-5] MP SHORTSEQ Aug 3 16:16:28 l2tps: [l2tp_l-5] MP MRRU 2048 Aug 3 16:16:28 l2tps: [l2tp_l-5] AUTHPROTO CHAP MSOFTv2 Aug 3 16:16:28 l2tps: [l2tp_l-5] MAGICNUM 0xcdeb1d4c Aug 3 16:16:28 l2tps: [l2tp_l-5] MRU 1500 Aug 3 16:16:28 l2tps: [l2tp_l-5] PROTOCOMP Aug 3 16:16:28 l2tps: [l2tp_l-5] ACFCOMP Aug 3 16:16:28 l2tps: [l2tp_l-5] LCP: SendConfigReq #2 Aug 3 16:16:27 l2tps: [l2tp_l-5] MAGICNUM 0x3426beea Aug 3 16:16:27 l2tps: [l2tp_l-5] MRU 1450 Aug 3 16:16:27 l2tps: [l2tp_l-5] LCP: SendConfigAck #12 Aug 3 16:16:27 l2tps: [l2tp_l-5] MAGICNUM 0x3426beea Aug 3 16:16:27 l2tps: [l2tp_l-5] MRU 1450 Aug 3 16:16:27 l2tps: [l2tp_l-5] LCP: rec'd Configure Request #12 (Ack-Sent) Aug 3 16:16:26 l2tps: [l2tp_l-5] LCP: state change Req-Sent --> Ack-Sent Aug 3 16:16:26 l2tps: [l2tp_l-5] MAGICNUM 0x3426beea Aug 3 16:16:26 l2tps: [l2tp_l-5] MRU 1450 Aug 3 16:16:26 l2tps: [l2tp_l-5] LCP: SendConfigAck #11 Aug 3 16:16:26 l2tps: [l2tp_l-5] MAGICNUM 0x3426beea Aug 3 16:16:26 l2tps: [l2tp_l-5] MRU 1450 Aug 3 16:16:26 l2tps: [l2tp_l-5] LCP: rec'd Configure Request #11 (Req-Sent) Aug 3 16:16:26 l2tps: [l2tp_l-5] ENDPOINTDISC [802.1] 00 1e 67 ce 84 59 Aug 3 16:16:26 l2tps: [l2tp_l-5] MP SHORTSEQ Aug 3 16:16:26 l2tps: [l2tp_l-5] MP MRRU 2048 Aug 3 16:16:26 l2tps: [l2tp_l-5] AUTHPROTO CHAP MSOFTv2 Aug 3 16:16:26 l2tps: [l2tp_l-5] MAGICNUM 0xcdeb1d4c Aug 3 16:16:26 l2tps: [l2tp_l-5] MRU 1500 Aug 3 16:16:26 l2tps: [l2tp_l-5] PROTOCOMP Aug 3 16:16:26 l2tps: [l2tp_l-5] ACFCOMP Aug 3 16:16:26 l2tps: [l2tp_l-5] LCP: SendConfigReq #1 Aug 3 16:16:26 l2tps: [l2tp_l-5] LCP: state change Starting --> Req-Sent Aug 3 16:16:26 l2tps: [l2tp_l-5] LCP: Up event Aug 3 16:16:26 l2tps: [l2tp_l-5] Link: UP event Aug 3 16:16:26 l2tps: [l2tp_l-5] L2TP: Call #18 connected Aug 3 16:16:26 l2tps: [l2tp_l-5] LCP: LayerStart Aug 3 16:16:26 l2tps: [l2tp_l-5] LCP: state change Initial --> Starting Aug 3 16:16:26 l2tps: [l2tp_l-5] LCP: Open event Aug 3 16:16:26 l2tps: [l2tp_l-5] Link: OPEN event Aug 3 16:16:26 l2tps: [l2tp_l-5] L2TP: Incoming call #18 via control connection 0x803258b10 accepted Aug 3 16:16:26 l2tps: L2TP: Incoming call #18 via connection 0x803258b10 received Aug 3 16:16:26 l2tps: [l2tp_l-1] LCP: no reply to 7 echo request(s) Aug 3 16:16:26 l2tps: L2TP: Control connection 0x803258b10 129.232.211.141 1701 <-> 105.27.116.62 62827 connected Aug 3 16:16:25 l2tps: Incoming L2TP packet from 105.27.116.62 62827
This is pfSense 2.4.2_1.
What is causing this and how can I fix this please?
thanks
Roland
-
Based on the contents of the log I'd say something is breaking the connection between them. pfSense is not getting a response on the line so it drops the connection.
Something is broken in the network between pfSense and the Mikrotik.
-
@jimp Strangely enough nothing is down when this happens. We have a ping running to keep IPSec links alive all the time and that continues.
I'll set up some extra checks to see if anything does actually go down.
Question: I'd like to keep L2TP up all the time and retry the connection when it goes down so that this situation doesn't ever occur, except if the actual connection is down. What are the options to achieve this?
-
@lifeboy said in L2TP closes connection for unknown reason:
... 2 Mikrotik routers that have been running for more than a year. No software update or changes have been made on the Mikrotik in a long time ...
How long is a long time? There have been a couple of serious vulnerabilities discovered and patched in Routeros during the past year.
-
pfSense is trying to reconnect, but it's getting no response from the other side. Something is preventing them from communicating, and it's not likely to be anything directly on pfSense.
-
@biggsy I have the latest version of RouterOS installed, but have now upgraded everything (packages) to the latest as well.
I'll monitor it and will see what happens.
-
@jimp I have some more info. I have various locations that connect over different network to pfSense via L2TP. I also have a two server locations that they connect to. So:
routeros1 -> L2TP -> pfSense 2.4.3_1 (location H)
routeros1 -> L2TP -> pfSense 2.4.3_1 (location V)
routeros2 -> L2TP -> pfSense 2.4.3_1 (location H)
routeros2 -> L2TP -> pfSense 2.4.3_1 (location V)Is the above scenario both routeros1 and routeros2 links to location H drop all the time, but both stay up during that time to location V. That seems to indicate that the pfSense is not happy with something that routeros does and it fails the link.
Everything is the same (software versions), except location V runs on AMD Opteron hardware (Sun X2100) and location H run on Intel (Super Micro I think).
-
Here is the l2tp log for an event where the L2TP link is established and then closed again by pfSense.
Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: LayerFinish Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: state change Stopping --> Stopped Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: rec'd Terminate Ack #2 (Stopping) Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: SendTerminateAck #3 Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: rec'd Terminate Request #12 (Stopping) Aug 14 07:28:24 l2tps [l2tp_b-2] IFACE: Add group l2tp to ng1 Aug 14 07:28:24 l2tps [l2tp_b-2] IFACE: Rename interface ng1 to l2tp2 Aug 14 07:28:24 l2tps [l2tp_b-2] IFACE: Up event Aug 14 07:28:24 l2tps [l2tp_b-2] 192.168.0.223 -> 192.168.0.225 Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: LayerUp Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: state change Ack-Sent --> Opened Aug 14 07:28:24 l2tps [l2tp_b-2] IPADDR 192.168.0.223 Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: rec'd Configure Ack #2 (Ack-Sent) Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: LayerDown Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: SendTerminateReq #2 Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: state change Opened --> Stopping Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: parameter negotiation failed Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: No compression negotiated Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: LayerUp Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: state change Ack-Rcvd --> Opened Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: SendConfigAck #11 Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: rec'd Configure Request #11 (Ack-Rcvd) Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: state change Req-Sent --> Ack-Sent Aug 14 07:28:24 l2tps [l2tp_b-2] IPADDR 192.168.0.225 Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: SendConfigAck #8 Aug 14 07:28:24 l2tps [l2tp_b-2] 192.168.0.225 is OK Aug 14 07:28:24 l2tps [l2tp_b-2] IPADDR 192.168.0.225 Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: rec'd Configure Request #8 (Req-Sent) Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: state change Req-Sent --> Ack-Rcvd Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: rec'd Configure Ack #1 (Req-Sent) Aug 14 07:28:24 l2tps [l2tp_b-2] IPADDR 192.168.0.223 Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: SendConfigReq #2 Aug 14 07:28:24 l2tps [l2tp_b-2] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: rec'd Configure Reject #1 (Req-Sent) Aug 14 07:28:24 l2tps [l2tp_b-2] 0x01000040:MPPE(128 bits), stateless Aug 14 07:28:24 l2tps [l2tp_b-2] MPPC Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: SendConfigRej #10 Aug 14 07:28:24 l2tps [l2tp_b-2] 0x01000040:MPPE(128 bits), stateless Aug 14 07:28:24 l2tps [l2tp_b-2] MPPC Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: rec'd Configure Request #10 (Req-Sent) Aug 14 07:28:24 l2tps [l2tp_l-2] rec'd unexpected protocol MPLS Control Protocol (RFC 3032), rejecting Aug 14 07:28:24 l2tps [l2tp_b-2] IPADDR 192.168.0.225 Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: SendConfigNak #7 Aug 14 07:28:24 l2tps [l2tp_b-2] NAKing with 192.168.0.225 Aug 14 07:28:24 l2tps [l2tp_b-2] IPADDR 0.0.0.0 Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: rec'd Configure Request #7 (Req-Sent) Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: SendConfigReq #1 Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: state change Starting --> Req-Sent Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: Protocol mppc disabled as useless for this setup Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: Up event Aug 14 07:28:24 l2tps [l2tp_b-2] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Aug 14 07:28:24 l2tps [l2tp_b-2] IPADDR 192.168.0.223 Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: SendConfigReq #1 Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: state change Starting --> Req-Sent Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: Got IP 192.168.0.225 from pool "p0" for peer Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: Up event Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: LayerStart Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: state change Initial --> Starting Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: Open event Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: LayerStart Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: state change Initial --> Starting Aug 14 07:28:24 l2tps [l2tp_b-2] IPCP: Open event Aug 14 07:28:24 l2tps [l2tp_b-2] Bundle: Status update: up 1 link, total bandwidth 64000 bps Aug 14 07:28:24 l2tps [l2tp_l-2] Link: Join bundle "l2tp_b-2" Aug 14 07:28:24 l2tps [l2tp_b-2] Bundle: Interface ng1 created Aug 14 07:28:24 l2tps [l2tp_l-2] Creating new bundle using template "l2tp_b". Aug 14 07:28:24 l2tps [l2tp_l-2] Link: Matched action 'bundle "l2tp_b" ""' Aug 14 07:28:24 l2tps [l2tp_l-2] LCP: authorization successful Aug 14 07:28:24 l2tps [l2tp_l-2] CHAP: sending SUCCESS #1 len: 46 Aug 14 07:28:24 l2tps [l2tp_l-2] CHAP: Reply message: S=C2DEDC922DFA427071447E9665569CC230FEAC34 Aug 14 07:28:24 l2tps [l2tp_l-2] CHAP: Response is valid Aug 14 07:28:24 l2tps [l2tp_l-2] CHAP: Auth return status: undefined Aug 14 07:28:24 l2tps [l2tp_l-2] AUTH: INTERNAL returned: undefined Aug 14 07:28:24 l2tps [l2tp_l-2] AUTH: Trying INTERNAL Aug 14 07:28:24 l2tps [l2tp_l-2] Name: "imb-router" Aug 14 07:28:24 l2tps [l2tp_l-2] CHAP: rec'd RESPONSE #1 len: 64 Aug 14 07:28:24 l2tps [l2tp_l-2] LCP: LayerUp Aug 14 07:28:24 l2tps [l2tp_l-2] CHAP: sending CHALLENGE #1 len: 21 Aug 14 07:28:24 l2tps [l2tp_l-2] LCP: auth: peer wants nothing, I want CHAP Aug 14 07:28:24 l2tps [l2tp_l-2] LCP: state change Ack-Sent --> Opened Aug 14 07:28:24 l2tps [l2tp_l-2] AUTHPROTO CHAP MSOFTv2 Aug 14 07:28:24 l2tps [l2tp_l-2] MAGICNUM 0xf47c96f8 Aug 14 07:28:24 l2tps [l2tp_l-2] MRU 1500 Aug 14 07:28:24 l2tps [l2tp_l-2] LCP: rec'd Configure Ack #3 (Ack-Sent) Aug 14 07:28:24 l2tps [l2tp_l-2] AUTHPROTO CHAP MSOFTv2 Aug 14 07:28:24 l2tps [l2tp_l-2] MAGICNUM 0xf47c96f8 Aug 14 07:28:24 l2tps [l2tp_l-2] MRU 1500 Aug 14 07:28:24 l2tps [l2tp_l-2] LCP: SendConfigReq #3 Aug 14 07:28:24 l2tps [l2tp_l-2] MP SHORTSEQ Aug 14 07:28:24 l2tps [l2tp_l-2] ENDPOINTDISC [802.1] 0c c4 7a ce c4 f1 Aug 14 07:28:24 l2tps [l2tp_l-2] MP MRRU 2048 Aug 14 07:28:24 l2tps [l2tp_l-2] PROTOCOMP Aug 14 07:28:24 l2tps [l2tp_l-2] ACFCOMP Aug 14 07:28:24 l2tps [l2tp_l-2] LCP: rec'd Configure Reject #2 (Ack-Sent) Aug 14 07:28:24 l2tps [l2tp_l-2] ENDPOINTDISC [802.1] 0c c4 7a ce c4 f1 Aug 14 07:28:24 l2tps [l2tp_l-2] MP SHORTSEQ Aug 14 07:28:24 l2tps [l2tp_l-2] MP MRRU 2048 Aug 14 07:28:24 l2tps [l2tp_l-2] AUTHPROTO CHAP MSOFTv2 Aug 14 07:28:24 l2tps [l2tp_l-2] MAGICNUM 0xf47c96f8 Aug 14 07:28:24 l2tps [l2tp_l-2] MRU 1500 Aug 14 07:28:24 l2tps [l2tp_l-2] PROTOCOMP Aug 14 07:28:24 l2tps [l2tp_l-2] ACFCOMP Aug 14 07:28:24 l2tps [l2tp_l-2] LCP: SendConfigReq #2 Aug 14 07:28:23 l2tps [l2tp_l-2] MAGICNUM 0x7fe0f9fc Aug 14 07:28:23 l2tps [l2tp_l-2] MRU 1450 Aug 14 07:28:23 l2tps [l2tp_l-2] LCP: SendConfigAck #9 Aug 14 07:28:23 l2tps [l2tp_l-2] MAGICNUM 0x7fe0f9fc Aug 14 07:28:23 l2tps [l2tp_l-2] MRU 1450 Aug 14 07:28:23 l2tps [l2tp_l-2] LCP: rec'd Configure Request #9 (Ack-Sent) Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: state change Req-Sent --> Ack-Sent Aug 14 07:28:22 l2tps [l2tp_l-2] MAGICNUM 0x7fe0f9fc Aug 14 07:28:22 l2tps [l2tp_l-2] MRU 1450 Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: SendConfigAck #8 Aug 14 07:28:22 l2tps [l2tp_l-2] MAGICNUM 0x7fe0f9fc Aug 14 07:28:22 l2tps [l2tp_l-2] MRU 1450 Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: rec'd Configure Request #8 (Req-Sent) Aug 14 07:28:22 l2tps [l2tp_l-2] ENDPOINTDISC [802.1] 0c c4 7a ce c4 f1 Aug 14 07:28:22 l2tps [l2tp_l-2] MP SHORTSEQ Aug 14 07:28:22 l2tps [l2tp_l-2] MP MRRU 2048 Aug 14 07:28:22 l2tps [l2tp_l-2] AUTHPROTO CHAP MSOFTv2 Aug 14 07:28:22 l2tps [l2tp_l-2] MAGICNUM 0xf47c96f8 Aug 14 07:28:22 l2tps [l2tp_l-2] MRU 1500 Aug 14 07:28:22 l2tps [l2tp_l-2] PROTOCOMP Aug 14 07:28:22 l2tps [l2tp_l-2] ACFCOMP Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: SendConfigReq #1 Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: state change Starting --> Req-Sent Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: Up event Aug 14 07:28:22 l2tps [l2tp_l-2] Link: UP event Aug 14 07:28:22 l2tps [l2tp_l-2] L2TP: Call #5 connected Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: LayerStart Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: state change Initial --> Starting Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: Open event Aug 14 07:28:22 l2tps [l2tp_l-2] Link: OPEN event Aug 14 07:28:22 l2tps [l2tp_l-2] L2TP: Incoming call #5 via control connection 0x803257f10 accepted Aug 14 07:28:22 l2tps L2TP: Incoming call #5 via connection 0x803257f10 received Aug 14 07:28:22 l2tps [l2tp_l-2] Link: Shutdown Aug 14 07:28:22 l2tps [l2tp_l-2] Link: SHUTDOWN event Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: state change Closing --> Initial Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: LayerFinish Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: Down event Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: state change Stopping --> Closing Aug 14 07:28:22 l2tps [l2tp_l-2] LCP: Close event Aug 14 07:28:22 l2tps [l2tp_l-2] Link: DOWN event Aug 14 07:28:22 l2tps [l2tp_l-2] L2TP: call #4 terminated: result=1 error=0 errmsg="" Aug 14 07:28:21 l2tps [l2tp_l-2] LCP: LayerDown Aug 14 07:28:21 l2tps [l2tp_l-2] LCP: SendTerminateAck #4 Aug 14 07:28:21 l2tps [l2tp_b-2] Bundle: Shutdown Aug 14 07:28:21 l2tps [l2tp_b-2] CCP: state change Closed --> Initial Aug 14 07:28:21 l2tps [l2tp_b-2] CCP: Down event Aug 14 07:28:21 l2tps [l2tp_b-2] IPCP: state change Closing --> Initial Aug 14 07:28:21 l2tps [l2tp_b-2] Bundle: No NCPs left. Closing links... Aug 14 07:28:21 l2tps [l2tp_b-2] IPCP: LayerFinish Aug 14 07:28:21 l2tps [l2tp_b-2] IPCP: Down event Aug 14 07:28:21 l2tps [l2tp_b-2] CCP: state change Stopped --> Closed Aug 14 07:28:21 l2tps [l2tp_b-2] CCP: Close event Aug 14 07:28:21 l2tps [l2tp_b-2] IFACE: Rename interface l2tp2 to l2tp2 Aug 14 07:28:21 l2tps [l2tp_b-2] IFACE: Down event Aug 14 07:28:21 l2tps [l2tp_b-2] IPCP: LayerDown Aug 14 07:28:21 l2tps [l2tp_b-2] IPCP: SendTerminateReq #3 Aug 14 07:28:21 l2tps [l2tp_b-2] IPCP: state change Opened --> Closing Aug 14 07:28:21 l2tps [l2tp_b-2] IPCP: Close event Aug 14 07:28:21 l2tps [l2tp_b-2] Bundle: Status update: up 0 links, total bandwidth 9600 bps Aug 14 07:28:21 l2tps [l2tp_l-2] Link: Leave bundle "l2tp_b-2" Aug 14 07:28:21 l2tps [l2tp_l-2] LCP: state change Opened --> Stopping Aug 14 07:28:21 l2tps [l2tp_l-2] LCP: rec'd Terminate Request #7 (Opened)
Note the lines:
Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: state change Opened --> Stopping
Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: parameter negotiation failed
Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: No compression negotiated
Aug 14 07:28:24 l2tps [l2tp_b-2] CCP: LayerUpIt's seems to me that there is some parameter that cannot be negotiated, so the layer is closed. How do I get more details on what happens?
-
I'm not getting any responses which seems to indicate nobody has any more clue of what is happening here than I have? Is there a way to get more verbose logging for L2TP?
-
It's seems there is a bug in renaming interface
i have the same problem.
ร use two L2TP interface, one to connect as client.
the second with a L2TP/IPSEC inteface for VPN.each time somebody disconnect from VPN, my client interface disconnect. It seems this is referenced as a bug referenced :
https://redmine.pfsense.org/issues/8164
I don't know how to bypass this bug.
-
I have sort of bypassed my problem by downgrading my mikrotik routeros version, but of course that opens me up to possible exploits with may have been fixed since. I have not considered that client connecting/disconnecting could be causing this though, so I will careful note what happens next time I have a disconnect.