[SOLVED] New PPTP VPN connection not working

banjo · March 5, 2015, 4:39pm

Hi all,

I have 4 VPN connections to my main Mikrotik RB750GL in the UK, I have 2 RB750GLs located in Switzerland and elsewhere in the UK which connect over PPTP fine and subnets route fine. I have an ASUS RT-AC68U in China which connects fine and requires some manual route entries to stop it using the UK as a default destination, but otherwise subnets route ok.

The 4th VPN connection from another Mikrotik RB750GL also in China connects for 65 seconds, and won’t route subnets.

I have followed the instructions here for setting up the VPN:
https://www.mikrotik.com/documentation/manual_2.7/Interface/PPTP.html

The configuration of the UK and Chinese Mikrotik’s are detailed here:
http://pastebin.ca/2948777

And finally here is a trace of the pptp connection …

15:41:32 pptp,info TCP connection established from xx.xx.xx.xx 
15:41:32 pptp,debug,packet rcvd Start-Control-Connection-Request from xx.xx.xx.xx 
15:41:32 pptp,debug,packet     protocol-version=0x0100 
15:41:32 pptp,debug,packet     framing-capabilities=2 
15:41:32 pptp,debug,packet     bearer-capabilities=0 
15:41:32 pptp,debug,packet     maximum-channels=0 
15:41:32 pptp,debug,packet     firmware-revision=1 
15:41:32 pptp,debug,packet     host-name=MikroTik 
15:41:32 pptp,debug,packet     vendor-name=MikroTik 
15:41:32 pptp,debug,packet sent Start-Control-Connection-Reply to xx.xx.xx.xx 
15:41:32 pptp,debug,packet     protocol-version=0x0100 
15:41:32 pptp,debug,packet     result-code=1 
15:41:32 pptp,debug,packet     error-code=0 
15:41:32 pptp,debug,packet     framing-capabilities=2 
15:41:32 pptp,debug,packet     bearer-capabilities=0 
15:41:32 pptp,debug,packet     maximum-channels=0 
15:41:32 pptp,debug,packet     firmware-revision=1 
15:41:32 pptp,debug,packet     host-name=MikroTik 
15:41:32 pptp,debug,packet     vendor-name=MikroTik 
15:41:32 pptp,debug,packet rcvd Outgoing-Call-Request from xx.xx.xx.xx 
15:41:32 pptp,debug,packet     call-id=0 
15:41:32 pptp,debug,packet     call-serial-number=0 
15:41:32 pptp,debug,packet     minimum-bps=2400 
15:41:32 pptp,debug,packet     maximum-bps=10000000 
15:41:32 pptp,debug,packet     bearer-type=3 
15:41:32 pptp,debug,packet     framing-type=2 
15:41:32 pptp,debug,packet     packet-recv-window-size=100 
15:41:32 pptp,debug,packet     packet-processing-delay=0 
15:41:32 pptp,debug,packet     phone-number-length=0 
15:41:32 pptp,debug,packet     phone-number= 
15:41:32 pptp,debug,packet     subaddress= 
15:41:32 pptp,ppp,debug <1679>: LCP lowerup 
15:41:32 pptp,ppp,debug <1679>: LCP open 
15:41:32 pptp,debug,packet sent Outgoing-Call-Reply to xx.xx.xx.xx 
15:41:32 pptp,debug,packet     call-id=1679 
15:41:32 pptp,debug,packet     peers-call-id=0 
15:41:32 pptp,debug,packet     result-code=1 
15:41:32 pptp,debug,packet     error-code=0 
15:41:32 pptp,debug,packet     cause-code=0 
15:41:32 pptp,debug,packet     connect-speed=100000 
15:41:32 pptp,debug,packet     packet-recv-window-size=100 
15:41:32 pptp,debug,packet     packet-processing-delay=0 
15:41:32 pptp,debug,packet     physical-channel-id=0 
15:41:33 pptp,ppp,debug,packet  <1679>: rcvd LCP ConfReq id=0x27 
15:41:33 pptp,ppp,debug,packet    <mru 1460> 
15:41:33 pptp,ppp,debug,packet    <magic 0x782101a4> 
15:41:33 pptp,ppp,debug,packet  <1679>: sent LCP ConfReq id=0x1 
15:41:33 pptp,ppp,debug,packet    <mru 1460> 
15:41:33 pptp,ppp,debug,packet    <magic 0x1c67cb35> 
15:41:33 pptp,ppp,debug,packet    <auth  mschap2> 
15:41:33 pptp,ppp,debug,packet  <1679>: sent LCP ConfAck id=0x27 
15:41:33 pptp,ppp,debug,packet    <mru 1460> 
15:41:33 pptp,ppp,debug,packet    <magic 0x782101a4> 
15:41:33 pptp,ppp,debug,packet  <1679>: rcvd LCP ConfAck id=0x1 
15:41:33 pptp,ppp,debug,packet    <mru 1460> 
15:41:33 pptp,ppp,debug,packet    <magic 0x1c67cb35> 
15:41:33 pptp,ppp,debug,packet    <auth  mschap2> 
15:41:33 pptp,ppp,debug <1679>: LCP opened 
15:41:33 pptp,ppp,debug,packet  <1679>: sent CHAP Challenge id=0x1 
15:41:33 pptp,ppp,debug,packet     <challenge len=16> 
15:41:33 pptp,ppp,debug,packet     <name MikroTik> 
15:41:34 pptp,ppp,debug,packet  <1679>: rcvd CHAP Response id=0x1 
15:41:34 pptp,ppp,debug,packet     <response len=49> 
15:41:34 pptp,ppp,debug,packet     <name xxxx> 
15:41:34 pptp,ppp,info,account xxxx logged in, 172.16.1.8 
15:41:34 pptp,ppp,debug,packet  <1679>: sent CHAP Success id=0x1 
15:41:34 pptp,ppp,debug,packet     S=7C42AE8A60F7721D9CE1B5ABB5510EE2F2C938BF 
15:41:34 pptp,ppp,info <pptp-xxxx>: authenticated 
15:41:34 pptp,ppp,debug <1679>: IPCP lowerup 
15:41:34 pptp,ppp,debug <1679>: IPCP open 
15:41:34 pptp,ppp,debug,packet  <1679>: sent IPCP ConfReq id=0x1 
15:41:34 pptp,ppp,debug,packet     <addr 172.16.1.7> 
15:41:34 pptp,ppp,debug <1679>: IPV6CP lowerup 
15:41:34 pptp,ppp,debug <1679>: IPV6CP open 
15:41:34 pptp,ppp,debug,packet  <1679>: sent IPV6CP ConfReq id=0x1 
15:41:34 pptp,ppp,debug,packet     <interface-identifier 0:0:f0:68d> 
15:41:34 pptp,ppp,debug <1679>: MPLSCP lowerup 
15:41:34 pptp,ppp,debug <1679>: MPLSCP open 
15:41:34 pptp,ppp,debug,packet  <1679>: sent MPLSCP ConfReq id=0x1 
15:41:34 pptp,ppp,debug <1679>: BCP open 
15:41:34 pptp,ppp,debug <1679>: CCP lowerup 
15:41:34 pptp,ppp,debug <1679>: CCP open 
15:41:34 pptp,ppp,debug,packet  <1679>: sent CCP ConfReq id=0x1 
15:41:34 pptp,ppp,debug,packet     <mppe 1000040> 
15:41:34 pptp,ppp,debug,packet  <1679>: rcvd IPCP ConfReq id=0x7b 
15:41:34 pptp,ppp,debug,packet     <addr 0.0.0.0> 
15:41:34 pptp,ppp,debug,packet  <1679>: sent IPCP ConfNak id=0x7b 
15:41:34 pptp,ppp,debug,packet     <addr 172.16.1.8> 
15:41:34 pptp,ppp,debug,packet  <1679>: rcvd IPV6CP ConfReq id=0xc8 
15:41:34 pptp,ppp,debug,packet     <interface-identifier 0:0:0:a> 
15:41:34 pptp,ppp,debug,packet  <1679>: sent IPV6CP ConfAck id=0xc8 
15:41:34 pptp,ppp,debug,packet     <interface-identifier 0:0:0:a> 
15:41:34 pptp,ppp,debug,packet  <1679>: rcvd MPLSCP ConfReq id=0x37 
15:41:34 pptp,ppp,debug,packet  <1679>: sent MPLSCP ConfAck id=0x37 
15:41:34 pptp,ppp,debug,packet  <1679>: rcvd CCP ConfReq id=0x3b 
15:41:34 pptp,ppp,debug,packet     <mppe 1000040> 
15:41:34 pptp,ppp,debug,packet  <1679>: sent CCP ConfAck id=0x3b 
15:41:34 pptp,ppp,debug,packet     <mppe 1000040> 
15:41:34 pptp,ppp,debug,packet  <1679>: rcvd IPCP ConfAck id=0x1 
15:41:34 pptp,ppp,debug,packet     <addr 172.16.1.7> 
15:41:34 pptp,ppp,debug,packet  <1679>: rcvd IPV6CP ConfAck id=0x1 
15:41:34 pptp,ppp,debug,packet     <interface-identifier 0:0:f0:68d> 
15:41:34 pptp,ppp,debug <1679>: IPV6CP opened 
15:41:34 pptp,ppp,info <pptp-xxxx>: connected 
15:41:34 pptp,ppp,debug,packet  <1679>: rcvd MPLSCP ConfAck id=0x1 
15:41:34 pptp,ppp,debug <1679>: MPLSCP opened 
15:41:34 pptp,ppp,debug,packet  <1679>: rcvd CCP ConfAck id=0x1 
15:41:34 pptp,ppp,debug,packet     <mppe 1000040> 
15:41:34 pptp,ppp,debug <1679>: CCP opened 
15:41:34 pptp,ppp,info <pptp-xxxx>: using encoding - MPPE128 stateless 
15:41:35 pptp,ppp,debug,packet  <1679>: rcvd IPCP ConfReq id=0x7c 
15:41:35 pptp,ppp,debug,packet     <addr 172.16.1.8> 
15:41:35 pptp,ppp,debug,packet  <1679>: sent IPCP ConfAck id=0x7c 
15:41:35 pptp,ppp,debug,packet     <addr 172.16.1.8> 
15:41:35 pptp,ppp,debug <1679>: IPCP opened 

 = = =   = = =   = = =      = = =   = = =   = = =      = = =   = = =   = = =

