L2TP closes connection for unknown reason
-
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.