Troubleshooting pppoe WAN connection which seems to stall from time to time



  • Troubleshooting pppoe WAN connection which seems to stall



  • @mattjoy So from time to time the wan feeds seem to stall. I found the following log entries which seem to indicate that there are high latency periods. But also 0 loss however I have seen many instances where streaming seems to be pausing for up to a minute or two at a time.

    The ISP insists that everything looks perfect. Do you have any thoughts or suggestions?

    Interface looks okay but the Gateway logs seem to tell another story.

    Status up PPPoE up
    Uptime 3d 02:17:51
    IPv4 Address
    216.137.248.126
    Subnet mask IPv4
    255.255.255.255
    Gateway IPv4
    64.4.226.254
    IPv6 Link Local
    fe80::208:a2ff:fe0a:e9b2%igb0
    DNS servers
    127.0.0.1
    216.152.176.1
    64.4.226.40
    MTU
    1492
    In/out packets
    27789542/24575471 (23.97 GiB/13.09 GiB)
    In/out packets (pass)
    27789542/24575471 (23.97 GiB/13.09 GiB)
    In/out packets (block)
    27164/0 (3.73 MiB/0 B)
    In/out errors
    0/0
    Collisions
    0

    Last 50 Gateways Log Entries. (Maximum 50)
    Jun 27 22:56:52 dpinger WAN_PPPOE 64.4.226.252: Clear latency 5252us stddev 431us loss 5%
    Jun 28 20:25:51 dpinger WAN_PPPOE 64.4.226.252: Alarm latency 5248us stddev 357us loss 21%
    Jun 28 20:28:42 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:28:44 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 0us stddev 0us loss 100%
    Jun 28 20:29:01 dpinger WAN_PPPOE 64.4.226.254: Clear latency 10122us stddev 24304us loss 10%
    Jun 28 20:29:08 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 9770us stddev 23328us loss 21%
    Jun 28 20:30:40 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:30:43 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 0us stddev 0us loss 100%
    Jun 28 20:32:14 dpinger WAN_PPPOE 64.4.226.254: Clear latency 6051us stddev 603us loss 5%
    Jun 28 20:32:36 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 6025us stddev 492us loss 21%
    Jun 28 20:36:35 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:37:11 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5964us stddev 506us loss 22%
    Jun 28 20:43:42 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:44:21 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5962us stddev 396us loss 21%
    Jun 28 20:47:10 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:47:23 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5701us stddev 402us loss 21%
    Jun 28 20:48:17 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:48:19 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 0us stddev 0us loss 100%
    Jun 28 20:50:20 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:51:33 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5815us stddev 405us loss 21%
    Jun 28 20:52:22 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:52:29 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 6293us stddev 1209us loss 27%
    Jun 28 20:53:56 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.252 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:54:47 dpinger WAN_PPPOE 64.4.226.252: Alarm latency 5208us stddev 322us loss 22%
    Jun 28 20:55:25 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jun 28 20:57:52 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5851us stddev 385us loss 21%
    Jun 28 21:00:00 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 6 19:02:58 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5839us stddev 391us loss 22%
    Jul 6 19:04:37 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 6 19:04:40 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5474us stddev 128us loss 33%
    Jul 6 19:05:42 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 6 19:05:45 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 0us stddev 0us loss 100%
    Jul 6 19:09:56 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 6 19:09:59 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 6335us stddev 0us loss 66%
    Jul 6 19:17:17 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 6 19:17:20 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 0us stddev 0us loss 100%
    Jul 6 19:19:30 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 6 19:28:10 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5911us stddev 374us loss 22%
    Jul 6 19:29:21 dpinger WAN_PPPOE 64.4.226.254: Clear latency 5970us stddev 403us loss 5%
    Jul 17 10:36:25 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 17 10:36:33 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 18 19:57:23 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5834us stddev 426us loss 22%
    Jul 18 19:58:41 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 18 19:58:43 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 0us stddev 0us loss 100%
    Jul 18 19:59:03 dpinger WAN_PPPOE 64.4.226.254: Clear latency 8986us stddev 17599us loss 11%
    Jul 18 19:59:21 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 9605us stddev 18882us loss 21%
    Jul 19 02:15:36 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 19 02:15:38 dpinger send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 64.4.226.254 bind_addr 216.137.248.126 identifier "WAN_PPPOE "
    Jul 22 02:24:37 dpinger WAN_PPPOE 64.4.226.254: Alarm latency 5960us stddev 386us loss 21%
    Jul 22 02:25:41 dpinger WAN_PPPOE 64.4.226.254: Clear latency 5795us stddev 549us loss 6%



  • Your alarm log seems to be showing 2 different dest_addr, 64.4.226.254 and 64.4.226.252. I'd suggest you look at your PPP log, I suspect the connection is dropping and being restarted frequently.

    You can see here for example a PPPoE connection that went down unexpectedly because the LCP protocol stopped receiving replies and tore down the connection:

    ...lots more log about connection going down
    Jul 23 10:28:55	ppp		[wan_link0] LCP: state change Opened --> Stopping
    Jul 23 10:28:55	ppp		[wan_link0] LCP: peer not responding to echo requests
    Jul 23 10:28:55	ppp		[wan_link0] LCP: no reply to 5 echo request(s)
    Jul 23 10:28:45	ppp		[wan_link0] LCP: no reply to 4 echo request(s)
    Jul 23 10:28:35	ppp		[wan_link0] LCP: no reply to 3 echo request(s)
    Jul 23 10:28:25	ppp		[wan_link0] LCP: no reply to 2 echo request(s)
    Jul 23 10:28:15	ppp		[wan_link0] LCP: no reply to 1 echo request(s)