15:42:23 pptp,debug,packet rcvd Echo-Request from yy.yy.yy.yy 
15:42:23 pptp,debug,packet     identifier=1830 
15:42:23 pptp,debug,packet sent Echo-Reply to yy.yy.yy.yy 
15:42:23 pptp,debug,packet     identifier=1830 
15:42:23 pptp,debug,packet     result-code=1 
15:42:23 pptp,debug,packet     error-code=0 
15:42:24 ovpn,info China-ASUS-Ovpn: terminating... 
15:42:24 ovpn,info China-ASUS-Ovpn: disconnected 

 = = =   = = =   = = =      = = =   = = =   = = =      = = =   = = =   = = =

15:42:33 pptp,ppp,debug,packet  <1679>: sent LCP EchoReq id=0x0 
15:42:33 pptp,ppp,debug,packet     <magic 0x1c67cb35> 
15:42:34 pptp,ppp,debug <1679>: LCP missed echo reply 
15:42:34 pptp,ppp,debug,packet  <1679>: sent LCP EchoReq id=0x1 
15:42:34 pptp,ppp,debug,packet     <magic 0x1c67cb35> 
15:42:35 pptp,ppp,debug <1679>: LCP missed echo reply 
15:42:35 pptp,ppp,debug,packet  <1679>: sent LCP EchoReq id=0x2 
15:42:35 pptp,ppp,debug,packet     <magic 0x1c67cb35> 
15:42:36 pptp,ppp,debug <1679>: LCP missed echo reply 
15:42:36 pptp,ppp,debug,packet  <1679>: sent LCP EchoReq id=0x3 
15:42:36 pptp,ppp,debug,packet     <magic 0x1c67cb35> 
15:42:37 pptp,ppp,debug <1679>: LCP missed echo reply 
15:42:37 pptp,ppp,debug,packet  <1679>: sent LCP EchoReq id=0x4 
15:42:37 pptp,ppp,debug,packet     <magic 0x1c67cb35> 
15:42:38 pptp,ppp,debug <1679>: LCP missed echo reply 
15:42:38 pptp,ppp,debug <1679>: LCP lowerdown 
15:42:38 pptp,ppp,debug <1679>: LCP closed 
15:42:38 pptp,ppp,debug <1679>: CCP lowerdown 
15:42:38 pptp,ppp,debug <1679>: CCP closed 
15:42:38 pptp,ppp,debug <1679>: BCP lowerdown 
15:42:38 pptp,ppp,debug <1679>: BCP down event in starting state 
15:42:38 pptp,ppp,debug <1679>: IPCP lowerdown 
15:42:38 pptp,ppp,debug <1679>: IPCP closed 
15:42:38 pptp,ppp,debug <1679>: IPV6CP lowerdown 
15:42:38 pptp,ppp,debug <1679>: IPV6CP closed 
15:42:38 pptp,ppp,debug <1679>: MPLSCP lowerdown 
15:42:38 pptp,ppp,debug <1679>: MPLSCP closed 
15:42:38 pptp,ppp,info <pptp-xxxx>: terminating... - peer is not responding 
15:42:38 pptp,ppp,debug <1679>: LCP lowerdown 
15:42:38 pptp,ppp,debug <1679>: LCP down event in starting state 
15:42:38 pptp,ppp,info,account xxxx logged out, 66 162 238 10 11 
15:42:38 pptp,ppp,info <pptp-xxxx>: disconnected

