I'm a fan of OpenWRT and greatly appreciate the efforts that go into this great project.
The problem I'm having seems different (and quite a bit less severe) than similar reports I've seen here but I am intrigued and would like to know what's going on and how I can improved my situation.
I've been running OpenWRT on a Linksys WRT1900ACS for a number of years through a series of upgrades. I'm now on v24.10.0. Throughout that time I've been very happy with the behaviour and performance EXCEPT that every few days my pppoe-wan interface loses connection. It's not such a big deal as it reconnects automatically within a few minutes. If it happens at night or while I'm away I wouldn't know except for the Connected: display on the Status | Overview page or trawling the logs.
I'd like to know what's causing the connection to be lost. Is it my end or the ISP doing it.
I can't learn much from the system log. The first thing I see in the logs related to the outage is:
...
<datetime stamp> daemon.info pppd[5262]: No response to 5 echo-requests
<datetime stamp> daemon.notice pppd[5262]: Serial link appears to be disconnected.
...
The kernel log shows:
...
[593853.729847] mv88e6085 f1072004.mdio-mii:00 wan: Link is Down
[593917.581537] mv88e6085 f1072004.mdio-mii:00 wan: Link is Up - 1Gbps/Full - flow control off
...
I'm happy to post more log entries of configuration to assist but maybe one of you has a quick answer for me.
Cheers.
How long does it take to reconnect?
Can we see the logs when this happens?
If it takes "a few minutes" to reconnect, then I would say it is not on your end; the router should take just a few seconds to reconnect, unless there is something wrong externally.
This morning it took 5 seconds to reconnect (while I slept!):
Fri Feb 28 00:05:31 2025 daemon.info pppd[5262]: No response to 5 echo-requests
Fri Feb 28 00:05:31 2025 daemon.notice pppd[5262]: Serial link appears to be disconnected.
Fri Feb 28 00:05:31 2025 daemon.info pppd[5262]: Connect time 95.9 minutes.
Fri Feb 28 00:05:31 2025 daemon.info pppd[5262]: Sent 0 bytes, received 14529097 bytes.
Fri Feb 28 00:05:31 2025 daemon.err odhcp6c[5326]: Failed to send RS (Network unreachable)
Fri Feb 28 00:05:31 2025 daemon.err odhcp6c[5326]: Failed to send RELEASE message to ff02::1:2 (Network unreachable)
Fri Feb 28 00:05:31 2025 daemon.notice netifd: Interface 'wan_6' is disabled
Fri Feb 28 00:05:31 2025 daemon.notice netifd: Network device 'pppoe-wan' link is down
Fri Feb 28 00:05:31 2025 daemon.notice netifd: Network alias 'pppoe-wan' link is down
Fri Feb 28 00:05:31 2025 daemon.notice netifd: Interface 'wan_6' has link connectivity loss
Fri Feb 28 00:05:31 2025 daemon.notice netifd: Interface 'wan' has lost the connection
Fri Feb 28 00:05:31 2025 daemon.notice netifd: wan_6 (5326): Command failed: ubus call network.interface notify_proto { "action": 0, "link-up": false, "keep": false, "interface": "wan_6" } (Permission denied)
Fri Feb 28 00:05:31 2025 daemon.err odhcp6c[5326]: Failed to send SOLICIT message to ff02::1:2 (Network unreachable)
Fri Feb 28 00:05:31 2025 daemon.notice netifd: Interface 'wan_6' is now down
Fri Feb 28 00:05:31 2025 daemon.info dnsmasq[1]: read /etc/hosts - 12 names
Fri Feb 28 00:05:31 2025 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 8 names
Fri Feb 28 00:05:31 2025 daemon.info dnsmasq[1]: read /tmp/hosts/odhcpd - 2 names
Fri Feb 28 00:05:31 2025 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Fri Feb 28 00:05:32 2025 daemon.notice pppd[5262]: Connection terminated.
Fri Feb 28 00:05:32 2025 daemon.info pppd[5262]: Sent PADT
Fri Feb 28 00:05:32 2025 daemon.info pppd[5262]: Exit.
Fri Feb 28 00:05:32 2025 daemon.notice netifd: Interface 'wan' is now down
Fri Feb 28 00:05:32 2025 daemon.notice netifd: Interface 'wan' is setting up now
Fri Feb 28 00:05:32 2025 daemon.info pppd[6090]: Plugin pppoe.so loaded.
Fri Feb 28 00:05:32 2025 daemon.info pppd[6090]: PPPoE plugin from pppd 2.5.1
Fri Feb 28 00:05:32 2025 daemon.notice pppd[6090]: pppd 2.5.1 started by root, uid 0
Fri Feb 28 00:05:32 2025 daemon.info pppd[6090]: PPP session is 64
Fri Feb 28 00:05:32 2025 daemon.warn pppd[6090]: Connected to XX:XX:XX:XX:XX:XX via interface wan.2
Fri Feb 28 00:05:32 2025 daemon.info pppd[6090]: Using interface pppoe-wan
Fri Feb 28 00:05:32 2025 daemon.notice pppd[6090]: Connect: pppoe-wan <--> wan.2
Fri Feb 28 00:05:32 2025 daemon.warn odhcpd[1875]: No default route present, overriding ra_lifetime to 0!
Fri Feb 28 00:05:33 2025 daemon.notice pppd[6090]: PAP authentication succeeded
Fri Feb 28 00:05:33 2025 daemon.notice pppd[6090]: peer from calling number XX:XX:XX:XX:XX:XX authorized
Fri Feb 28 00:05:33 2025 daemon.notice pppd[6090]: local LL address XX:XX:XX:XX:XX:XX
Fri Feb 28 00:05:33 2025 daemon.notice pppd[6090]: remote LL address XX:XX:XX:XX:XX:XX
Fri Feb 28 00:05:33 2025 daemon.notice pppd[6090]: local IP address XX.XX.XX.XX
Fri Feb 28 00:05:33 2025 daemon.notice pppd[6090]: remote IP address XX.XX.XX.XX
Fri Feb 28 00:05:33 2025 daemon.notice pppd[6090]: primary DNS address XX.XX.XX.XX
Fri Feb 28 00:05:33 2025 daemon.notice pppd[6090]: secondary DNS address XX.XX.XX.XX
Fri Feb 28 00:05:33 2025 daemon.notice netifd: Network device 'pppoe-wan' link is up
Fri Feb 28 00:05:33 2025 daemon.notice netifd: Network alias 'pppoe-wan' link is up
Fri Feb 28 00:05:33 2025 daemon.notice netifd: Interface 'wan' is now up
Fri Feb 28 00:05:33 2025 daemon.notice netifd: Interface 'wan_6' is enabled
Fri Feb 28 00:05:33 2025 daemon.notice netifd: Interface 'wan_6' has link connectivity
Fri Feb 28 00:05:33 2025 daemon.notice netifd: Interface 'wan_6' is setting up now
Fri Feb 28 00:05:33 2025 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Fri Feb 28 00:05:33 2025 user.notice firewall: Reloading firewall due to ifupdate of wan (pppoe-wan)
Fri Feb 28 00:05:36 2025 daemon.notice netifd: Interface 'wan_6' is now up
Any downtime is undesirable, obviously; but a five seconds disconnection now and then is probably expected. Most people with a normal router would rarely notice it.
1 Like
So if the interface pppoe-wan is "living" on flaps, pppoe-wan gets reconnected, I was having similar issues, for me:
config interface 'wan'
option hostname 'turris'
option ipv6 '1'
option proto 'pppoe'
option username 'USERNAME'
option password 'PASSWORD'
option force_link '1'
option device 'eth2.7'
adding force_link 1 solved that issue... and it might as well in your case assuming these flap events are not long enough to trigger a timeout by themselves, as the "No response to 5 echo-requests" error implies that something is too slow. If the force_link does not help, I guess we should see to increase the disconnection timeout a bit.
1 Like
Sometimes it takes longer, maybe a few reconnection cycles. It's inconvenient in the middle of a movie! (1st World problem) I'm just trying to work out whether the problem is in my setup or upstream.
I'll give force link a try and see how it goes. Thanks.
That doesn't seem to have improved the situation. I will revert that change for now. Thanks for the suggestion though.
Mmmh, okay then let's try to make your pppoed less prone to hang-up:
See here:
https://openwrt.org/docs/guide-user/network/wan/wan_interface_protocols#protocol_pppoe_ppp_over_ethernet
keepalive 2 numbers no 5 1 The numbers must be separated by a space. First number is “we assume the connection is down after this number of pings failed” (ppp's lcp-echo-failure option). Second number is for “seconds between each ping” (ppp's lcp-echo-interval option).
I would try to increase these numbers to say 60 1 to try for a full minute to hold on to the connection. Let's see how that fares and whether your ISP holds state long enough...
Current error messages imply it is your PPPoE system that ends the connection, but due to inactivity the other side might have done the same already and just failed to inform you...
2 Likes
Is that 2-value parameter what LuCI parses out into LCP echo failure threshold and LCP echo interval?
I haven't made you're latest suggested change yet but looking at pppd.log (I have remote logging turned on) I see it disconnected/reconnected 4 times overnight with the following entries:
Mar 4 05:16:59 bluetongue pppd[22227]: Terminating on signal 15
Mar 4 05:16:59 bluetongue pppd[22227]: Connect time 29.9 minutes.
Mar 4 05:16:59 bluetongue pppd[22227]: Sent 0 bytes, received 1412627 bytes.
Mar 4 05:17:04 bluetongue pppd[22758]: Plugin pppoe.so loaded.
Mar 4 05:17:04 bluetongue pppd[22758]: PPPoE plugin from pppd 2.5.1
Mar 4 05:17:04 bluetongue pppd[22758]: pppd 2.5.1 started by root, uid 0
Mar 4 05:17:04 bluetongue pppd[22758]: PPP session is 41265
Mar 4 05:17:04 bluetongue pppd[22758]: Connected to ##.##.##.##.##.## via interface wan.2
Mar 4 05:17:04 bluetongue pppd[22758]: Using interface pppoe-wan
Mar 4 05:17:04 bluetongue pppd[22758]: Connect: pppoe-wan <--> wan.2
Mar 4 05:17:04 bluetongue pppd[22758]: PAP authentication succeeded
Mar 4 05:17:04 bluetongue pppd[22758]: peer from calling number ##.##.##.##.##.## authorized
Mar 4 05:17:04 bluetongue pppd[22758]: local LL address ####:####:####:####...
Mar 4 05:17:04 bluetongue pppd[22758]: remote LL address ####:####:####:####...
Mar 4 05:17:04 bluetongue pppd[22758]: local IP address ##.##.##.##
Mar 4 05:17:04 bluetongue pppd[22758]: remote IP address ##.##.##.##
Mar 4 05:17:04 bluetongue pppd[22758]: primary DNS address ##.##.##.##
Mar 4 05:17:04 bluetongue pppd[22758]: secondary DNS address ##.##.##.##
Does "Terminating on signal 15" tell you anything helpful?
I've tried a few changes like you've suggested. That hasn't reduced the number of outages but maybe increasing the time to connection restoration (maybe because it's waiting longer between keepalive pings).
Hunting around for other hints, I see these pairs of lines in the kernel log:
[701229.732826] mv88e6085 f1072004.mdio-mii:00 wan: Link is Down
[701289.974365] mv88e6085 f1072004.mdio-mii:00 wan: Link is Up - 1Gbps/Full - flow control off
and wonder if there's any hint there.
I found this 3 year old topic on github: https://github.com/openwrt/openwrt/issues/11459
and wonder whether I shouldn't try:
[ ifup = "$ACTION" ] || exit 0
[ -n "$DEVICE" ] || exit 0
if [ "$DEVICE" == wan ] ; then
ethtool --set-eee "$DEVICE" eee off
fi
to disable an energy efficient ethernet functionality in the device. I'm not sure ethtool is available.
That looks like a 60 second down state epoch... quite a lot to "bridge over".
It is as installable package in some variants IIRC, if you install it maybe looking at the following might be helpful:
ethtool wan
ethtool --statistics wan
ethtool --show-eee
I installed ethtool and dependenies and
ethtool --show-ee indicated that eee WAS disabled.
I enabled it and am now waiting to see how that goes.
I haven't done anything to persist that across reboots yet...
Thanks for your interest in my non-critical problem.
The pppoe connection has been up 16 hours, tick... tick... tick...
Fingers crossed.
1 Like
There may be many reasons
For example, an Internet provider banks you as a flood
And there are a lot of similar options
For example, not the correct installation K-Lite Codec Pack, can make a DNS request every second to a domain that does not work
Then it all depends on how the provider switch is configured
You need to turn off all the excess in the router, everything that you do not use
make your traffic not look like a flood
And this is one example of millions 
Install luci-app-adblock and luci-app-https-dns-proxy, this can partially solve your problem
Well, I had one good day but I'm back to several pppoe disconnections and reconnections each day (maybe mostly at night).
Is there any definitive way of determining whether the disconnections are being triggered by my device or by my ISP's upstream devices or systems?
So if the remote side closes the connection properly the log will have an entry describing that, however if the remote side does not send a termination/hang up notice there will be nothing in the log...
Maybe post a more inclusive section of the logread output for one of the events, that includes say also the entries for, say 2 minutes before your pppoe client gave up.
Make sure to redact usernames passwords and MAC addresses...
Looking at log files on my remote logging server the only entries I can find are in the pppd.log, netifd.log and kernel.log files.
Here are the only relevant lines extracted from those files for a succession of two disconnect/reconnect cycles the night before last.
I inserted a string of hashes to delineate the events but didn't delete any lines.
The timestamps seem to line up well.
There are no entries in the logs for an extended period of time prior to these events.
pppd.log
Mar 11 23:33:11 bluetongue pppd[13278]: No response to 5 echo-requests
Mar 11 23:33:11 bluetongue pppd[13278]: Serial link appears to be disconnected.
Mar 11 23:33:11 bluetongue pppd[13278]: Connect time 83.2 minutes.
Mar 11 23:33:11 bluetongue pppd[13278]: Sent 0 bytes, received 11375564 bytes.
Mar 11 23:33:11 bluetongue pppd[13278]: Connection terminated.
Mar 11 23:33:11 bluetongue pppd[13278]: Sent PADT
Mar 11 23:33:11 bluetongue pppd[13278]: Exit.
Mar 11 23:33:11 bluetongue pppd[13985]: Plugin pppoe.so loaded.
Mar 11 23:33:11 bluetongue pppd[13985]: PPPoE plugin from pppd 2.5.1
Mar 11 23:33:11 bluetongue pppd[13985]: pppd 2.5.1 started by root, uid 0
Mar 11 23:33:11 bluetongue pppd[13985]: PPP session is 49608
Mar 11 23:33:11 bluetongue pppd[13985]: Connected to ##:##:##:##:##:## via interface wan.2
Mar 11 23:33:11 bluetongue pppd[13985]: Using interface pppoe-wan
Mar 11 23:33:11 bluetongue pppd[13985]: Connect: pppoe-wan <--> wan.2
Mar 11 23:33:12 bluetongue pppd[13985]: PAP authentication succeeded
Mar 11 23:33:12 bluetongue pppd[13985]: peer from calling number ##:##:##:##:##:## authorized
Mar 11 23:33:12 bluetongue pppd[13985]: local LL address ####::####:####:####:####
Mar 11 23:33:12 bluetongue pppd[13985]: remote LL address ####::####:####:####:####
Mar 11 23:33:12 bluetongue pppd[13985]: local IP address ###.###.###.###
Mar 11 23:33:12 bluetongue pppd[13985]: remote IP address ###.###.###.###
Mar 11 23:33:12 bluetongue pppd[13985]: primary DNS address ###.###.###.###
Mar 11 23:33:12 bluetongue pppd[13985]: secondary DNS address ###.###.###.###
###############
Mar 11 23:34:12 bluetongue pppd[13985]: No response to 5 echo-requests
Mar 11 23:34:12 bluetongue pppd[13985]: Serial link appears to be disconnected.
Mar 11 23:34:12 bluetongue pppd[13985]: Connect time 1.0 minutes.
Mar 11 23:34:12 bluetongue pppd[13985]: Sent 0 bytes, received 34464 bytes.
Mar 11 23:34:15 bluetongue pppd[13985]: Terminating on signal 15
Mar 11 23:34:18 bluetongue pppd[13985]: Connection terminated.
Mar 11 23:34:18 bluetongue pppd[13985]: Sent PADT
Mar 11 23:34:18 bluetongue pppd[13985]: Modem hangup
Mar 11 23:34:18 bluetongue pppd[13985]: Exit.
Mar 11 23:35:19 bluetongue pppd[14577]: Plugin pppoe.so loaded.
Mar 11 23:35:19 bluetongue pppd[14577]: PPPoE plugin from pppd 2.5.1
Mar 11 23:35:19 bluetongue pppd[14577]: pppd 2.5.1 started by root, uid 0
Mar 11 23:35:19 bluetongue pppd[14577]: PPP session is 11318
Mar 11 23:35:19 bluetongue pppd[14577]: Connected to ##:##:##:##:##:## via interface wan.2
Mar 11 23:35:19 bluetongue pppd[14577]: Using interface pppoe-wan
Mar 11 23:35:19 bluetongue pppd[14577]: Connect: pppoe-wan <--> wan.2
Mar 11 23:35:22 bluetongue pppd[14577]: PAP authentication succeeded
Mar 11 23:35:22 bluetongue pppd[14577]: peer from calling number ##:##:##:##:##:## authorized
Mar 11 23:35:22 bluetongue pppd[14577]: local LL address ####::####:####:####:####
Mar 11 23:35:22 bluetongue pppd[14577]: remote LL address ####::####:####:####:####
Mar 11 23:35:23 bluetongue pppd[14577]: local IP address ###.###.###.###
Mar 11 23:35:23 bluetongue pppd[14577]: remote IP address ###.###.###.###
Mar 11 23:35:23 bluetongue pppd[14577]: primary DNS address ###.###.###.###
Mar 11 23:35:23 bluetongue pppd[14577]: secondary DNS address ###.###.###.###
netifd.log
Mar 11 23:33:11 bluetongue netifd: Interface 'wan_6' is disabled
Mar 11 23:33:11 bluetongue netifd: Network device 'pppoe-wan' link is down
Mar 11 23:33:11 bluetongue netifd: Network alias 'pppoe-wan' link is down
Mar 11 23:33:11 bluetongue netifd: Interface 'wan_6' has link connectivity loss
Mar 11 23:33:11 bluetongue netifd: Interface 'wan' has lost the connection
Mar 11 23:33:11 bluetongue netifd: wan_6 (13343): Command failed: ubus call network.interface notify_proto { "action": 0, "link-up": false, "keep": false, "interface": "wan_6" } (Permission denied)
Mar 11 23:33:11 bluetongue netifd: Interface 'wan_6' is now down
Mar 11 23:33:11 bluetongue netifd: Interface 'wan' is now down
Mar 11 23:33:11 bluetongue netifd: Interface 'wan' is setting up now
Mar 11 23:33:12 bluetongue netifd: Network device 'pppoe-wan' link is up
Mar 11 23:33:12 bluetongue netifd: Network alias 'pppoe-wan' link is up
Mar 11 23:33:12 bluetongue netifd: Interface 'wan' is now up
Mar 11 23:33:12 bluetongue netifd: Interface 'wan_6' is enabled
Mar 11 23:33:12 bluetongue netifd: Interface 'wan_6' has link connectivity
Mar 11 23:33:12 bluetongue netifd: Interface 'wan_6' is setting up now
Mar 11 23:33:15 bluetongue netifd: Interface 'wan_6' is now up
###############
Mar 11 23:34:12 bluetongue netifd: Interface 'wan_6' is disabled
Mar 11 23:34:12 bluetongue netifd: Network device 'pppoe-wan' link is down
Mar 11 23:34:12 bluetongue netifd: Network alias 'pppoe-wan' link is down
Mar 11 23:34:12 bluetongue netifd: Interface 'wan_6' has link connectivity loss
Mar 11 23:34:12 bluetongue netifd: Interface 'wan' has lost the connection
Mar 11 23:34:12 bluetongue netifd: wan_6 (14050): Command failed: ubus call network.interface notify_proto { "action": 0, "link-up": false, "keep": false, "interface": "wan_6" } (Permission denied)
Mar 11 23:34:12 bluetongue netifd: Interface 'wan_6' is now down
Mar 11 23:34:15 bluetongue netifd: Network device 'wan' link is down
Mar 11 23:34:15 bluetongue netifd: 8021q 'wan.2' link is down
Mar 11 23:34:15 bluetongue netifd: Interface 'wan' has link connectivity loss
Mar 11 23:34:18 bluetongue netifd: Interface 'wan' is now down
Mar 11 23:35:19 bluetongue netifd: Network device 'wan' link is up
Mar 11 23:35:19 bluetongue netifd: 8021q 'wan.2' link is up
Mar 11 23:35:19 bluetongue netifd: Interface 'wan' has link connectivity
Mar 11 23:35:19 bluetongue netifd: Interface 'wan' is setting up now
Mar 11 23:35:22 bluetongue netifd: Network device 'pppoe-wan' link is up
Mar 11 23:35:22 bluetongue netifd: Network alias 'pppoe-wan' link is up
Mar 11 23:35:22 bluetongue netifd: Interface 'wan' is now up
Mar 11 23:35:22 bluetongue netifd: Interface 'wan_6' is enabled
Mar 11 23:35:22 bluetongue netifd: Interface 'wan_6' has link connectivity
Mar 11 23:35:22 bluetongue netifd: Interface 'wan_6' is setting up now
Mar 11 23:35:25 bluetongue netifd: Interface 'wan_6' is now up
kernel.log
For some reason only the second disconnect was logged in the kernel.log file. I usually see a pair of lines like the following for each event.
Mar 11 23:34:15 bluetongue kernel: [31794.317343] mv88e6085 f1072004.mdio-mii:00 wan: Link is Down
Mar 11 23:35:19 bluetongue kernel: [31858.071079] mv88e6085 f1072004.mdio-mii:00 wan: Link is Up - 1Gbps/Full - flow control off