PPP Problem

My house has 2 CenturyLink fiber optic connections to The Internet. On July 5, 2025, the connections didn’t work for 3 periods of time.

One of the CenturyLink fiber optic connections has a CenturyLink-provided “C4000XG” routers, the other has my Dell R530 server connected to it. I’m pretty much stuck with “the internet is down” human notifications for anything connected to the C4000XG router. I have the R530 configured to use PPP and PPPoE to connect to CenturyLink’s network. I can get timestamps and messages from that software to look at the outage.

Outages ran from:

  1. Jul 05 09:52:45 to Jul 05 09:58:27 - 5:42 duration
  2. Jul 05 13:13:00 to Jul 05 13:18:42 - 5:42 duration
  3. Jul 05 16:56:12 to Jul 05 17:01:14 - 5:42 duration

My timezone is America/Denver. Daylight savings was in effect during the outages, so the timestamps are in -0600 timezone.

I feel like the 3 instances of 5:42 elapsed time for the outages is more due to how pppd and the rp-pppoe plugin timeouts work and interact than anything else.

I’ve got Arch Linux ppp package 2.5.2-1, and rp-pppoe 4.0-5 running.

Log and error messages

All three of the short outages show similar journal entries. I’m going to illustrate with the third outage (Jul 05 16:56:12 to Jul 05 17:01:14) journal entries.

The pppd journal looks like this:

Jul 05 16:56:12 dellr530 pppd[894]: No response to 4 echo-requests
Jul 05 16:56:12 dellr530 pppd[894]: Serial link appears to be disconnected.
Jul 05 16:56:12 dellr530 pppd[894]: Connect time 217.6 minutes.
Jul 05 16:56:12 dellr530 pppd[894]: Sent 21264139 bytes, received 278228475 bytes.
Jul 05 16:56:18 dellr530 pppd[894]: Connection terminated.
Jul 05 16:56:18 dellr530 pppd[894]: Sent PADT
Jul 05 16:56:18 dellr530 pppd[894]: Modem hangup 
Jul 05 16:56:53 dellr530 pppd[894]: pppoe: Timeout waiting for PADO packets
Jul 05 16:56:53 dellr530 pppd[894]: Timeout waiting for PADO packets
Jul 05 16:58:08 dellr530 pppd[894]: pppoe: Timeout waiting for PADO packets
Jul 05 16:58:08 dellr530 pppd[894]: Timeout waiting for PADO packets
Jul 05 16:59:23 dellr530 pppd[894]: pppoe: Timeout waiting for PADO packets
Jul 05 16:59:23 dellr530 pppd[894]: Timeout waiting for PADO packets
Jul 05 17:00:38 dellr530 pppd[894]: pppoe: Timeout waiting for PADO packets
Jul 05 17:00:38 dellr530 pppd[894]: Timeout waiting for PADO packets
Jul 05 17:01:13 dellr530 pppd[894]: PPP session is 2902 (0xb56)
Jul 05 17:01:13 dellr530 pppd[894]: Connected to 78:fe:3d:b3:18:3b via interface eno3.201
Jul 05 17:01:13 dellr530 pppd[894]: Using interface ppp0
Jul 05 17:01:13 dellr530 pppd[894]: Connect: ppp0 <--> eno3.201
Jul 05 17:01:13 dellr530 pppd[894]: CHAP authentication succeeded
Jul 05 17:01:13 dellr530 pppd[894]: CHAP authentication succeeded
Jul 05 17:01:13 dellr530 pppd[894]: peer from calling number 78:FE:3D:B3:18:3B authorized
Jul 05 17:01:14 dellr530 pppd[894]: Cannot determine ethernet address for proxy ARP
Jul 05 17:01:14 dellr530 pppd[894]: local  IP address 70.56.0.0/14
Jul 05 17:01:14 dellr530 pppd[894]: remote IP address 207.224.0.0/15

My R530 server got new IPv4 addresses each time. Just to be perfectly clear, the Dell R530 did not reboot during these travails.

Looking at a longer journal context (journalctl --since 2025-07-05T16:50:30 --until 2025-07-05T17:05:00), I see other interesting journal entries:

Jul 05 16:53:45 dellr530 kernel: tg3 0000:03:00.0 eno3: Link is down
Jul 05 16:53:50 dellr530 kernel: tg3 0000:03:00.0 eno3: Link is up at 1000 Mbps, full duplex
Jul 05 16:53:50 dellr530 kernel: tg3 0000:03:00.0 eno3: Flow control is off for TX and off for RX
Jul 05 16:53:50 dellr530 kernel: tg3 0000:03:00.0 eno3: EEE is disabled
Jul 05 16:53:52 dellr530 kernel: tg3 0000:03:00.0 eno3: Link is down
Jul 05 16:53:55 dellr530 kernel: tg3 0000:03:00.0 eno3: Link is up at 1000 Mbps, full duplex
Jul 05 16:53:55 dellr530 kernel: tg3 0000:03:00.0 eno3: Flow control is off for TX and off for RX
Jul 05 16:53:55 dellr530 kernel: tg3 0000:03:00.0 eno3: EEE is disabled
Jul 05 17:00:24 dellr530 kernel: tg3 0000:03:00.0 eno3: Link is down
Jul 05 17:00:27 dellr530 kernel: tg3 0000:03:00.0 eno3: Link is up at 1000 Mbps, full duplex
Jul 05 17:00:27 dellr530 kernel: tg3 0000:03:00.0 eno3: Flow control is off for TX and off for RX
Jul 05 17:00:27 dellr530 kernel: tg3 0000:03:00.0 eno3: EEE is disabled

The kernel has the eno3 interface going down 2:27 before pppd detects a problem. That’s reporting occurrences at the optical network terminal (ONT). Here are the down/up flaps from my R530’s journal:

Jul 05 09:50:28  Link is down
Jul 05 09:50:34  Link is up
Jul 05 09:50:36  Link is down
Jul 05 09:50:39  Link is up
Jul 05 09:57:28  Link is down
Jul 05 09:57:31  Link is up

Jul 05 13:10:49  Link is down
Jul 05 13:10:53  Link is up
Jul 05 13:10:56  Link is down
Jul 05 13:10:59  Link is up
Jul 05 13:17:26  Link is down
Jul 05 13:17:29  Link is up
Jul 05 13:18:02  Link is down
Jul 05 13:18:08  Link is up

Jul 05 16:53:45  Link is down
Jul 05 16:53:50  Link is up
Jul 05 16:53:52  Link is down
Jul 05 16:53:55  Link is up
Jul 05 17:00:24  Link is down
Jul 05 17:00:27  Link is up

Looks like 3 flaps for outage 1, 4 flaps for outage 2,and 3 for outage 3. Each flap runs between 3 and 6 seconds, so there’s no polling interval masking or “debouncing” the flapping.

Smokeping evidence

I’ve been running Smokeping for a few months, hoping for a little insight into network behavior.

Smokeping latency chart illustrating outage and packet loss

That’s Smokeping latency measurements for a VPS that I rent. I piously believe the host machine is in Kansas City. A traceroute shows Cogent IP addresses and FQDNs between CenturyLink and the VPS, so it’s definitely not on CenturyLink’s network.

Smokeping has a default interval of 300 seconds. I haven’t changed that, mainly because I don’t know much about Smokeping. Nevertheless, Smokeping latency data shows 3% packet loss in the 16:45 - 16:50 interval, which precedes the kernel journal entries about tg3 link loss. That same level of packet loss shows up before each of the 3 outages. Smokeping does not show much, if any, packet loss except the 5 minute intervals before the outages. Even if Smokeping sent out packets at the end of its 5 minute interval, 16:50 is still 3:45 before the kernel logs a message about “link is down”. Some networking funny business happens leading up to the link failure.

Conclusion

I didn’t touch anything, software or hardware, before or during these short outages. A second fiber optic link seems to have had problems at the same times as the link I can examine in detail. I have to conclude that the CenturyLink network had some troubles, not my home network. Since there’s little real information about how any ISP lays out fiber optic networking, I can’t say if the box at the end of the neighborhood (fiber optic aggregator?) is the problem, or some other piece of CenturyLink’s network is at issue.