PPTP connection unstable - drops after 25s to 43s

RouterOS General
1

Hi,

I have got a setup in which the MT ROS 6.2 handles PPPoE out to connect to a DSL line but provides PPTP services inbound. While I have got this working in general, the inbound connection does not stay up for longer than 43 seconds but will be established for at least 25 seconds.

connecting client is a Ubuntu Desktop at 47.68.35.56
pppoe-TTL is the PPPoE out connection on MT that establishes the connection to the ISP via DSL.

MT Log:

jan/28 01:09:27 pptp,ppp,debug,packet     <name kellieg> 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent CHAP Success id=0x1 
jan/28 01:09:27 pptp,ppp,debug,packet     S=71DF46EBC5911D96F0F0F8B6C468ED4CF544D83
E 
jan/28 01:09:27 pptp,ppp,info <pptp-0>: authenticated 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: IPCP lowerup 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: IPCP open 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent IPCP ConfReq id=0x1 
jan/28 01:09:27 pptp,ppp,debug,packet     <addr 192.168.143.254> 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: IPV6CP open 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: MPLSCP lowerup 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: MPLSCP open 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent MPLSCP ConfReq id=0x1 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: BCP open 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: CCP lowerup 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: CCP open 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent CCP ConfReq id=0x1 
jan/28 01:09:27 pptp,ppp,debug,packet     <mppe 1000060> 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: rcvd IPCP ConfReq id=0x1 
jan/28 01:09:27 pptp,ppp,debug,packet     <addr 0.0.0.0> 
jan/28 01:09:27 pptp,ppp,debug,packet     <ms-dns 0.0.0.0> 
jan/28 01:09:27 pptp,ppp,debug,packet     <ms-dns 0.0.0.0> 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent IPCP ConfRej id=0x1 
jan/28 01:09:27 pptp,ppp,debug,packet     <ms-dns 0.0.0.0> 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: rcvd LCP ProtRej id=0x3 
jan/28 01:09:27 pptp,ppp,debug,packet      82 81 01 01 00 04 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: rcvd IPCP ConfAck id=0x1 
jan/28 01:09:27 pptp,ppp,debug,packet     <addr 192.168.143.254> 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: rcvd CCP ConfReq id=0x1 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent CCP ConfAck id=0x1 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: rcvd CCP ConfRej id=0x1 
jan/28 01:09:27 pptp,ppp,debug,packet     <mppe 1000060> 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent CCP ConfReq id=0x2 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: rcvd IPCP ConfReq id=0x2 
jan/28 01:09:27 pptp,ppp,debug,packet     <addr 0.0.0.0> 
jan/28 01:09:27 pptp,ppp,debug,packet     <ms-dns 0.0.0.0> 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent IPCP ConfNak id=0x2 
jan/28 01:09:27 pptp,ppp,debug,packet     <addr 192.168.143.1> 
jan/28 01:09:27 pptp,ppp,debug,packet     <ms-dns 192.168.140.1> 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: rcvd CCP ConfAck id=0x2 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: CCP opened 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: CCP close 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: CCP closed 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent CCP TermReq id=0x3 
jan/28 01:09:27 pptp,ppp,debug,packet     No compression negotiated\00 
jan/28 01:09:27 pptp,ppp,debug <47.68.35.56>: IPCP timer 
jan/28 01:09:27 pptp,ppp,debug,packet  <47.68.35.56>: sent IPCP ConfReq id=0x2
jan/28 01:09:27 pptp,ppp,debug,packet     <addr 192.168.143.254> 
jan/28 01:09:28 pptp,ppp,debug,packet  <47.68.35.56>: rcvd IPCP ConfReq id=0x3 
jan/28 01:09:28 pptp,ppp,debug,packet     <addr 192.168.143.1> 
jan/28 01:09:28 pptp,ppp,debug,packet     <ms-dns 192.168.140.1> 
jan/28 01:09:28 pptp,ppp,debug,packet  <47.68.35.56>: sent IPCP ConfAck id=0x3 
jan/28 01:09:28 pptp,ppp,debug,packet     <addr 192.168.143.1> 
jan/28 01:09:28 pptp,ppp,debug,packet     <ms-dns 192.168.140.1> 
jan/28 01:09:28 pptp,ppp,debug,packet  <47.68.35.56>: rcvd CCP TermAck id=0x3 
jan/28 01:09:28 pptp,ppp,debug,packet  <47.68.35.56>: rcvd IPCP ConfAck id=0x2 
jan/28 01:09:28 pptp,ppp,debug,packet     <addr 192.168.143.254> 
jan/28 01:09:28 pptp,ppp,debug <47.68.35.56>: IPCP opened 
jan/28 01:09:28 pptp,ppp,info <pptp-0>: connected 
jan/28 01:09:28 pptp,ppp,info,account kellieg logged in, 192.168.143.1 
jan/28 01:09:29 pppoe,ppp,debug,packet  pppoe-TTL: rcvd LCP EchoReq id=0x20 
jan/28 01:09:29 pppoe,ppp,debug,packet     <magic 0x3001faca> 
jan/28 01:09:29 pppoe,ppp,debug,packet  pppoe-TTL: sent LCP EchoRep id=0x20 
jan/28 01:09:29 pppoe,ppp,debug,packet     <magic 0x18ce71d8> 
jan/28 01:09:56 pptp,ppp,debug,packet  <47.68.35.56>: rcvd LCP EchoReq id=0x1 
jan/28 01:09:56 pptp,ppp,debug,packet     <magic 0x4c2e561a> 
jan/28 01:09:56 pptp,ppp,debug,packet  <47.68.35.56>: sent LCP EchoRep id=0x1 
jan/28 01:09:56 pptp,ppp,debug,packet     <magic 0x5112ca90> 
jan/28 01:09:59 pppoe,ppp,debug,packet  pppoe-TTL: rcvd LCP EchoReq id=0x21 
jan/28 01:09:59 pppoe,ppp,debug,packet     <magic 0x3001faca> 
jan/28 01:09:59 pppoe,ppp,debug,packet  pppoe-TTL: sent LCP EchoRep id=0x21 
jan/28 01:09:59 pppoe,ppp,debug,packet     <magic 0x18ce71d8> 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: LCP lowerdown 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: LCP closed 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: CCP lowerdown 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: BCP lowerdown 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: BCP down event in starting state 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: IPCP lowerdown 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: IPCP closed 
jan/28 01:10:13 pptp,ppp,info,account kellieg logged out, 46 9173 3868 95 54 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: IPV6CP lowerdown 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: IPV6CP down event in starting state 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: MPLSCP lowerdown 
jan/28 01:10:13 pptp,ppp,info <pptp-kellieg>: terminating... - call cleared 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: LCP lowerdown 
jan/28 01:10:13 pptp,ppp,debug <47.68.35.56>: LCP down event in starting state 
jan/28 01:10:13 pptp,ppp,info <pptp-kellieg>: disconnected



