OpenWrt Forum Archive

Topic: PPTP disconnects after a minute: No response to 5 echo-requests

The content of this topic has been archived on 3 May 2018. There are no obvious gaps in this topic, but there may still be some posts missing at the end.

Hi. I have a TP-Link TL-WDR4300 router with Barrier Braker trunk r35819 installed on it. I'm trying to configure a VPN tunnel, but after about one minute of successful connection, the tunnel collapses, and I receive the following error.

Log:

Feb 28 11:33:35 OpenWrt daemon.info pppd[2301]: Plugin pptp.so loaded.
Feb 28 11:33:35 OpenWrt daemon.info pppd[2301]: PPTP plugin version 1.00
Feb 28 11:33:35 OpenWrt daemon.notice pppd[2301]: pppd 2.4.5 started by root, uid 0
Feb 28 11:33:35 OpenWrt daemon.debug pppd[2302]: pptp: call manager for xxx.xxx.36.25
Feb 28 11:33:35 OpenWrt daemon.debug pppd[2302]: window size:    50
Feb 28 11:33:35 OpenWrt daemon.debug pppd[2302]: call id:    1
Feb 28 11:33:35 OpenWrt daemon.debug pppd[2302]: control connection
Feb 28 11:33:35 OpenWrt daemon.debug pppd[2302]: unix_sock
Feb 28 11:33:35 OpenWrt daemon.debug pppd[2303]: Sent control packet type is 1 'Start-Control-Connection-Request'
Feb 28 11:33:35 OpenWrt daemon.debug pppd[2303]: Received Start Control Connection Reply
Feb 28 11:33:35 OpenWrt daemon.debug pppd[2303]: Client connection established.
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2303]: Sent control packet type is 7 'Outgoing-Call-Request'
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2303]: Received Outgoing Call Reply.
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2303]: Outgoing call established (call ID 1, peer's call ID 25012).
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: using channel 1
Feb 28 11:33:36 OpenWrt daemon.info pppd[2301]: Using interface pptp-vpn
Feb 28 11:33:36 OpenWrt daemon.notice pppd[2301]: Connect: pptp-vpn <--> pptp (vpn.foo.org)
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x192f029c>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [LCP ConfReq id=0x0 <mru 1400> <auth eap> <magic 0x499402a5> <pcomp> <accomp> <callback CBCP> <mrru 1614> <endpoint 13 17 01 bd d0 cc 00 bf 54 40 1c bc be 58 ec 9a bf e4 ae 00 00 00 00>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [LCP ConfRej id=0x0 <pcomp> <accomp> <callback CBCP> <mrru 1614>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x192f029c>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [LCP ConfReq id=0x1 <mru 1400> <auth eap> <magic 0x499402a5> <endpoint 13 17 01 bd d0 cc 00 bf 54 40 1c bc be 58 ec 9a bf e4 ae 00 00 00 00>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [LCP ConfNak id=0x1 <auth chap MS-v2>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [LCP ConfReq id=0x2 <mru 1400> <auth chap MS-v2> <magic 0x499402a5> <endpoint 13 17 01 bd d0 cc 00 bf 54 40 1c bc be 58 ec 9a bf e4 ae 00 00 00 00>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [LCP ConfAck id=0x2 <mru 1400> <auth chap MS-v2> <magic 0x499402a5> <endpoint 13 17 01 bd d0 cc 00 bf 54 40 1c bc be 58 ec 9a bf e4 ae 00 00 00 00>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [LCP EchoReq id=0x0 magic=0x192f029c]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2303]: PPTP_SET_LINK_INFO received from peer_callid 1
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2303]:   send_accm is %lX, recv_accm is %lX
Feb 28 11:33:36 OpenWrt daemon.warn pppd[2303]: Non-zero Async Control Character Maps are not supported!
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [CHAP Challenge id=0x0 <08716b9cef6a0bd6fa22f402c56a93f6>, name = "VPN"]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [CHAP Response id=0x0 <ec32d42faa7a5c423cabe5f5c83a411c0000000000000000b88192ad0daf7efbba73785a66ea02224e3e317d2d843f3e00>, name = "bkeresz"]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [LCP EchoRep id=0x0 magic=0x499402a5]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [CHAP Success id=0x0 "S=03186B3090888C490194BA355E20624F67A7946F"]
Feb 28 11:33:36 OpenWrt daemon.notice pppd[2301]: CHAP authentication succeeded
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [CCP ConfReq id=0x1 <mppe +H -M +S -L -D -C>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [CCP ConfReq id=0x4 <mppe +H -M -S -L -D +C>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [CCP ConfNak id=0x4 <mppe +H -M +S -L -D +C>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [IPCP ConfReq id=0x5 <addr xxx.xxx.156.1>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [IPCP TermAck id=0x5]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [CCP ConfAck id=0x1 <mppe +H -M +S -L -D -C>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [CCP ConfReq id=0x6 <mppe +H -M +S -L -D +C>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [CCP ConfNak id=0x6 <mppe +H -M +S -L -D -C>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [CCP ConfReq id=0x7 <mppe +H -M +S -L -D -C>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [CCP ConfAck id=0x7 <mppe +H -M +S -L -D -C>]
Feb 28 11:33:36 OpenWrt daemon.notice pppd[2301]: MPPE 128-bit stateless compression enabled
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [IPCP ConfNak id=0x2 <addr xxx.xxx.156.142> <ms-dns1 xxx.xxx.36.22> <ms-dns2 xxx.xxx.36.20>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: sent [IPCP ConfReq id=0x3 <addr xxx.xxx.156.142> <ms-dns1 xxx.xxx.36.22> <ms-dns2 xxx.xxx.36.20>]
Feb 28 11:33:36 OpenWrt daemon.debug pppd[2301]: rcvd [IPCP ConfAck id=0x3 <addr xxx.xxx.156.142> <ms-dns1 xxx.xxx.36.22> <ms-dns2 xxx.xxx.36.20>]
Feb 28 11:33:37 OpenWrt daemon.debug pppd[2301]: sent [LCP EchoReq id=0x1 magic=0x192f029c]
Feb 28 11:33:37 OpenWrt daemon.debug pppd[2301]: rcvd [LCP EchoRep id=0x1 magic=0x499402a5]
Feb 28 11:33:37 OpenWrt daemon.debug pppd[2301]: rcvd [IPCP ConfReq id=0x8 <addr xxx.xxx.156.1>]
Feb 28 11:33:37 OpenWrt daemon.debug pppd[2301]: sent [IPCP ConfAck id=0x8 <addr xxx.xxx.156.1>]
Feb 28 11:33:37 OpenWrt daemon.notice pppd[2301]: local  IP address xxx.xxx.156.142
Feb 28 11:33:37 OpenWrt daemon.notice pppd[2301]: remote IP address xxx.xxx.156.1
Feb 28 11:33:37 OpenWrt daemon.notice pppd[2301]: primary   DNS address xxx.xxx.36.22
Feb 28 11:33:37 OpenWrt daemon.notice pppd[2301]: secondary DNS address xxx.xxx.36.20
Feb 28 11:33:37 OpenWrt daemon.debug pppd[2301]: Script /lib/netifd/ppp-up started (pid 2317)
Feb 28 11:33:37 OpenWrt daemon.notice netifd: Interface 'vpn' is now up
Feb 28 11:33:37 OpenWrt daemon.debug pppd[2301]: Script /lib/netifd/ppp-up finished (pid 2317), status = 0x1
Feb 28 11:33:39 OpenWrt user.info firewall: adding vpn (pptp-vpn) to zone vpn
Feb 28 11:33:40 OpenWrt daemon.info dnsmasq[2250]: reading /tmp/resolv.conf.auto
Feb 28 11:33:40 OpenWrt daemon.info dnsmasq[2250]: using nameserver xxx.yyy.246.53#53
Feb 28 11:33:40 OpenWrt daemon.info dnsmasq[2250]: using nameserver xxx.yyy.246.54#53
Feb 28 11:33:40 OpenWrt daemon.info dnsmasq[2250]: using local addresses only for domain lan
Feb 28 11:34:36 OpenWrt daemon.warn pppd[2303]: read error: Connection reset by peer
Feb 28 11:34:36 OpenWrt daemon.debug pppd[2303]: Closing connection (shutdown)
Feb 28 11:34:36 OpenWrt daemon.warn pppd[2303]: write error: Broken pipe
Feb 28 11:34:36 OpenWrt daemon.debug pppd[2303]: Closing connection (call state)
Feb 28 11:34:36 OpenWrt daemon.err pppd[2303]: Fatal signal 11
Feb 28 11:34:36 OpenWrt daemon.info pppd[2303]: Exit.
Feb 28 11:34:40 OpenWrt daemon.info pppd[2301]: No response to 5 echo-requests
Feb 28 11:34:40 OpenWrt daemon.notice pppd[2301]: Serial link appears to be disconnected.
Feb 28 11:34:40 OpenWrt daemon.info pppd[2301]: Connect time 1.1 minutes.
Feb 28 11:34:40 OpenWrt daemon.info pppd[2301]: Sent 80 bytes, received 5995 bytes.
Feb 28 11:34:40 OpenWrt daemon.debug pppd[2301]: Script /lib/netifd/ppp-down started (pid 2414)
Feb 28 11:34:40 OpenWrt daemon.err pppd[2301]: MPPE disabled
Feb 28 11:34:40 OpenWrt daemon.debug pppd[2301]: sent [LCP TermReq id=0x2 "MPPE disabled"]
Feb 28 11:34:40 OpenWrt daemon.debug pppd[2301]: sent [LCP TermReq id=0x3 "MPPE disabled"]
Feb 28 11:34:40 OpenWrt daemon.notice netifd: Interface 'vpn' has lost the connection
Feb 28 11:34:40 OpenWrt daemon.debug pppd[2301]: Script /lib/netifd/ppp-down finished (pid 2414), status = 0x1
Feb 28 11:34:41 OpenWrt user.info firewall: removing vpn (pptp-vpn) from zone vpn
Feb 28 11:34:43 OpenWrt daemon.debug pppd[2301]: sent [LCP TermReq id=0x4 "MPPE disabled"]
Feb 28 11:34:43 OpenWrt daemon.notice pppd[2301]: Connection terminated.
Feb 28 11:34:43 OpenWrt daemon.notice pppd[2301]: Modem hangup
Feb 28 11:35:07 OpenWrt daemon.info dnsmasq[2250]: reading /tmp/resolv.conf.auto
Feb 28 11:35:07 OpenWrt daemon.info dnsmasq[2250]: using nameserver xxx.yyy.246.53#53
Feb 28 11:35:07 OpenWrt daemon.info dnsmasq[2250]: using nameserver xxx.yyy.246.54#53
Feb 28 11:35:07 OpenWrt daemon.info dnsmasq[2250]: using local addresses only for domain lan 

/etc/ppp/options.pptp

noipdefault
noauth
nobsdcomp
nodeflate
idle 0
mppe required,no40,no56,stateless
maxfail 0

debug
refuse-pap
refuse-eap
refuse-chap
refuse-mschap

/etc/config/network

config interface 'loopback'
    option ifname 'lo'
    option proto 'static'
    option ipaddr '127.0.0.1'
    option netmask '255.0.0.0'

config interface 'lan'
    option ifname 'eth0.1'
    option type 'bridge'
    option proto 'static'
    option ipaddr '192.168.1.1'
    option netmask '255.255.255.0'

config interface 'wan'
    option ifname 'eth0.2'
    option proto 'dhcp'

config switch
    option name 'switch0'
    option reset '1'
    option enable_vlan '1'

config switch_vlan
    option device 'switch0'
    option vlan '1'
    option ports '0t 2 3 4 5'

config switch_vlan
    option device 'switch0'
    option vlan '2'
    option ports '0t 1'

config interface 'vpn'
    option proto 'pptp'
    option server 'vpn.foo.org'
    option username 'xxx'
    option password 'yyy'
    option peerdns '0'
    option defaultroute '0'
    option auto '0'

config route
    option interface 'vpn'
    option target 'xxx.xxx.0.0'
    option netmask '255.255.0.0'
    option gateway 'xxx.xxx.156.1'

/etc/config/firewall

config defaults
    option syn_flood '1'
    option input 'ACCEPT'
    option output 'ACCEPT'
    option forward 'REJECT'

config zone
    option name 'lan'
    option network 'lan'
    option input 'ACCEPT'
    option output 'ACCEPT'
    option forward 'REJECT'

config zone
    option name 'wan'
    option network 'wan'
    option input 'REJECT'
    option output 'ACCEPT'
    option forward 'REJECT'
    option masq '1'
    option mtu_fix '1'

config rule
    option name 'Allow-DHCP-Renew'
    option src 'wan'
    option proto 'udp'
    option dest_port '68'
    option target 'ACCEPT'
    option family 'ipv4'

config rule
    option name 'Allow-Ping'
    option src 'wan'
    option proto 'icmp'
    option icmp_type 'echo-request'
    option family 'ipv4'
    option target 'ACCEPT'

config rule
    option name 'Allow-DHCPv6'
    option src 'wan'
    option proto 'udp'
    option src_ip 'fe80::/10'
    option src_port '547'
    option dest_ip 'fe80::/10'
    option dest_port '546'
    option family 'ipv6'
    option target 'ACCEPT'

config rule
    option name 'Allow-ICMPv6-Input'
    option src 'wan'
    option proto 'icmp'
    list icmp_type 'echo-request'
    list icmp_type 'echo-reply'
    list icmp_type 'destination-unreachable'
    list icmp_type 'packet-too-big'
    list icmp_type 'time-exceeded'
    list icmp_type 'bad-header'
    list icmp_type 'unknown-header-type'
    list icmp_type 'router-solicitation'
    list icmp_type 'neighbour-solicitation'
    list icmp_type 'router-advertisement'
    list icmp_type 'neighbour-advertisement'
    option limit '1000/sec'
    option family 'ipv6'
    option target 'ACCEPT'

config rule
    option name 'Allow-ICMPv6-Forward'
    option src 'wan'
    option dest '*'
    option proto 'icmp'
    list icmp_type 'echo-request'
    list icmp_type 'echo-reply'
    list icmp_type 'destination-unreachable'
    list icmp_type 'packet-too-big'
    list icmp_type 'time-exceeded'
    list icmp_type 'bad-header'
    list icmp_type 'unknown-header-type'
    option limit '1000/sec'
    option family 'ipv6'
    option target 'ACCEPT'

config rule
    option name 'Enforce-ULA-Border-Src'
    option src '*'
    option dest 'wan'
    option proto 'all'
    option src_ip 'fc00::/7'
    option family 'ipv6'
    option target 'REJECT'

config rule
    option name 'Enforce-ULA-Border-Dest'
    option src '*'
    option dest 'wan'
    option proto 'all'
    option dest_ip 'fc00::/7'
    option family 'ipv6'
    option target 'REJECT'

config include
    option path '/etc/firewall.user'

config zone
    option name 'vpn'
    option forward 'REJECT'
    option output 'ACCEPT'
    option network 'vpn'
    option masq '1'
    option mtu_fix '1'
    option input 'REJECT'

config forwarding
    option dest 'vpn'
    option src 'lan'

config forwarding
    option dest 'wan'
    option src 'lan'

config rule
    option target 'ACCEPT'
    option name 'Allow-Ping-VPN'
    option proto 'icmp'
    option src 'vpn'
    option family 'ipv4'
  

Any idea?

Bump!

2 methods.


1.
Keep it simple. No need to create new zone for vpn. Modify your wan zone and add vpn as another interface

config zone
    option name 'wan'
    option network 'wan vpn'

you can roll back all changes to file firewall.
your /etc/config/network seems ok.

2. if you must keep vpn as a zone then,

go and copy all rules that you see for wan and add similar rule for vpn.
e-g
config rule
    option name 'Allow-Ping'
    option src 'wan'
    option proto 'icmp'
    option icmp_type 'echo-request'
    option family 'ipv4'
    option target 'ACCEPT'

make one for vpn and using 'vpn' in src
replicate all.
I think either will work, however 1 seems simpler.

Thanks for your answer, but putting them into the same zone didn't help. Disconnection still occurs after 60 seconds sad

if its not the firewall issue, then perhaps you need to enable echo from your pptp client. The server may be expecting the echo and may disconnect you after 60 seconds or so. This is also what the message connection reset by peer means. i.e the communication was ended by the remote side. so look for /etc/ppp/options
and add

lcp-echo-failure 10
lcp-echo-interval 6
if not already there.

These settings (with different numbers though) have been already included, and changing the numbers only postpone the connection and leaves it in a frozen state after one minute.
Maybe I should open a ticket for this? I'm afraid the devs won't be able to replicate the issue without the credentials and the exact config of the server

if you have those settings, then you need to verify that they are in effect. pppd will log these settings when it starts for the first time (debug flag should be enabled). So check your log and ensure you have the two settings.
From what I see, the remote side is resetting the connection. Which means it thinks your side is dead. Which could mean

1) your pppd is not sending echos
2)your pppd is not sending echos fast enough (may be your interval is set for 60 sec by which time the remote thinks ur dead)
3)your pppd is sending echos, but they are not reaching the remote side (could be because of firewall or routing problem for example)

for the one minute when your vpn is up, did you try to ping the remote side ?
your remote side addr is xxx.xxx.156.1 (from logs)
so do a ping and see if u can get icmp through.
if you can't ping, may be you dont have a route to your vpn. check your route tables after ur vpn is connected. u will have just 1 min or less to do all this wink

The discussion might have continued from here.