I’ve compared this with the connection established by the Mikrotik in Switzerland and there is no difference in the startup log other than session id#s …

15:50:48 pptp,info TCP connection established from yy.yy.yy.yy 
15:50:48 pptp,debug,packet rcvd Start-Control-Connection-Request from yy.yy.yy.yy 
15:50:48 pptp,debug,packet     protocol-version=0x0100 
15:50:48 pptp,debug,packet     framing-capabilities=2 
15:50:48 pptp,debug,packet     bearer-capabilities=0 
15:50:48 pptp,debug,packet     maximum-channels=0 
15:50:48 pptp,debug,packet     firmware-revision=1 
15:50:48 pptp,debug,packet     host-name=MikroTik 
15:50:48 pptp,debug,packet     vendor-name=MikroTik 
15:50:48 pptp,debug,packet sent Start-Control-Connection-Reply to yy.yy.yy.yy 
15:50:48 pptp,debug,packet     protocol-version=0x0100 
15:50:48 pptp,debug,packet     result-code=1 
15:50:48 pptp,debug,packet     error-code=0 
15:50:48 pptp,debug,packet     framing-capabilities=2 
15:50:48 pptp,debug,packet     bearer-capabilities=0 
15:50:48 pptp,debug,packet     maximum-channels=0 
15:50:48 pptp,debug,packet     firmware-revision=1 
15:50:48 pptp,debug,packet     host-name=MikroTik 
15:50:48 pptp,debug,packet     vendor-name=MikroTik 
15:50:48 pptp,debug,packet rcvd Outgoing-Call-Request from yy.yy.yy.yy 
15:50:48 pptp,debug,packet     call-id=0 
15:50:48 pptp,debug,packet     call-serial-number=0 
15:50:48 pptp,debug,packet     minimum-bps=2400 
15:50:48 pptp,debug,packet     maximum-bps=10000000 
15:50:48 pptp,debug,packet     bearer-type=3 
15:50:48 pptp,debug,packet     framing-type=2 
15:50:48 pptp,debug,packet     packet-recv-window-size=100 
15:50:48 pptp,debug,packet     packet-processing-delay=0 
15:50:48 pptp,debug,packet     phone-number-length=0 
15:50:48 pptp,debug,packet     phone-number= 
15:50:48 pptp,debug,packet     subaddress= 
15:50:48 pptp,ppp,debug <1688>: LCP lowerup 
15:50:48 pptp,ppp,debug <1688>: LCP open 
15:50:48 pptp,debug,packet sent Outgoing-Call-Reply to yy.yy.yy.yy 
15:50:48 pptp,debug,packet     call-id=1688 
15:50:48 pptp,debug,packet     peers-call-id=0 
15:50:48 pptp,debug,packet     result-code=1 
15:50:48 pptp,debug,packet     error-code=0 
15:50:48 pptp,debug,packet     cause-code=0 
15:50:48 pptp,debug,packet     connect-speed=100000 
15:50:48 pptp,debug,packet     packet-recv-window-size=100 
15:50:48 pptp,debug,packet     packet-processing-delay=0 
15:50:48 pptp,debug,packet     physical-channel-id=0 
15:50:48 pptp,ppp,debug,packet  <1688>: rcvd LCP ConfReq id=0x39 
15:50:48 pptp,ppp,debug,packet    <mru 1460> 
15:50:48 pptp,ppp,debug,packet    <magic 0x74906448> 
15:50:48 pptp,ppp,debug,packet  <1688>: sent LCP ConfReq id=0x1 
15:50:48 pptp,ppp,debug,packet    <mru 1460> 
15:50:48 pptp,ppp,debug,packet    <magic 0x28156061> 
15:50:48 pptp,ppp,debug,packet    <auth  mschap2> 
15:50:48 pptp,ppp,debug,packet  <1688>: sent LCP ConfAck id=0x39 
15:50:48 pptp,ppp,debug,packet    <mru 1460> 
15:50:48 pptp,ppp,debug,packet    <magic 0x74906448> 
15:50:48 pptp,ppp,debug,packet  <1688>: rcvd LCP ConfAck id=0x1 
15:50:48 pptp,ppp,debug,packet    <mru 1460> 
15:50:48 pptp,ppp,debug,packet    <magic 0x28156061> 
15:50:48 pptp,ppp,debug,packet    <auth  mschap2> 
15:50:48 pptp,ppp,debug <1688>: LCP opened 
15:50:48 pptp,ppp,debug,packet  <1688>: sent CHAP Challenge id=0x1 
15:50:48 pptp,ppp,debug,packet     <challenge len=16> 
15:50:48 pptp,ppp,debug,packet     <name MikroTik> 
15:50:48 pptp,ppp,debug,packet  <1688>: rcvd CHAP Response id=0x1 
15:50:48 pptp,ppp,debug,packet     <response len=49> 
15:50:48 pptp,ppp,debug,packet     <name yyyy> 
15:50:48 pptp,ppp,info,account yyyy logged in, 172.16.1.6 
15:50:48 pptp,ppp,debug,packet  <1688>: sent CHAP Success id=0x1 
15:50:48 pptp,ppp,debug,packet     S=4F7353A347DB4FC5B8335C07B7E8B4A24C9FFF58 
15:50:48 pptp,ppp,info <pptp-yyyy>: authenticated 
15:50:48 pptp,ppp,debug <1688>: IPCP lowerup 
15:50:48 pptp,ppp,debug <1688>: IPCP open 
15:50:48 pptp,ppp,debug,packet  <1688>: sent IPCP ConfReq id=0x1 
15:50:48 pptp,ppp,debug,packet     <addr 172.16.1.5> 
15:50:48 pptp,ppp,debug <1688>: IPV6CP lowerup 
15:50:48 pptp,ppp,debug <1688>: IPV6CP open 
15:50:48 pptp,ppp,debug,packet  <1688>: sent IPV6CP ConfReq id=0x1 
15:50:48 pptp,ppp,debug,packet     <interface-identifier 0:0:f0:696> 
15:50:48 pptp,ppp,debug <1688>: MPLSCP lowerup 
15:50:48 pptp,ppp,debug <1688>: MPLSCP open 
15:50:48 pptp,ppp,debug,packet  <1688>: sent MPLSCP ConfReq id=0x1 
15:50:48 pptp,ppp,debug <1688>: BCP open 
15:50:48 pptp,ppp,debug <1688>: CCP lowerup 
15:50:48 pptp,ppp,debug <1688>: CCP open 
15:50:48 pptp,ppp,debug,packet  <1688>: sent CCP ConfReq id=0x1 
15:50:48 pptp,ppp,debug,packet     <mppe 1000040> 
15:50:48 pptp,ppp,debug,packet  <1688>: rcvd IPCP ConfReq id=0x11 
15:50:48 pptp,ppp,debug,packet     <addr 0.0.0.0> 
15:50:49 pptp,ppp,debug,packet  <1688>: sent IPCP ConfNak id=0x11 
15:50:49 pptp,ppp,debug,packet     <addr 172.16.1.6> 
15:50:49 pptp,ppp,debug,packet  <1688>: rcvd IPV6CP ConfReq id=0x9 
15:50:49 pptp,ppp,debug,packet     <interface-identifier 0:0:0:a> 
15:50:49 pptp,ppp,debug,packet  <1688>: sent IPV6CP ConfAck id=0x9 
15:50:49 pptp,ppp,debug,packet     <interface-identifier 0:0:0:a> 
15:50:49 pptp,ppp,debug,packet  <1688>: rcvd MPLSCP ConfReq id=0x9 
15:50:49 pptp,ppp,debug,packet  <1688>: sent MPLSCP ConfAck id=0x9 
15:50:49 pptp,ppp,debug,packet  <1688>: rcvd CCP ConfReq id=0x9 
15:50:49 pptp,ppp,debug,packet     <mppe 1000040> 
15:50:49 pptp,ppp,debug,packet  <1688>: sent CCP ConfAck id=0x9 
15:50:49 pptp,ppp,debug,packet     <mppe 1000040> 
15:50:49 pptp,ppp,debug,packet  <1688>: rcvd IPCP ConfAck id=0x1 
15:50:49 pptp,ppp,debug,packet     <addr 172.16.1.5> 
15:50:49 pptp,ppp,debug,packet  <1688>: rcvd IPV6CP ConfAck id=0x1 
15:50:49 pptp,ppp,debug,packet     <interface-identifier 0:0:f0:696> 
15:50:49 pptp,ppp,debug <1688>: IPV6CP opened 
15:50:49 pptp,ppp,info <pptp-yyyy>: connected 
15:50:49 pptp,ppp,debug,packet  <1688>: rcvd MPLSCP ConfAck id=0x1 
15:50:49 pptp,ppp,debug <1688>: MPLSCP opened 
15:50:49 pptp,ppp,debug,packet  <1688>: rcvd CCP ConfAck id=0x1 
15:50:49 pptp,ppp,debug,packet     <mppe 1000040> 
15:50:49 pptp,ppp,debug <1688>: CCP opened 
15:50:49 pptp,ppp,info <pptp-yyyy>: using encoding - MPPE128 stateless 
15:50:49 pptp,ppp,debug,packet  <1688>: rcvd IPCP ConfReq id=0x12 
15:50:49 pptp,ppp,debug,packet     <addr 172.16.1.6> 
15:50:49 pptp,ppp,debug,packet  <1688>: sent IPCP ConfAck id=0x12 
15:50:49 pptp,ppp,debug,packet     <addr 172.16.1.6> 
15:50:49 pptp,ppp,debug <1688>: IPCP opened