connecting client (Ubuntu desktop)

Jan 28 01:09:29 laptop NetworkManager: <info>  (ppp0): writing resolv.conf to /sbin/resolvconf
Jan 28 01:09:29 laptop NetworkManager: <info>  (ppp0): writing resolv.conf to /sbin/resolvconf
Jan 28 01:09:29 laptop NetworkManager: <info>  Policy set 'TTL' (ppp0) as default for routing and DNS.
Jan 28 01:10:00 laptop ntpd[2659]: Listening on interface #6 ppp0, 192.168.143.1#123 Enabled
Jan 28 01:10:13 laptop pppd[14560]: Modem hangup
Jan 28 01:10:13 laptop pppd[14560]: Connect time 0.8 minutes.
Jan 28 01:10:13 laptop pppd[14560]: Sent 10678 bytes, received 3754 bytes.
Jan 28 01:10:13 laptop pppd[14560]: Connection terminated.
Jan 28 01:10:13 laptop NetworkManager: <info>  (ppp0): writing resolv.conf to /sbin/resolvconf
Jan 28 01:10:14 laptop pppd[14560]: Exit.
Jan 28 01:10:14 laptop NetworkManager:    SCPlugin-Ifupdown: devices removed (path: /sys/devices/virtual/net/ppp0, iface: ppp0)

I am at my wits end as I cannot find out why the connection drops .. not even which side initiates the drop.

My next step is to trace the traffic on the client side to see if I can capture anything that is not logged.

Has anyone come across this before and/or maybe a clue as to why this happens?

Cheers,
Stefan

2

good old wireshark indicated that it’s the client sending a Call-Clear-Request packet to tcp.1723 of the PPtP server. At this stage I cannot see that this setting is derived from MT but therefore must reside on the Ubuntu machine.

This thread is no longer a MT related one (unless I find proof that this is a setting propagated from MT to the client).

Thanks,
Stefan