Regular disconnections - why?

Hi all, I've recently switched to Zen's unlimited VDSL2 fibre offer. Most of the time, I'm getting a decent connection (50Mbps down / 15Mbps up) but once or twice a day, the link seems to drop and come back up again, obviously breaking any gaming or streaming video, etc. that may be happening at the time. I'm trying to figure out where the problem lies.

My setup is:
Linux router --> VDSL modem --> Exchange

I'm guessing either my ethernet connection to the modem is faulty or the modem itself is dropping the DSL connection. I suspect the latter but how can I be sure? Is there some way I can regularly ping the VDSL modem to see whether ping failures coincide with the connection dropouts, or whether that link continues to be stable when the internet connection dies? Here is the output on my Linux terminal from when I brought the PPPoE connection up, having had one dropout:

[email protected]:/etc/ppp# pon dsl-provider debug dump logfd 2 nodetach
Plugin rp-pppoe.so loaded.
pppd options in effect:
debug # (from command line)
nodetach # (from command line)
holdoff 10 # (from /etc/ppp/peers/dsl-provider)
persist # (from /etc/ppp/peers/dsl-provider)
logfd 2 # (from command line)
dump # (from command line)
plugin rp-pppoe.so # (from /etc/ppp/peers/dsl-provider)
noauth # (from /etc/ppp/peers/dsl-provider)
user [email protected] # (from /etc/ppp/peers/dsl-provider)
eth0 # (from /etc/ppp/peers/dsl-provider)
eth0 # (from /etc/ppp/peers/dsl-provider)
asyncmap 0 # (from /etc/ppp/options)
lcp-echo-failure 4 # (from /etc/ppp/options)
lcp-echo-interval 30 # (from /etc/ppp/options)
hide-password # (from /etc/ppp/peers/dsl-provider)
noipdefault # (from /etc/ppp/peers/dsl-provider)
defaultroute # (from /etc/ppp/peers/dsl-provider)
replacedefaultroute # (from /etc/ppp/peers/dsl-provider)
usepeerdns # (from /etc/ppp/peers/dsl-provider)
noipx # (from /etc/ppp/options)
Send PPPOE Discovery V1T1 PADI session 0x0 length 12
dst ff:ff:ff:ff:ff:ff src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00]
Recv PPPOE Discovery V1T1 PADT session 0x158 length 0
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX

Send PPPOE Discovery V1T1 PADI session 0x0 length 12
dst ff:ff:ff:ff:ff:ff src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00]
Recv PPPOE Discovery V1T1 PADO session 0x0 length 43
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX
[host-uniq c9 30 00 00] [AC-name bras-red9.dy-B226E1811E038E] [service-name]
Send PPPOE Discovery V1T1 PADR session 0x0 length 12
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00]
Recv PPPOE Discovery V1T1 PADS session 0x159 length 43
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00] [AC-name bras-red9.dy-B226E1811E038E]
PADS: Service-Name: ''
PPP session is 345
Connected to XX:XX:XX:XX:XX:XX via interface eth0
using channel 9
Using interface ppp0
Connect: ppp0 <--> eth0
sent [LCP ConfReq id=0x1 <mru 1492> <magic 0xba05a0f0>]
rcvd [LCP ConfReq id=0x78 <mru 1492> <auth chap MD5> <magic 0x5b926101>]
sent [LCP ConfAck id=0x78 <mru 1492> <auth chap MD5> <magic 0x5b926101>]
rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0xba05a0f0>]
sent [LCP EchoReq id=0x0 magic=0xba05a0f0]
rcvd [CHAP Challenge id=0x1 <30da2b61385610032672840719fb4802>, name = "bras-red9.dy"]
sent [CHAP Response id=0x1 <057efd5df161dc345017ac01a5990968>, name = "[email protected]"]
rcvd [LCP EchoRep id=0x0 magic=0x5b926101]
rcvd [LCP ConfReq id=0xc7 <mru 1492> <auth chap MD5> <magic 0x5b926101>]
sent [LCP ConfReq id=0x2 <mru 1492> <magic 0x8334258>]
sent [LCP ConfAck id=0xc7 <mru 1492> <auth chap MD5> <magic 0x5b926101>]
rcvd [LCP ConfAck id=0x2 <mru 1492> <magic 0x8334258>]
sent [LCP EchoReq id=0x0 magic=0x8334258]
rcvd [CHAP Challenge id=0x1 <79562e6aae5f6cca057a9d93e829874b>, name = "dsl4.wh-man"]
sent [CHAP Response id=0x1 <bb6bf1cc346296d7929bac0721191383>, name = "[email protected]"]
rcvd [LCP EchoRep id=0x0 magic=0x5b926101]
rcvd [CHAP Success id=0x1 "CHAP authentication success, unit 1651"]
CHAP authentication succeeded: CHAP authentication success, unit 1651
CHAP authentication succeeded
peer from calling number XX:XX:XX:XX:XX:XX authorized
sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
rcvd [IPCP ConfReq id=0x4f <addr 62.3.83.6>]
sent [IPCP ConfAck id=0x4f <addr 62.3.83.6>]
rcvd [IPCP ConfNak id=0x1 <addr XX.XX.XX.XXX> <ms-dns1 212.23.6.100> <ms-dns2 212.23.3.100>]
sent [IPCP ConfReq id=0x2 <addr XX.XX.XX.XXX> <ms-dns1 212.23.6.100> <ms-dns2 212.23.3.100>]
rcvd [IPCP ConfAck id=0x2 <addr XX.XX.XX.XXX> <ms-dns1 212.23.6.100> <ms-dns2 212.23.3.100>]
local IP address XX.XX.XX.XXX
remote IP address 62.3.83.6
primary DNS address 212.23.6.100
secondary DNS address 212.23.3.100
Script /etc/ppp/ip-up started (pid 12494)
Script /etc/ppp/ip-up finished (pid 12494), status = 0x0
rcvd [LCP TermReq id=0xc8]
LCP terminated by peer
Connect time 694.9 minutes.
Sent 10966662 bytes, received 259701354 bytes.
Script /etc/ppp/ip-down started (pid 14305)
sent [LCP TermAck id=0xc8]
Script /etc/ppp/ip-down finished (pid 14305), status = 0x0
Connection terminated.
Modem hangup
Send PPPOE Discovery V1T1 PADI session 0x0 length 12
dst ff:ff:ff:ff:ff:ff src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00]
Recv PPPOE Discovery V1T1 PADO session 0x0 length 43
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX
[host-uniq c9 30 00 00] [AC-name bras-red9.dy-B226E1811E038E] [service-name]
Send PPPOE Discovery V1T1 PADR session 0x0 length 12
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00]
Recv PPPOE Discovery V1T1 PADS session 0xd0 length 43
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00] [AC-name bras-red9.dy-B226E1811E038E]
PADS: Service-Name: ''
PPP session is 208
Connected to XX:XX:XX:XX:XX:XX via interface eth0
using channel 10
Using interface ppp0
Connect: ppp0 <--> eth0
sent [LCP ConfReq id=0x3 <mru 1492> <magic 0xfbeea7a9>]
rcvd [LCP ConfReq id=0x1b <mru 1492> <auth chap MD5> <magic 0x3c61ef90>]
sent [LCP ConfAck id=0x1b <mru 1492> <auth chap MD5> <magic 0x3c61ef90>]
rcvd [LCP ConfAck id=0x3 <mru 1492> <magic 0xfbeea7a9>]
sent [LCP EchoReq id=0x0 magic=0xfbeea7a9]
rcvd [CHAP Challenge id=0x1 <bb0a6705f7e48a0c037eaec3293089fa>, name = "bras-red9.dy"]
sent [CHAP Response id=0x1 <97680e242aba9cc15f2e9140122880d1>, name = "[email protected]"]
rcvd [LCP EchoRep id=0x0 magic=0x3c61ef90]
rcvd [LCP ConfReq id=0x26 <mru 1492> <auth chap MD5> <magic 0x3c61ef90>]
sent [LCP ConfReq id=0x4 <mru 1492> <magic 0x11eea51c>]
sent [LCP ConfAck id=0x26 <mru 1492> <auth chap MD5> <magic 0x3c61ef90>]
rcvd [LCP ConfAck id=0x4 <mru 1492> <magic 0x11eea51c>]
sent [LCP EchoReq id=0x0 magic=0x11eea51c]
rcvd [CHAP Challenge id=0x1 <aa0a4ae92d5c2a402ca7deda77d81c29>, name = "dsl4.wh-man"]
sent [CHAP Response id=0x1 <4fe35f901a58d78490fbb712b2284381>, name = "[email protected]"]
rcvd [LCP EchoRep id=0x0 magic=0x3c61ef90]
rcvd [CHAP Success id=0x1 "CHAP authentication success, unit 4286"]
CHAP authentication succeeded: CHAP authentication success, unit 4286
CHAP authentication succeeded
peer from calling number XX:XX:XX:XX:XX:XX authorized
sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
rcvd [IPCP ConfReq id=0xa7 <addr 62.3.83.6>]
sent [IPCP ConfAck id=0xa7 <addr 62.3.83.6>]
rcvd [IPCP ConfNak id=0x3 <addr XX.XX.XX.XXX> <ms-dns1 212.23.6.100> <ms-dns2 212.23.3.100>]
sent [IPCP ConfReq id=0x4 <addr XX.XX.XX.XXX> <ms-dns1 212.23.6.100> <ms-dns2 212.23.3.100>]
rcvd [IPCP ConfAck id=0x4 <addr XX.XX.XX.XXX> <ms-dns1 212.23.6.100> <ms-dns2 212.23.3.100>]
local IP address XX.XX.XX.XXX
remote IP address 62.3.83.6
primary DNS address 212.23.6.100
secondary DNS address 212.23.3.100
Script /etc/ppp/ip-up started (pid 14330)
Script /etc/ppp/ip-up finished (pid 14330), status = 0x0
... Pause for a few hours while the internet connection works OK ...
No response to 4 echo-requests
Serial link appears to be disconnected.
Connect time 283.2 minutes.
Sent 8260957 bytes, received 144506651 bytes.
Script /etc/ppp/ip-down started (pid 15006)
sent [LCP TermReq id=0x5 "Peer not responding"]
Script /etc/ppp/ip-down finished (pid 15006), status = 0x0
sent [LCP TermReq id=0x6 "Peer not responding"]
Connection terminated.
Modem hangup
Send PPPOE Discovery V1T1 PADI session 0x0 length 12
dst ff:ff:ff:ff:ff:ff src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00]
Recv PPPOE Discovery V1T1 PADO session 0x0 length 43
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX
[host-uniq c9 30 00 00] [AC-name bras-red9.dy-B226E1811E038E] [service-name]
Send PPPOE Discovery V1T1 PADR session 0x0 length 12
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00]
Recv PPPOE Discovery V1T1 PADS session 0x19d length 43
dst XX:XX:XX:XX:XX:XX src XX:XX:XX:XX:XX:XX
[service-name] [host-uniq c9 30 00 00] [AC-name bras-red9.dy-B226E1811E038E]
PADS: Service-Name: ''
PPP session is 413
Connected to XX:XX:XX:XX:XX:XX via interface eth0
using channel 11
Using interface ppp0
Connect: ppp0 <--> eth0
sent [LCP ConfReq id=0x7 <mru 1492> <magic 0xc5073944>]
rcvd [LCP ConfReq id=0x92 <mru 1492> <auth chap MD5> <magic 0x540e3e59>]
sent [LCP ConfAck id=0x92 <mru 1492> <auth chap MD5> <magic 0x540e3e59>]
rcvd [LCP ConfAck id=0x7 <mru 1492> <magic 0xc5073944>]
sent [LCP EchoReq id=0x0 magic=0xc5073944]
rcvd [CHAP Challenge id=0x1 <1ccd1dfa1c3f766eb8688b32eee31de7>, name = "bras-red9.dy"]
sent [CHAP Response id=0x1 <64d4d13945e9a71e22285d7b70859673>, name = "[email protected]"]
rcvd [LCP EchoRep id=0x0 magic=0x540e3e59]
rcvd [LCP ConfReq id=0xd4 <mru 1492> <auth chap MD5> <magic 0x540e3e59>]
sent [LCP ConfReq id=0x8 <mru 1492> <magic 0xa51d1646>]
sent [LCP ConfAck id=0xd4 <mru 1492> <auth chap MD5> <magic 0x540e3e59>]
rcvd [LCP ConfAck id=0x8 <mru 1492> <magic 0xa51d1646>]
sent [LCP EchoReq id=0x0 magic=0xa51d1646]
rcvd [CHAP Challenge id=0x1 <bb3049925410fd7d5b2bd1420ccfbd7c>, name = "dsl6.wh-man"]
sent [CHAP Response id=0x1 <c8ad4440f20cee3d75df6269c1d140bb>, name = "[email protected]"]
rcvd [LCP EchoRep id=0x0 magic=0x540e3e59]
rcvd [CHAP Success id=0x1 "CHAP authentication success, unit 3661"]
CHAP authentication succeeded: CHAP authentication success, unit 3661
CHAP authentication succeeded
peer from calling number XX:XX:XX:XX:XX:XX authorized
sent [IPCP ConfReq id=0x5 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
rcvd [IPCP ConfReq id=0x56 <addr 62.3.83.21>]
sent [IPCP ConfAck id=0x56 <addr 62.3.83.21>]
rcvd [IPCP ConfNak id=0x5 <addr XX.XX.XX.XXX> <ms-dns1 212.23.6.100> <ms-dns2 212.23.3.100>]
sent [IPCP ConfReq id=0x6 <addr XX.XX.XX.XXX> <ms-dns1 212.23.6.100> <ms-dns2 212.23.3.100>]
rcvd [IPCP ConfAck id=0x6 <addr XX.XX.XX.XXX> <ms-dns1 212.23.6.100> <ms-dns2 212.23.3.100>]
local IP address XX.XX.XX.XXX
remote IP address 62.3.83.21
primary DNS address 212.23.6.100
secondary DNS address 212.23.3.100
Script /etc/ppp/ip-up started (pid 15033)
Script /etc/ppp/ip-up finished (pid 15033), status = 0x0

Edited by jez9999 (Wed 30-Oct-13 14:38:53)

What is your 'echo request' time interval set at? <------- IGNORE

I just saw in the logs - 30 seconds.

What happens if you increase this, say, to 60 seconds?

Nick

Edited by Lethe (Wed 30-Oct-13 14:48:30)

I can try changing it to that but the thing is it doesn't feel like Linux is killing the connection; it feels like the connection is dying first and then Linux is realizing it. For a while, the connection won't work (no websites loading, no ICMP ping responses, etc.) and then the stuff appears in the terminal about no response to 4 echo-requests, not the other way round.

OK, so that sorts that then... the echo requests are not lying.

Nick

Are those LCP echos meant to be responded to by the VDSL modem or the DSLAM? If the modem, it suggests a problem between the router and modem. If the DSLAM, then the router/modem connection might be fine and the modem just doesn't respond because it doesn't have a connection to the DSLAM.

Well, if you say internet dies before PPPoE dies, and as interval is 30 seconds (2 minutes before PPPoE disconnect), it appears that the blackbox modem has disconnected.

I also have a vdsl modem that I can't 'see', and I hate it as there is no way to see what is going on.

I may try to get one on-line somewhere so I can unlock it (I dare not try on the 'live' one at the mo.).

Nick

Actually, just had a thought.

Do a few traceroutes from your linux router box and note the first hop (should be the same each time).

Grab that address, and set up a cron job to ping that address once and > log.file

You will now have a 'connectivity' log file which when compared to ppp logs will show if indeed it is the modem disconnecting.

Nick

So nobody have any idea about my problem then?

In reply to a post by Lethe:

set up a cron job to ping that address once and > log.file

That's a hard way of doing it…

ping -c 1000 -i 10 nnn.nnn.nnn.nnn > pinglog.txt

will put the results of 1,000 pings at 10 second intervals into pinglog.txt. Adjust the numbers to suit

Edited by billford (Sun 03-Nov-13 22:12:20)

The failed echo-requests that are triggering the redial are LCP Echo Requests, which is the equivalent of a ping but at the PPP layer. LCP Echo Requests are the correct way to monitor for PPPoE failure, especially as the IP address of the gateway at the Zen end of an FTTC connection is dynamic.


pppd sends a LCP Echo Request every lcp-echo-interval. If lcp-echo-failure in a row of these requests fail, the connection is assumed to have died, the PPP layer is torn down and the connection is re-established.

The defaults listed in your dump make little sense for FTTC PPPoE - there's no reason to wait two minutes before giving up with the PPP connection and starting over. The defaults are for dial-up PPP, where re-establishing the connection takes tens of seconds and likely has a financial cost attached. With FTTC PPPoE, the connection can be re-established in less than a second if the VDSL2 connection has stayed synchronised, and there's no cost attached, so it is in your interests to detect and act on any PPP failure quickly rather than waiting and hoping things will start working.

I'd make lcp-echo-interval 4 and lcp-echo-failure 4 in /etc/ppp/options , which means an LCP Echo Request is sent every 4 seconds and a failure is detected after 4 failed attempts (i.e. 16 seconds). An LCP Echo Request once every 4 seconds imposes minimal overhead, but allows for rapid detection of connection failure. One or two consecutive failures will happen from time to time with such a short interval, but 4 in a row almost guarantees the connection has failed.

You can tweak the detection interval even lower than 16 seconds if you like, but I wouldn't want to send an LCP Echo Request more often than every 4 seconds. Ultimately, it's a trade-off between speed of detection and detecting false failures.


You should configure your equipment not to close sockets or drop firewall states on a PPPoE failure, as the static IP on Zen means any traffic should resume once the PPPoE connection is re-established. My lack of familiarity with Linux precludes me from knowing where these settings are if they are not the defaults: I use FreeBSD with mpd5 rather than Linux with pppd. If you find sockets and/or firewall states are being torn down on PPP failure, I'd take a close look at the /etc/ppp/ip-up and /etc/ppp/ip-down scripts (especially the ip-down one).


So far as why these PPP drop-outs are occurring, you'd need to address that question to Zen support, who can take a look at the logs for your connection.