Why can’t I route the Chinese subnets? and why won’t the link stay up for more than 65 seconds?

banjo · March 20, 2015, 11:23am

Some more details on the issue …

I have replaced the ASUS with another Mikrotik and configured it to use the same pptp user. This Mikrotik also fails to connect intermittently over pptp.

Sometimes I will get a perfect pptp link which stays up for days and allows me to route my 192.168 subnets, but if I do something as innocuous as “/ip route set gateway=pptp-uk numbers=16,17” then the pptp link fails, and goes into a loop of connecting for 65secs, dropping, and reconnecting. Whilst its looping like this I cant route my 192.168 subnets.

Why would something as unrelated as changing a route cause pptp to fail in this way?

(The only thing that has changed recently is that I upgraded all Mikrotiks to 6.27, and the one in the UK is now missing the routeros-mipsbe-6.27 package).

banjo · March 21, 2015, 5:23pm

Doh! - Just worked out why the router’s in China didn’t work, especially when touching the routing tables.

I had a routing entry to “jump the wall” for a range of IP address in the UK, but my pptp-server was in that range. So sometimes routing would work and sometimes not, depending upon whether or not the pptp-client module was trying to contact the pptp-server recursively via its own ppp link or correctly via the ISP.

soamz · June 5, 2016, 7:45am

Did you solve this ?

How ?